diff --git a/README.rst b/README.rst index 5dc888e..8f6cbb4 100644 --- a/README.rst +++ b/README.rst @@ -161,3 +161,71 @@ Authentication backend This is the default backend. The returned attributes are the fields available on the user model. * mysql backend ``cas_server.auth.MysqlAuthUser``: see the 'Mysql backend settings' section. The returned attributes are those return by sql query ``CAS_SQL_USER_QUERY``. + +Logs +---- + +``django-cas-server`` logs most of its actions. To enable login, you must set the ``LOGGING`` +(https://docs.djangoproject.com/en/dev/topics/logging) variable is ``settings.py``. + +Users successful actions (login, logout) are logged with the level ``INFO``, failures are logged +with the level ``WARNING`` and user attributes transmitted to a service are logged with the level ``DEBUG``. + +For exemple to log to syslog you can use : + +.. code-block:: python + + LOGGING = { + 'version': 1, + 'disable_existing_loggers': False, + 'formatters': { + 'cas_syslog': { + 'format': 'cas: %(levelname)s %(message)s' + }, + }, + 'handlers': { + 'cas_syslog': { + 'level': 'INFO', + 'class': 'logging.handlers.SysLogHandler', + 'address': '/dev/log', + 'formatter': 'cas_syslog', + }, + }, + 'loggers': { + 'cas_server': { + 'handlers': ['cas_syslog'], + 'level': 'INFO', + 'propagate': True, + }, + }, + } + + +Or to log to a file: + +.. code-block:: python + + LOGGING = { + 'version': 1, + 'disable_existing_loggers': False, + 'formatters': { + 'cas_file': { + 'format': '%(asctime)s %(levelname)s %(message)s' + }, + }, + 'handlers': { + 'cas_file': { + 'level': 'INFO', + 'class': 'logging.FileHandler', + 'filename': '/tmp/cas_server.log', + 'formatter': 'cas_file', + }, + }, + 'loggers': { + 'cas_server': { + 'handlers': ['cas_file'], + 'level': 'INFO', + 'propagate': True, + }, + }, + } diff --git a/cas_server/models.py b/cas_server/models.py index 3867d2f..8997f4c 100644 --- a/cas_server/models.py +++ b/cas_server/models.py @@ -22,6 +22,7 @@ from picklefield.fields import PickledObjectField import re import os import sys +import logging from importlib import import_module from datetime import timedelta from concurrent.futures import ThreadPoolExecutor @@ -31,6 +32,8 @@ import cas_server.utils as utils SessionStore = import_module(settings.SESSION_ENGINE).SessionStore +logger = logging.getLogger(__name__) + class User(models.Model): """A user logged into the CAS""" @@ -82,6 +85,12 @@ class User(models.Model): try: future.result() except Exception as error: + logger.warning( + "Error during SLO for user %s: %s" % ( + self.username, + error + ) + ) if request is not None: error = utils.unpack_nested_exception(error) messages.add_message( @@ -125,6 +134,7 @@ class User(models.Model): after a Service Ticket has been generated""" ticket = self.get_ticket(ServiceTicket, service, service_pattern, renew) url = utils.update_url(service, {'ticket': ticket.value}) + logger.info("Service ticket created for service %s by user %s." % (service, self.username)) return url @@ -220,6 +230,7 @@ class ServicePattern(models.Model): def check_user(self, user): """Check if `user` if allowed to use theses services""" if self.restrict_users and not self.usernames.filter(value=user.username): + logger.warning("Username %s not allowed on service %s" % (user.username, self.name)) raise BadUsername() for filtre in self.filters.all(): if isinstance(user.attributs.get(filtre.attribut, []), list): @@ -230,12 +241,28 @@ class ServicePattern(models.Model): if re.match(filtre.pattern, str(value)): break else: + logger.warning( + "User constraint failed for %s, service %s: %s do not match %s %s." % ( + user.username, + self.name, + filtre.pattern, + filtre.attribut, + user.attributs.get(filtre.attribut) + ) + ) raise BadFilter('%s do not match %s %s' % ( filtre.pattern, filtre.attribut, user.attributs.get(filtre.attribut) )) if self.user_field and not user.attributs.get(self.user_field): + logger.warning( + "Cannot use %s a loggin for user %s on service %s because it is absent" % ( + self.user_field, + user.username, + self.name + ) + ) raise UserFieldNotDefined() return True @@ -246,6 +273,7 @@ class ServicePattern(models.Model): for service_pattern in cls.objects.all().order_by('pos'): if re.match(service_pattern.pattern, service): return service_pattern + logger.warning("Service %s not allowed." % service) raise cls.DoesNotExist() @@ -378,6 +406,7 @@ class Ticket(models.Model): try: future.result() except Exception as error: + logger.warning("Error durring SLO %s" % error) sys.stderr.write("%r\n" % error) def logout(self, request, session, async_list=None): @@ -386,6 +415,12 @@ class Ticket(models.Model): self.validate = True self.save() if self.validate and self.single_log_out: + logger.info( + "Sending SLO requests to service %s for user %s" % ( + self.service, + self.user.username + ) + ) try: xml = u""" @@ -409,8 +444,15 @@ class Ticket(models.Model): ) ) except Exception as error: + error = utils.unpack_nested_exception(error) + logger.warning( + "Error durring SLO for user %s on service %s: %s" % ( + self.user.username, + self.service, + error + ) + ) if request is not None: - error = utils.unpack_nested_exception(error) messages.add_message( request, messages.WARNING, diff --git a/cas_server/views.py b/cas_server/views.py index e88e2cb..6ef944b 100644 --- a/cas_server/views.py +++ b/cas_server/views.py @@ -23,6 +23,8 @@ from django.views.decorators.csrf import csrf_exempt from django.views.generic import View +import logging +import pprint import requests from lxml import etree from datetime import timedelta @@ -38,6 +40,8 @@ from .models import ServicePattern SessionStore = import_module(settings.SESSION_ENGINE).SessionStore +logger = logging.getLogger(__name__) + class AttributesMixin(object): """mixin for the attributs methode""" @@ -60,9 +64,14 @@ class LogoutMixin(object): """destroy CAS session utils""" def logout(self, all=False): """effectively destroy CAS session""" + username = self.request.session.get("username") + if username: + if all: + logger.info("Logging out user %s from all of they sessions." % username) + else: + logger.info("Logging out user %s." % username) # logout the user from the current session try: - username = self.request.session.get("username") user = models.User.objects.get( username=username, session_key=self.request.session.session_key @@ -81,6 +90,7 @@ class LogoutMixin(object): session.flush() user.logout(self.request) user.delete() + logger.info("User %s logged out" % username) class LogoutView(View, LogoutMixin): @@ -97,6 +107,7 @@ class LogoutView(View, LogoutMixin): def get(self, request, *args, **kwargs): """methode called on GET request on this view""" + logger.info("logout requested") self.init_get(request) self.logout(self.request.GET.get("all")) # if service is set, redirect to service after logout @@ -212,6 +223,7 @@ class LoginView(View, LogoutMixin): # if not set a new LT and fail values['lt'] = self.request.session['lt'][-1] self.init_form(values) + logger.warning("Receive an invalid login ticket") return self.INVALID_LOGIN_TICKET elif not self.request.session.get("authenticated") or self.renew: self.init_form(self.request.POST) @@ -222,10 +234,13 @@ class LoginView(View, LogoutMixin): self.request.session["authenticated"] = True self.renewed = True self.warned = True + logger.info("User %s successfully authenticated" % self.request.session["username"]) return self.USER_LOGIN_OK else: + logger.warning("A logging attemps failed") return self.USER_LOGIN_FAILURE else: + logger.warning("Receuve a logging attempt whereas the user is already logged") return self.USER_ALREADY_LOGGED def init_get(self, request): @@ -356,6 +371,11 @@ class LoginView(View, LogoutMixin): session_key=self.request.session.session_key ) except models.User.DoesNotExist: + logger.warning( + "User %s seems authenticated but is not found in the database." % ( + self.request.session.get("username"), + ) + ) self.logout() if self.ajax: data = { @@ -503,10 +523,27 @@ class Validate(View): ) ticket.validate = True ticket.save() + logger.info( + "Validate: Service ticket %s validated, user %s authenticated on service %s" % ( + ticket.value, + ticket.user.username, + ticket.service + ) + ) return HttpResponse("yes\n", content_type="text/plain") except ServiceTicket.DoesNotExist: + logger.warning( + ( + "Validate: Service ticket %s not found or " + "already validated, auth to %s failed" + ) % ( + ticket, + service + ) + ) return HttpResponse("no\n", content_type="text/plain") else: + logger.warning("Validate: service or ticket missing") return HttpResponse("no\n", content_type="text/plain") @@ -548,6 +585,7 @@ class ValidateService(View, AttributesMixin): self.renew = True if request.GET.get('renew') else False if not self.service or not self.ticket: + logger.warning("ValidateService: missing ticket or service") return ValidateError( 'INVALID_REQUEST', "you must specify a service and a ticket" @@ -568,6 +606,18 @@ class ValidateService(View, AttributesMixin): if self.pgt_url and self.pgt_url.startswith("https://"): return self.process_pgturl(params) else: + logger.info( + "ValidateService: ticket %s validated for user %s on service %s." % ( + self.ticket.value, + self.ticket.user.username, + self.ticket.service + ) + ) + logger.debug( + "ValidateService: User attributs are:\n%s" % ( + pprint.pformat(self.ticket.attributs), + ) + ) return render( request, "cas_server/serviceValidate.xml", @@ -575,6 +625,9 @@ class ValidateService(View, AttributesMixin): content_type="text/xml; charset=utf-8" ) except ValidateError as error: + logger.warning( + "ValidateService: validation error: %s %s" % (error.code, error.msg) + ) return error.render(request) def process_ticket(self): @@ -598,11 +651,11 @@ class ValidateService(View, AttributesMixin): for prox in ticket.proxies.all(): proxies.append(prox.url) else: - raise ValidateError('INVALID_TICKET') + raise ValidateError('INVALID_TICKET', self.ticket) ticket.validate = True ticket.save() if ticket.service != self.service: - raise ValidateError('INVALID_SERVICE') + raise ValidateError('INVALID_SERVICE', self.service) return ticket, proxies except (ServiceTicket.DoesNotExist, ProxyTicket.DoesNotExist): raise ValidateError('INVALID_TICKET', 'ticket not found') @@ -626,6 +679,22 @@ class ValidateService(View, AttributesMixin): params['proxyGrantingTicket'] = proxyid else: pticket.delete() + logger.info( + ( + "ValidateService: ticket %s validated for user %s on service %s. " + "Proxy Granting Ticket transmited to %s." + ) % ( + self.ticket.value, + self.ticket.user.username, + self.ticket.service, + self.pgt_url + ) + ) + logger.debug( + "ValidateService: User attributs are:\n%s" % ( + pprint.pformat(self.ticket.attributs), + ) + ) return render( self.request, "cas_server/serviceValidate.xml", @@ -668,6 +737,7 @@ class Proxy(View): "you must specify and pgt and targetService" ) except ValidateError as error: + logger.warning("Proxy: validation error: %s %s" % (error.code, error.msg)) return error.render(request) def process_proxy(self): @@ -678,7 +748,7 @@ class Proxy(View): if not pattern.proxy: raise ValidateError( 'UNAUTHORIZED_SERVICE', - 'the service do not allow proxy ticket' + 'the service %s do not allow proxy ticket' % self.target_service ) # is the proxy granting ticket valid ticket = ProxyGrantingTicket.objects.get( @@ -694,6 +764,12 @@ class Proxy(View): pattern, renew=False) models.Proxy.objects.create(proxy_ticket=pticket, url=ticket.service) + logger.info( + "Proxy ticket created for user %s on service %s." % ( + ticket.user.username, + self.target_service + ) + ) return render( self.request, "cas_server/proxy.xml", @@ -701,9 +777,9 @@ class Proxy(View): content_type="text/xml; charset=utf-8" ) except ProxyGrantingTicket.DoesNotExist: - raise ValidateError('INVALID_TICKET', 'PGT not found') + raise ValidateError('INVALID_TICKET', 'PGT %s not found' % self.pgt) except ServicePattern.DoesNotExist: - raise ValidateError('UNAUTHORIZED_SERVICE') + raise ValidateError('UNAUTHORIZED_SERVICE', self.target_service) except (models.BadUsername, models.BadFilter, models.UserFieldNotDefined): raise ValidateError( 'UNAUTHORIZED_USER', @@ -771,6 +847,17 @@ class SamlValidate(View, AttributesMixin): params['username'] = self.ticket.user.attributs.get( self.ticket.service_pattern.user_field ) + logger.info( + "SamlValidate: ticket %s validated for user %s on service %s." % ( + self.ticket.value, + self.ticket.user.username, + self.ticket.service + ) + ) + logger.debug( + "SamlValidate: User attributs are:\n%s" % pprint.pformat(self.ticket.attributs) + ) + return render( request, "cas_server/samlValidate.xml", @@ -778,6 +865,7 @@ class SamlValidate(View, AttributesMixin): content_type="text/xml; charset=utf-8" ) except SamlValidateError as error: + logger.warning("SamlValidate: validation error: %s %s" % (error.code, error.msg)) return error.render(request) def process_ticket(self): @@ -800,17 +888,17 @@ class SamlValidate(View, AttributesMixin): else: raise SamlValidateError( 'AuthnFailed', - 'ticket should begin with PT- or ST-' + 'ticket %s should begin with PT- or ST-' % ticket ) ticket.validate = True ticket.save() if ticket.service != self.target: raise SamlValidateError( 'AuthnFailed', - 'TARGET do not match ticket service' + 'TARGET %s do not match ticket service' % self.target ) return ticket except (IndexError, KeyError): raise SamlValidateError('VersionMismatch') except (ServiceTicket.DoesNotExist, ProxyTicket.DoesNotExist): - raise SamlValidateError('AuthnFailed', 'ticket not found') + raise SamlValidateError('AuthnFailed', 'ticket %s not found' % ticket)