From fbbf7a320da4daf6d661bf314d7744103bb95bc5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lauri=20V=C3=B5sandi?= Date: Sun, 13 Dec 2015 15:11:22 +0000 Subject: [PATCH] Add preliminary support for logging Current logging mechanism makes use of Python's logging module. MySQL logging handler inserts log entries to MySQL server and another logging handler is used to stream events to web interface via nginx streaming push. --- README.rst | 3 +- certidude/api/__init__.py | 44 +++++++++++++++++- certidude/api/log.py | 39 ++++++++++++++++ certidude/api/request.py | 11 ++++- certidude/auth.py | 25 ++++++++--- certidude/authority.py | 2 +- certidude/config.py | 5 ++- certidude/mysqllog.py | 45 +++++++++++++++++++ certidude/push.py | 9 ++++ certidude/static/authority.html | 13 ++++++ certidude/static/css/style.css | 19 +++++--- .../static/img/iconmonstr-error-4-icon.svg | 12 +++++ .../static/img/iconmonstr-info-6-icon.svg | 18 ++++++++ .../static/img/iconmonstr-warning-6-icon.svg | 11 +++++ certidude/static/js/certidude.js | 35 +++++++++++++++ certidude/static/logentry.html | 5 +++ 16 files changed, 280 insertions(+), 16 deletions(-) create mode 100644 certidude/api/log.py create mode 100644 certidude/mysqllog.py create mode 100644 certidude/static/img/iconmonstr-error-4-icon.svg create mode 100644 certidude/static/img/iconmonstr-info-6-icon.svg create mode 100644 certidude/static/img/iconmonstr-warning-6-icon.svg create mode 100644 certidude/static/logentry.html diff --git a/README.rst b/README.rst index 1615f29..6c6dd60 100644 --- a/README.rst +++ b/README.rst @@ -67,7 +67,8 @@ To install Certidude: .. code:: bash - apt-get install -y python3 python3-pip python3-dev python3-mysql.connector cython3 build-essential libffi-dev libssl-dev libkrb5-dev + apt-get install -y python3 python3-pip python3-dev cython3 build-essential libffi-dev libssl-dev libkrb5-dev + pip3 install --allow-external mysql-connector-python mysql-connector-python pip3 install certidude Make sure you're running PyOpenSSL 0.15+ and netifaces 0.10.4+ from PyPI, diff --git a/certidude/api/__init__.py b/certidude/api/__init__.py index 02697fa..d366ab6 100644 --- a/certidude/api/__init__.py +++ b/certidude/api/__init__.py @@ -35,7 +35,7 @@ class SessionResource(object): @event_source def on_get(self, req, resp): return dict( - username=req.context.get("user")[0], + username=req.context.get("user"), event_channel = config.PUSH_EVENT_SOURCE % config.PUSH_TOKEN, autosign_subnets = config.AUTOSIGN_SUBNETS, request_subnets = config.REQUEST_SUBNETS, @@ -78,6 +78,7 @@ def certidude_app(): from .request import RequestListResource, RequestDetailResource from .lease import LeaseResource from .whois import WhoisResource + from .log import LogResource app = falcon.API() @@ -89,10 +90,51 @@ def certidude_app(): app.add_route("/api/signed/", SignedCertificateListResource()) app.add_route("/api/request/{cn}/", RequestDetailResource()) app.add_route("/api/request/", RequestListResource()) + app.add_route("/api/log/", LogResource()) app.add_route("/api/", SessionResource()) # Gateway API calls, should this be moved to separate project? app.add_route("/api/lease/", LeaseResource()) app.add_route("/api/whois/", WhoisResource()) + """ + Set up logging + """ + + from certidude import config + from certidude.mysqllog import MySQLLogHandler + from datetime import datetime + import logging + import socket + import json + + + class PushLogHandler(logging.Handler): + def emit(self, record): + from certidude.push import publish + print("EVENT HAPPENED:", record.created) + publish("log-entry", dict( + created = datetime.fromtimestamp(record.created), + message = record.msg % record.args, + severity = record.levelname.lower())) + + sql_handler = MySQLLogHandler(config.DATABASE_POOL) + push_handler = PushLogHandler() + + for facility in "api", "cli": + logger = logging.getLogger(facility) + logger.setLevel(logging.DEBUG) + logger.addHandler(sql_handler) + logger.addHandler(push_handler) + + + logging.getLogger("cli").info("Started Certidude at %s", socket.getaddrinfo(socket.gethostname(), 0, flags=socket.AI_CANONNAME)[0][3]) + + import atexit + + def exit_handler(): + logging.getLogger("cli").info("Shutting down Certidude") + + atexit.register(exit_handler) + return app diff --git a/certidude/api/log.py b/certidude/api/log.py new file mode 100644 index 0000000..f6d04b3 --- /dev/null +++ b/certidude/api/log.py @@ -0,0 +1,39 @@ + +from certidude import config +from certidude.auth import login_required, authorize_admin +from certidude.decorators import serialize + +class LogResource(object): + @serialize + @login_required + @authorize_admin + def on_get(self, req, resp): + """ + Translate currently online client's IP-address to distinguished name + """ + + SQL_LOG_ENTRIES = """ + SELECT + * + FROM + log + ORDER BY created DESC + """ + conn = config.DATABASE_POOL.get_connection() + cursor = conn.cursor(dictionary=True) + cursor.execute(SQL_LOG_ENTRIES) + + def g(): + for row in cursor: + yield row + cursor.close() + conn.close() + return tuple(g()) + +# for acquired, released, identity in cursor: +# return { +# "acquired": datetime.utcfromtimestamp(acquired), +# "identity": parse_dn(bytes(identity)) +# } +# return None + diff --git a/certidude/api/request.py b/certidude/api/request.py index 9013f53..9b82415 100644 --- a/certidude/api/request.py +++ b/certidude/api/request.py @@ -1,6 +1,7 @@ import click import falcon +import logging import ipaddress import os from certidude import config, authority, helpers, push @@ -8,6 +9,8 @@ from certidude.auth import login_required, authorize_admin from certidude.decorators import serialize from certidude.wrappers import Request, Certificate +logger = logging.getLogger("api") + class RequestListResource(object): @serialize @authorize_admin @@ -27,13 +30,14 @@ class RequestListResource(object): if subnet.overlaps(remote_addr): break else: + logger.warning("Attempted to submit signing request from non-whitelisted address %s", req.env["REMOTE_ADDR"]) raise falcon.HTTPForbidden("Forbidden", "IP address %s not whitelisted" % remote_addr) if req.get_header("Content-Type") != "application/pkcs10": raise falcon.HTTPUnsupportedMediaType( "This API call accepts only application/pkcs10 content type") - body = req.stream.read(req.content_length) + body = req.stream.read(req.content_length).decode("ascii") csr = Request(body) # Check if this request has been already signed and return corresponding certificte if it has been signed @@ -65,6 +69,7 @@ class RequestListResource(object): try: csr = authority.store_request(body) except FileExistsError: + logger.warning("Rejected signing request with overlapping common name from %s", req.env["REMOTE_ADDR"]) raise falcon.HTTPConflict( "CSR with such CN already exists", "Will not overwrite existing certificate signing request, explicitly delete CSR and try again") @@ -77,9 +82,11 @@ class RequestListResource(object): click.echo("Redirecting to: %s" % url) resp.status = falcon.HTTP_SEE_OTHER resp.set_header("Location", url) + logger.warning("Redirecting signing request from %s to %s", req.env["REMOTE_ADDR"], url) else: # Request was accepted, but not processed resp.status = falcon.HTTP_202 + logger.info("Signing request from %s stored", req.env["REMOTE_ADDR"]) class RequestDetailResource(object): @@ -108,6 +115,7 @@ class RequestDetailResource(object): resp.body = "Certificate successfully signed" resp.status = falcon.HTTP_201 resp.location = os.path.join(req.relative_uri, "..", "..", "signed", cn) + logger.info("Signing request %s signed by %s from %s", csr.common_name, req.context["user"], req.env["REMOTE_ADDR"]) @login_required @authorize_admin @@ -116,4 +124,5 @@ class RequestDetailResource(object): authority.delete_request(cn) except FileNotFoundError: resp.body = "No certificate CN=%s found" % cn + logger.warning("User %s attempted to delete non-existant signing request %s from %s", req.context["user"], cn, req.env["REMOTE_ADDR"]) raise falcon.HTTPNotFound() diff --git a/certidude/auth.py b/certidude/auth.py index 416ac9e..e633d5a 100644 --- a/certidude/auth.py +++ b/certidude/auth.py @@ -3,10 +3,13 @@ import click import falcon import ipaddress import kerberos +import logging import os import re import socket +logger = logging.getLogger("api") + # Vanilla Kerberos provides only username. # AD also embeds PAC (Privilege Attribute Certificate), which # is supposed to be sent via HTTP headers and it contains @@ -30,11 +33,12 @@ else: click.echo("Kerberos enabled, service principal is HTTP/%s" % FQDN) def login_required(func): - def wrapped(resource, req, resp, *args, **kwargs): + def authenticate(resource, req, resp, *args, **kwargs): authorization = req.get_header("Authorization") if not authorization: resp.append_header("WWW-Authenticate", "Negotiate") + logger.debug("No Kerberos ticket offered while attempting to access %s from %s", req.env["PATH_INFO"], req.env["REMOTE_ADDR"]) raise falcon.HTTPUnauthorized("Unauthorized", "No Kerberos ticket offered, are you sure you've logged in with domain user account?") token = ''.join(authorization.split()[1:]) @@ -42,6 +46,7 @@ def login_required(func): try: result, context = kerberos.authGSSServerInit("HTTP@" + FQDN) except kerberos.GSSError as ex: + # TODO: logger.error raise falcon.HTTPForbidden("Forbidden", "Authentication System Failure: %s(%s)" % (ex.args[0][0], ex.args[1][0],)) try: @@ -49,28 +54,35 @@ def login_required(func): except kerberos.GSSError as ex: s = str(dir(ex)) kerberos.authGSSServerClean(context) + # TODO: logger.error raise falcon.HTTPForbidden("Forbidden", "Bad credentials: %s (%s)" % (ex.args[0][0], ex.args[1][0])) except kerberos.KrbError as ex: kerberos.authGSSServerClean(context) + # TODO: logger.error raise falcon.HTTPForbidden("Forbidden", "Bad credentials: %s" % (ex.args[0],)) - req.context["user"] = kerberos.authGSSServerUserName(context).split("@") + user = kerberos.authGSSServerUserName(context) + req.context["user"], req.context["user_realm"] = user.split("@") try: # BUGBUG: https://github.com/02strich/pykerberos/issues/6 #kerberos.authGSSServerClean(context) pass except kerberos.GSSError as ex: + # TODO: logger.error raise error.LoginFailed('Authentication System Failure %s(%s)' % (ex.args[0][0], ex.args[1][0],)) if result == kerberos.AUTH_GSS_COMPLETE: + logger.debug("Succesfully authenticated user %s for %s from %s", user, req.env["PATH_INFO"], req.env["REMOTE_ADDR"]) return func(resource, req, resp, *args, **kwargs) elif result == kerberos.AUTH_GSS_CONTINUE: + # TODO: logger.error raise falcon.HTTPUnauthorized("Unauthorized", "Tried GSSAPI") else: + # TODO: logger.error raise falcon.HTTPForbidden("Forbidden", "Tried GSSAPI") - return wrapped + return authenticate def authorize_admin(func): @@ -85,12 +97,13 @@ def authorize_admin(func): if subnet.overlaps(remote_addr): break else: + logger.info("Rejected access to administrative call %s by %s from %s, source address not whitelisted", req.env["PATH_INFO"], user, req.env["REMOTE_ADDR"]) raise falcon.HTTPForbidden("Forbidden", "Remote address %s not whitelisted" % remote_addr) # Check for username whitelist - kerberos_username, kerberos_realm = req.context.get("user") - if kerberos_username not in config.ADMIN_USERS: - raise falcon.HTTPForbidden("Forbidden", "User %s not whitelisted" % kerberos_username) + if req.context.get("user") not in config.ADMIN_USERS: + logger.info("Rejected access to administrative call %s by %s from %s, user not whitelisted", req.env["PATH_INFO"], user, req.env["REMOTE_ADDR"]) + raise falcon.HTTPForbidden("Forbidden", "User %s not whitelisted" % req.context.get("user")) # Retain username, TODO: Better abstraction with username, e-mail, sn, gn? diff --git a/certidude/authority.py b/certidude/authority.py index 16135e8..cdd0c62 100644 --- a/certidude/authority.py +++ b/certidude/authority.py @@ -66,7 +66,7 @@ def store_request(buf, overwrite=False): raise FileExistsError("Request already exists") else: with open(request_path + ".part", "wb") as fh: - fh.write(buf) + fh.write(buf.encode("ascii")) os.rename(request_path + ".part", request_path) return Request(open(request_path)) diff --git a/certidude/config.py b/certidude/config.py index 309a4b1..a868ebc 100644 --- a/certidude/config.py +++ b/certidude/config.py @@ -3,6 +3,7 @@ import click import configparser import ipaddress import os +import socket import string from random import choice @@ -24,6 +25,8 @@ REQUESTS_DIR = cp.get("authority", "requests_dir") SIGNED_DIR = cp.get("authority", "signed_dir") REVOKED_DIR = cp.get("authority", "revoked_dir") +#LOG_DATA = cp.get("logging", "database") + CERTIFICATE_BASIC_CONSTRAINTS = "CA:FALSE" CERTIFICATE_KEY_USAGE_FLAGS = "nonRepudiation,digitalSignature,keyEncipherment" CERTIFICATE_EXTENDED_KEY_USAGE_FLAGS = "clientAuth" @@ -51,7 +54,7 @@ o = urlparse(cp.get("authority", "database")) if o.scheme == "mysql": import mysql.connector DATABASE_POOL = mysql.connector.pooling.MySQLConnectionPool( - pool_size = 3, + pool_size = 32, user=o.username, password=o.password, host=o.hostname, diff --git a/certidude/mysqllog.py b/certidude/mysqllog.py new file mode 100644 index 0000000..d75717b --- /dev/null +++ b/certidude/mysqllog.py @@ -0,0 +1,45 @@ + +import logging +import time + +class MySQLLogHandler(logging.Handler): + + SQL_CREATE_TABLE = """CREATE TABLE IF NOT EXISTS log( + created datetime, facility varchar(30), level int, + severity varchar(10), message text, module varchar(20), + func varchar(20), lineno int, exception text, process int, + thread text, thread_name text)""" + + SQL_INSERT_ENTRY = """insert into log( created, facility, level, severity, + message, module, func, lineno, exception, process, thread, + thread_name) values (%s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s); + """ + + def __init__(self, pool): + logging.Handler.__init__(self) + self.pool = pool + conn = self.pool.get_connection() + cur = conn.cursor() + cur.execute(self.SQL_CREATE_TABLE) + conn.commit() + cur.close() + conn.close() + + def emit(self, record): + conn = self.pool.get_connection() + cur = conn.cursor() + cur.execute(self.SQL_INSERT_ENTRY, ( + time.strftime("%Y-%m-%d %H:%M:%S", time.localtime(record.created)), + record.name, + record.levelno, + record.levelname.lower(), + record.msg % record.args, record.module, + record.funcName, + record.lineno, + logging._defaultFormatter.formatException(record.exc_info) if record.exc_info else "", + record.process, + record.thread, + record.threadName)) + conn.commit() + cur.close() + conn.close() diff --git a/certidude/push.py b/certidude/push.py index 18ad726..a44a84a 100644 --- a/certidude/push.py +++ b/certidude/push.py @@ -1,12 +1,18 @@ import click +import json import urllib.request from certidude import config + def publish(event_type, event_data): """ Publish event on push server """ + if not isinstance(event_data, str): + from certidude.decorators import MyEncoder + event_data = json.dumps(event_data, cls=MyEncoder) + url = config.PUSH_PUBLISH % config.PUSH_TOKEN click.echo("Posting event %s %s at %s, waiting for response..." % (repr(event_type), repr(event_data), repr(url))) notification = urllib.request.Request( @@ -25,4 +31,7 @@ def publish(event_type, event_data): raise else: print("Push server returned:", response.code, body) + response.close() + + diff --git a/certidude/static/authority.html b/certidude/static/authority.html index 2c159c8..45b2b7d 100644 --- a/certidude/static/authority.html +++ b/certidude/static/authority.html @@ -35,6 +35,19 @@ +
+

Log

+

+ + + + + +

+ +
+

Revoked certificates

To fetch certificate revocation list:

diff --git a/certidude/static/css/style.css b/certidude/static/css/style.css index 0f44908..420945b 100644 --- a/certidude/static/css/style.css +++ b/certidude/static/css/style.css @@ -75,7 +75,6 @@ button:disabled, .button:disabled { footer { display: block; - color: #fff; text-align: center; } @@ -84,10 +83,6 @@ a { color: #44c; } -footer a { - color: #aaf; -} - html,body { margin: 0; padding: 0 0 1em 0; @@ -143,6 +138,7 @@ pre { .container { max-width: 960px; + padding: 0 1em; margin: 0 auto; } @@ -174,6 +170,19 @@ pre { text-decoration: none; } +li span.icon { + background-size: 32px; + padding-left: 42px; + padding-top: 2px; + padding-bottom: 2px; +} + + +.icon.critical { background-image: url("../img/iconmonstr-error-4-icon.svg"); } +.icon.error { background-image: url("../img/iconmonstr-error-4-icon.svg"); } +.icon.warning { background-image: url("../img/iconmonstr-warning-6-icon.svg"); } +.icon.info { background-image: url("../img/iconmonstr-info-6-icon.svg"); } + .icon.revoke { background-image: url("../img/iconmonstr-x-mark-5-icon.svg"); } .icon.download { background-image: url("../img/iconmonstr-download-12-icon.svg"); } diff --git a/certidude/static/img/iconmonstr-error-4-icon.svg b/certidude/static/img/iconmonstr-error-4-icon.svg new file mode 100644 index 0000000..65ff8ac --- /dev/null +++ b/certidude/static/img/iconmonstr-error-4-icon.svg @@ -0,0 +1,12 @@ + + + + + + + diff --git a/certidude/static/img/iconmonstr-info-6-icon.svg b/certidude/static/img/iconmonstr-info-6-icon.svg new file mode 100644 index 0000000..f433119 --- /dev/null +++ b/certidude/static/img/iconmonstr-info-6-icon.svg @@ -0,0 +1,18 @@ + + + + + + + diff --git a/certidude/static/img/iconmonstr-warning-6-icon.svg b/certidude/static/img/iconmonstr-warning-6-icon.svg new file mode 100644 index 0000000..b6f93a4 --- /dev/null +++ b/certidude/static/img/iconmonstr-warning-6-icon.svg @@ -0,0 +1,11 @@ + + + + + + + diff --git a/certidude/static/js/certidude.js b/certidude/static/js/certidude.js index e6b9cd2..4a9a65d 100644 --- a/certidude/static/js/certidude.js +++ b/certidude/static/js/certidude.js @@ -23,6 +23,20 @@ $(document).ready(function() { console.log("Received server-sent event:", event); } + source.addEventListener("log-entry", function(e) { + var entry = JSON.parse(e.data); + console.info("Received log entry:", entry, "gonna prepend:", $("#log_level_" + entry.severity).prop("checked")); + if ($("#log_level_" + entry.severity).prop("checked")) { + $("#log_entries").prepend(nunjucks.render("logentry.html", { + entry: { + created: new Date(entry.created).toLocaleString(), + message: entry.message, + severity: entry.severity + } + })); + } + }); + source.addEventListener("up-client", function(e) { console.log("Adding security association:" + e.data); var lease = JSON.parse(e.data); @@ -92,6 +106,27 @@ $(document).ready(function() { $("#container").html(nunjucks.render('authority.html', { session: session, window: window })); + + $.ajax({ + method: "GET", + url: "/api/log/", + dataType: "json", + success:function(entries, status, xhr) { + console.info("Got", entries.length, "log entries"); + for (var j = 0; j < entries.length; j++) { + if ($("#log_level_" + entries[j].severity).prop("checked")) { + $("#log_entries").append(nunjucks.render("logentry.html", { + entry: { + created: new Date(entries[j].created).toLocaleString("et-EE"), + message: entries[j].message, + severity: entries[j].severity + } + })); + } + } + } + }); + $.ajax({ method: "GET", url: "/api/lease/", diff --git a/certidude/static/logentry.html b/certidude/static/logentry.html new file mode 100644 index 0000000..3e5cba8 --- /dev/null +++ b/certidude/static/logentry.html @@ -0,0 +1,5 @@ +
  • +{{ entry.created }} +{{ entry.message }} +
  • +