diff --git a/atst/domain/authnid/crl/__init__.py b/atst/domain/authnid/crl/__init__.py index 3451e30e..6a5addd2 100644 --- a/atst/domain/authnid/crl/__init__.py +++ b/atst/domain/authnid/crl/__init__.py @@ -2,6 +2,7 @@ import sys import os import re import hashlib +import logging from flask import current_app as app from datetime import datetime from OpenSSL import crypto, SSL @@ -30,9 +31,9 @@ class CRLInterface: def __init__(self, *args, logger=None, **kwargs): self.logger = logger - def _log_info(self, message): + def _log(self, message, level=logging.INFO): if self.logger: - self.logger.info(message) + self.logger.log(level, message, extras={"tags": ["authorization", "crl"]}) def crl_check(self, cert): raise NotImplementedError() @@ -50,7 +51,7 @@ class NoOpCRLCache(CRLInterface): def crl_check(self, cert): cn = self._get_cn(cert) - self._log_info( + self._log( "Did not perform CRL validation for certificate with Common Name '{}'".format( cn ) @@ -111,11 +112,14 @@ class CRLCache(CRLInterface): try: return crypto.load_crl(crypto.FILETYPE_ASN1, crl_file.read()) except crypto.Error: - self._log_info("Could not load CRL at location {}".format(crl_location)) + self._log( + "Could not load CRL at location {}".format(crl_location), + level=logging.WARNING, + ) def _build_store(self, issuer): store = self.store_class() - self._log_info("STORE ID: {}. Building store.".format(id(store))) + self._log("STORE ID: {}. Building store.".format(id(store))) store.set_flags(crypto.X509StoreFlags.CRL_CHECK) crl_info = self.crl_cache.get(issuer.der(), {}) issuer_name = get_common_name(issuer) @@ -132,7 +136,7 @@ class CRLCache(CRLInterface): crl = self._load_crl(crl_info["location"]) store.add_crl(crl) - self._log_info( + self._log( "STORE ID: {}. Adding CRL with issuer Common Name {}".format( id(store), issuer_name ) @@ -158,7 +162,7 @@ class CRLCache(CRLInterface): def _add_certificate_chain_to_store(self, store, issuer): ca = self.certificate_authorities.get(issuer.der()) store.add_cert(ca) - self._log_info( + self._log( "STORE ID: {}. Adding CA with subject {}".format( id(store), ca.get_subject() ) @@ -182,10 +186,11 @@ class CRLCache(CRLInterface): except crypto.X509StoreContextError as err: if err.args[0][0] == CRL_EXPIRED_ERROR_CODE: if app.config.get("CRL_FAIL_OPEN"): - self._log_info( + self._log( "Encountered expired CRL for certificate with CN {} and issuer CN {}, failing open.".format( parsed.get_subject().CN, parsed.get_issuer().CN - ) + ), + level=logging.WARNING, ) return True else: diff --git a/atst/domain/authz/decorator.py b/atst/domain/authz/decorator.py index e9efac3a..980ee04c 100644 --- a/atst/domain/authz/decorator.py +++ b/atst/domain/authz/decorator.py @@ -45,17 +45,19 @@ def user_can_access_decorator(permission, message=None, override=None): try: check_access(permission, message, override, *args, **kwargs) app.logger.info( - "[access] User {} accessed {} {}".format( + "User {} accessed {} {}".format( g.current_user.id, request.method, request.path - ) + ), + extra={"tags": ["access", "success"]}, ) return f(*args, **kwargs) except UnauthorizedError as err: app.logger.warning( - "[access] User {} denied access {} {}".format( + "User {} denied access {} {}".format( g.current_user.id, request.method, request.path - ) + ), + extra={"tags": ["access", "failure"]}, ) raise (err) diff --git a/atst/routes/errors.py b/atst/routes/errors.py index d00c7f0a..c129e08d 100644 --- a/atst/routes/errors.py +++ b/atst/routes/errors.py @@ -15,7 +15,7 @@ from atst.utils.flash import formatted_flash as flash def log_error(e): error_message = e.message if hasattr(e, "message") else str(e) - current_app.logger.error(error_message) + current_app.logger.exception(error_message) def handle_error(e, message="Not Found", code=404): diff --git a/tests/utils.py b/tests/utils.py index 0615aec7..636f08b9 100644 --- a/tests/utils.py +++ b/tests/utils.py @@ -20,11 +20,14 @@ class FakeLogger: def __init__(self): self.messages = [] - def info(self, msg): + def log(self, _lvl, msg, *args, **kwargs): self.messages.append(msg) - def warning(self, msg): + def info(self, msg, *args, **kwargs): self.messages.append(msg) - def error(self, msg): + def warning(self, msg, *args, **kwargs): + self.messages.append(msg) + + def error(self, msg, *args, **kwargs): self.messages.append(msg)