From 53a92e89c645c2dd42ac07645e9f568487891882 Mon Sep 17 00:00:00 2001 From: Howard Johnson Date: Oct 28 2016 23:01:35 +0000 Subject: [PATCH 1/3] Add audit logging subsystem This commit adds a new database to store audit records, with functions to store and fetch records. Signed-off-by: Howard Johnson --- diff --git a/ipsilon/install/ipsilon-server-install b/ipsilon/install/ipsilon-server-install index 03daa8b..93ab4ad 100755 --- a/ipsilon/install/ipsilon-server-install +++ b/ipsilon/install/ipsilon-server-install @@ -113,6 +113,8 @@ def install(plugins, args): 'datadir': args['data_dir'], 'dbname': 'userprefs'}, 'transdb': args['transaction_dburi'] or args['database_url'] % {'datadir': args['data_dir'], 'dbname': 'transactions'}, + 'auditdb': args['audit_dburi'] or args['database_url'] % { + 'datadir': args['data_dir'], 'dbname': 'audit'}, 'samlsessionsdb': args['samlsessions_dburi'] or args[ 'database_url'] % {'datadir': args['data_dir'], 'dbname': 'saml2sessions'}, @@ -414,6 +416,8 @@ def parse_args(plugins): 'template)') parser.add_argument('--transaction-dburi', help='Transaction database URI (override template)') + parser.add_argument('--audit-dburi', + help='Audit database URI (override template)') parser.add_argument('--samlsessions-dburi', help='SAML 2 sessions database URI (override ' + 'template)') diff --git a/ipsilon/root.py b/ipsilon/root.py index f2b3b2b..4e2d35a 100644 --- a/ipsilon/root.py +++ b/ipsilon/root.py @@ -1,5 +1,6 @@ # Copyright (C) 2013,2016 Ipsilon project Contributors, for license see COPYING +from ipsilon.util.audit import Audit from ipsilon.util.page import Page from ipsilon.util.webfinger import WebFinger from ipsilon.util import errors @@ -37,6 +38,7 @@ class Root(Page): cherrypy.config['error_page.404'] = errors.Error_404(self._site) cherrypy.config['error_page.500'] = errors.Errors(self._site) + self._site['audit'] = Audit() self._site['authz'] = Authz(self._site) # set up WebFinger endpoint diff --git a/ipsilon/tools/dbupgrade.py b/ipsilon/tools/dbupgrade.py index 54d7105..4825cc1 100644 --- a/ipsilon/tools/dbupgrade.py +++ b/ipsilon/tools/dbupgrade.py @@ -6,7 +6,8 @@ import cherrypy import os from jinja2 import Environment, FileSystemLoader import ipsilon.util.sessions -from ipsilon.util.data import AdminStore, Store, UserStore, TranStore +from ipsilon.util.data import AdminStore, Store, UserStore, TranStore, \ + AuditStore from ipsilon.util.sessions import SqlSession from ipsilon.root import Root @@ -93,7 +94,7 @@ def execute_upgrade(cfgfile): return upgrade_failed() # Now handle the rest of the default datastores - for store in [UserStore, TranStore]: + for store in [UserStore, TranStore, AuditStore]: store = store() logger.info('Handling default datastore %s', store.__class__.__name__) diff --git a/ipsilon/util/audit.py b/ipsilon/util/audit.py new file mode 100644 index 0000000..1a78acd --- /dev/null +++ b/ipsilon/util/audit.py @@ -0,0 +1,105 @@ +# Copyright (C) 2016 Ipsilon project Contributors, for license see COPYING + +from ipsilon.util.data import AuditStore +from ipsilon.util.log import Log +from ipsilon.util.user import UserSession +import datetime + + +class Audit(Log): + def __init__(self): + self._store = AuditStore() + self._handlers = {} + + def audit(self, provider_type, provider_name, event_type, **event_attrs): + """ + Log an audit entry in the audit database. + + provider_type, provider_name, and event_type are all strings. + + Callers can store arbitrary data in the audit record (so long as it can + be serialised into JSON format) by passing keyword arguments to the + method. To render this data into a readable format, the caller can + implement a get_audit_display method and register with the audit + handler. See the register_provider method below. + + There are two "special" attributes: + 'user' is the name of the user causing the event. Many callers to + this function will already have a User or UserSession object to + hand, so passing this value in can save some processing. It if + isn't provided, the function will fetch the data itself. + 'timestamp' can be used to override the timestamp related to the + event. If it is not specified, the current time will be used. + """ + if 'user' in event_attrs: + user = event_attrs['user'] + del event_attrs['user'] + else: + us = UserSession() + user = us.user + if 'timestamp' in event_attrs: + timestamp = event_attrs['timestamp'] + del event_attrs['timestamp'] + else: + timestamp = datetime.datetime.now() + + self._store.add_record(timestamp, user, provider_type, provider_name, + event_type, event_attrs) + + def fetch_records(self, user=None, limit=None, age=None): + """ + Returns audit records from the audit database. By default, it will + return all records in the store, which probably isn't what you want. + + Output can be restricted to records relating to a specific user by + specifying the username as the argument. The limit argument restricts + the output to the most recent LIMIT records. age allows the + restriction of the output to records in the most recent AGE hours. + + Records are returned as a list, newest record first. Each record is a + dict with the following keys: + 'ts' is the event timestamp, as a DateTime. + 'user' is the username related to the event. + 'session' is the CherryPy session ID of the event, and can be used to + trace the activities of a single login session. + 'ip' is the source IP address of the request that triggered the audit + event. + 'provtype' is the provider type specified by the audit caller. + 'provname' is the provider name specified by the audit caller. + 'eventtype' is the event type. + 'eventattrs' is a dict containing any extra attributes passed to the + audit call. + 'event' is generated by the appropriate event rendering function, if + one was registered. Otherwise it will have a default value of + 'Unknown event'. + """ + records = self._store.fetch_records(user, limit, age) + for r in records: + r['event'] = 'Unknown event' + if r['provtype'] in self._handlers: + if r['provname'] in self._handlers[r['provtype']]: + r['event'] = self._handlers[r['provtype']][r['provname']]( + r['eventtype'], r['eventattrs']) + return records + + def register_provider(self, provider_type, provider_name, handler): + """ + Registers a handler function to render audit entries into human- + readable display form. The handler must be a callable matching the + following signature: + + render_event_method(event_type, event_attrs) + + event_type is the type string passed in the original audit call. Any + extra data passed to audit via keyword args is passed to the rendering + function in the event_attrs dict. The render function should return a + string. + """ + if not callable(handler): + raise ValueError("Handler is not callable, or doesn't have a " + "get_audit_display method.") + + if provider_type not in self._handlers: + self._handlers[provider_type] = {} + + self._handlers[provider_type][provider_name] = handler diff --git a/ipsilon/util/data.py b/ipsilon/util/data.py index 690e1f3..15b68ce 100644 --- a/ipsilon/util/data.py +++ b/ipsilon/util/data.py @@ -4,7 +4,7 @@ import cherrypy import datetime from ipsilon.util.log import Log from sqlalchemy import create_engine -from sqlalchemy import MetaData, Table, Column, Text, String +from sqlalchemy import MetaData, Table, Column, Text, String, Integer, DateTime from sqlalchemy.pool import QueuePool, SingletonThreadPool from sqlalchemy.schema import (PrimaryKeyConstraint, Index, AddConstraint, CreateIndex) @@ -14,6 +14,7 @@ import os import uuid import logging import time +import json CURRENT_SCHEMA_VERSION = 3 @@ -27,6 +28,12 @@ UNIQUE_DATA_TABLE = {'columns': [('uuid', String(255)), ('name', String(255)), 'primary_key': ('uuid', 'name'), 'indexes': [('uuid',)] } +AUDIT_TABLE = {'columns': [('id', Integer()), ('timestamp', DateTime()), + 'user', 'session', 'ip', 'provtype', 'provname', + 'eventtype', 'eventattrs'], + 'primary_key': ('id',), + 'indexes': [('id',)] + } class DatabaseError(Exception): @@ -981,3 +988,72 @@ class SAML2SessionStore(Store): return 3 else: raise NotImplementedError() + + +class AuditStore(Store): + def __init__(self): + super(AuditStore, self).__init__('audit.db') + self.table = 'audit' + + def _initialize_schema(self): + q = self._query(self._db, self.table, AUDIT_TABLE, trans=False) + q.create() + q._con.close() # pylint: disable=protected-access + + def add_record(self, timestamp, user, provider_type, provider_name, + event_type, event_attrs): + q = self._query(self._db, self.table, AUDIT_TABLE) + q.insert({'timestamp': timestamp, 'user': user, + 'session': cherrypy.session.id, + 'ip': cherrypy.request.remote.ip, 'provtype': provider_type, + 'provname': provider_name, 'eventtype': event_type, + 'eventattrs': json.dumps(event_attrs)}) + q.commit() + + def fetch_records(self, user, limit, age): + # pylint: disable=protected-access + table = SqlQuery(self._db, self.table, AUDIT_TABLE)._table + sel = select([table.c.timestamp, table.c.user, table.c.session, + table.c.ip, table.c.provtype, table.c.provname, + table.c.eventtype, table.c.eventattrs]) + if user: + sel = sel.where(table.c.user == user) + if age: + oldest = datetime.datetime.now() - datetime.timedelta(hours=age) + sel = sel.where(table.c.timestamp >= oldest) + sel = sel.order_by(table.c.timestamp.desc()) + if limit: + sel.limit(limit) + + d = [] + for row in sel.execute(): + d.append({ + 'ts': row[0], + 'user': row[1], + 'session': row[2], + 'ip': row[3], + 'provtype': row[4], + 'provname': row[5], + 'eventtype': row[6], + 'eventattrs': json.loads(row[7]) + }) + + return d + + def _upgrade_schema(self, old_version): + if old_version == 1: + return 2 + elif old_version == 2: + return 3 + else: + raise NotImplementedError + + def _cleanup(self): + # pylint: disable=protected-access + table = SqlQuery(self._db, self.table, AUDIT_TABLE)._table + expiretime = datetime.datetime.now() - \ + datetime.timedelta(days=cherrypy.config.get('audit.purge_age', 30)) + sel = select([table.c.id]).where(table.c.timestamp < expiretime) + # pylint: disable=no-value-for-parameter + d = table.delete().where(table.c.id.in_(sel)) + return d.execute().rowcount diff --git a/ipsilon/util/page.py b/ipsilon/util/page.py index e1cecb9..43883a6 100644 --- a/ipsilon/util/page.py +++ b/ipsilon/util/page.py @@ -35,6 +35,9 @@ class Page(Endpoint): self.user = None self._is_form_page = form self.auth_protect = False + # Subclasses are expected to change these, if they want audit to work + self._audittype = None + self._auditname = None def get_url(self): return cherrypy.url(relative=False) @@ -140,4 +143,15 @@ class Page(Endpoint): msg = 'Transaction expired, or cookies not available' raise cherrypy.HTTPError(401, msg) + def register_audit(self): + self._site['audit'].register_provider(self._audittype, self._auditname, + self.get_audit_display) + + def audit(self, event_type, **event_attrs): + self._site['audit'].audit(self._audittype, self._auditname, event_type, + **event_attrs) + + def get_audit_display(self, event_type, event_attrs): + return '' + exposed = True diff --git a/quickrun.py b/quickrun.py index 847f6c6..e0f739e 100755 --- a/quickrun.py +++ b/quickrun.py @@ -71,6 +71,7 @@ def config(workdir): subprocess.call(['/usr/bin/sqlite3', '-init', sql, users_db, '.quit']) trans_db = os.path.join(workdir, 'transactions.sqlite') + audit_db = os.path.join(workdir, 'audit.sqlite') cachedir = os.path.join(workdir, 'cache') with open(CONF_TEMPLATE) as f: @@ -88,6 +89,7 @@ def config(workdir): 'admindb': admin_db, 'usersdb': users_db, 'transdb': trans_db, + 'auditdb': audit_db, 'sesstype': 'file', 'sessopt': 'path', 'sessval': os.path.join(workdir, 'sessions'), diff --git a/templates/install/ipsilon.conf b/templates/install/ipsilon.conf index 373d86e..44dd848 100644 --- a/templates/install/ipsilon.conf +++ b/templates/install/ipsilon.conf @@ -12,6 +12,8 @@ base.dir = "${staticdir}" admin.config.db = "${admindb}" user.prefs.db = "${usersdb}" transactions.db = "${transdb}" +audit.db = "${auditdb}" +audit.purge_age = 30 tools.sessions.on = True tools.sessions.name = "${instance}_ipsilon_session_id" diff --git a/tests/helpers/common.py b/tests/helpers/common.py index ddefbcb..d49f793 100755 --- a/tests/helpers/common.py +++ b/tests/helpers/common.py @@ -257,7 +257,7 @@ basicConstraints = CA:false""" % {'certdir': os.path.join(self.testdir, self.processes.append(p) p.wait() for d in ['adminconfig', 'users', 'transactions', 'sessions', - 'saml2.sessions.db']: + 'saml2.sessions.db', 'audit']: cmd = ['/usr/bin/createdb', '-h', addr, '-p', port, d] subprocess.check_call(cmd, env=env) From ee2d4951804857b1025aeaf4da27883d0b0bdfdd Mon Sep 17 00:00:00 2001 From: Howard Johnson Date: Oct 28 2016 23:01:57 +0000 Subject: [PATCH 2/3] Add a audit record "recent activity" list to the user portal Signed-off-by: Howard Johnson --- diff --git a/ipsilon/user/common.py b/ipsilon/user/common.py index 82cc4b7..62b8bca 100644 --- a/ipsilon/user/common.py +++ b/ipsilon/user/common.py @@ -38,6 +38,11 @@ class UserPortal(UserPortalPage): def root(self, *args, **kwargs): us = UserSession() user = us.get_user() + + events = self._site['audit'].fetch_records(user=user.name, limit=10) + # Data comes out newest->oldest, but oldest->newest looks better on + # the page. + events.reverse() consents = user.list_consents() for consent in consents: @@ -59,4 +64,5 @@ class UserPortal(UserPortalPage): title='', baseurl=self.url, menu=self.menu, + events=events, consents=consents) diff --git a/templates/user/index.html b/templates/user/index.html index a235a22..330a152 100644 --- a/templates/user/index.html +++ b/templates/user/index.html @@ -3,6 +3,41 @@
+

My Recent Activity

+
+
+

Event Time

+
+
+

IP Address

+
+
+

Session

+
+
+

Event

+
+
+{%- for event in events %} +
+
+

{{ event.ts.strftime('%Y-%m-%d %H:%M:%S') }}

+
+
+

{{ event.ip }}

+
+
+

{{ event.session }}

+
+
+

{{ event.event }}

+
+
+{%- endfor %} +
+
+
+

Granted Consent

From 2631805630b9410ed0bfaa6c05cb7e3803fbbb26 Mon Sep 17 00:00:00 2001 From: Howard Johnson Date: Oct 28 2016 23:02:12 +0000 Subject: [PATCH 3/3] Add audit logging to a couple of bits of the login stack for testing Signed-off-by: Howard Johnson --- diff --git a/ipsilon/login/authtest.py b/ipsilon/login/authtest.py index 9e28de7..087bea0 100644 --- a/ipsilon/login/authtest.py +++ b/ipsilon/login/authtest.py @@ -10,6 +10,16 @@ import logging class TestAuth(LoginFormBase): + def __init__(self, site, mgr, page, template=None): + super(TestAuth, self).__init__(site, mgr, page, template=template) + self._auditname = 'testauth' + self.register_audit() + + def get_audit_display(self, event_type, event_attrs): + if event_type == 'login': + return 'User logged in' + else: + return 'Unknown event' def POST(self, *args, **kwargs): username = kwargs.get("login_name") @@ -18,6 +28,7 @@ class TestAuth(LoginFormBase): if username and password: if password == 'ipsilon': + self.audit('login', user=username) cherrypy.log("User %s successfully authenticated." % username) testdata = { 'givenname': 'Test User δΈ€', diff --git a/ipsilon/login/common.py b/ipsilon/login/common.py index d0ef41a..e83551b 100644 --- a/ipsilon/login/common.py +++ b/ipsilon/login/common.py @@ -246,6 +246,7 @@ class LoginPageBase(Page): super(LoginPageBase, self).__init__(site) self.lm = mgr self._Transaction = None + self._audittype = 'login' def root(self, *args, **kwargs): raise cherrypy.HTTPError(500) @@ -370,9 +371,19 @@ class Logout(Page): def __init__(self, *args, **kwargs): super(Logout, self).__init__(*args, **kwargs) self.handlers = {} + self._audittype = 'login' + self._auditname = 'logout' + self.register_audit() + + def get_audit_display(self, event_type, event_attrs): + if event_type == 'logout': + return 'User logged out' + else: + return 'Unknown event' def root(self, *args, **kwargs): us = UserSession() + self.audit('logout') for provider in self.handlers: self.debug("Calling logout for provider %s" % provider)