summaryrefslogtreecommitdiffstats
path: root/custodia/log.py
blob: a9a03451b8128b0e5950347d2366cc9f5086a9bf (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
# Copyright (C) 2015  Custodia Project Contributors - see LICENSE file

import logging
import sys

custodia_logger = logging.getLogger('custodia')
custodia_logger.addHandler(logging.NullHandler())


LOGGING_FORMAT = "%(asctime)s - %(origin)-32s - %(message)s"
LOGGING_DATEFORMAT = "%Y-%m-%d %H:%M:%S"


class OriginContextFilter(logging.Filter):
    def filter(self, record):
        if not hasattr(record, 'origin'):
            record.origin = record.name.split('.')[-1]

        return True


def setup_logging(debug=False, auditlog='custodia.audit.log'):
    # prevent multiple stream handlers
    root_logger = logging.getLogger()
    if not any(isinstance(hdlr, logging.StreamHandler)
               for hdlr in root_logger.handlers):
        default_fmt = logging.Formatter(LOGGING_FORMAT, LOGGING_DATEFORMAT)
        stream_hdlr = logging.StreamHandler(sys.stderr)
        stream_hdlr.setFormatter(default_fmt)
        stream_hdlr.addFilter(OriginContextFilter())
        root_logger.addHandler(stream_hdlr)

    custodia_logger = logging.getLogger('custodia')
    if debug:
        custodia_logger.setLevel(logging.DEBUG)
        custodia_logger.debug('Custodia debug logger enabled')
        # If the global debug is enabled, turn debug on in all custodia.
        # loggers
        logdict = logging.Logger.manager.loggerDict
        for name, obj in logdict.items():
            if not isinstance(obj, logging.Logger):
                continue
            if name.startswith('custodia.'):
                obj.setLevel(logging.DEBUG)
    else:
        custodia_logger.setLevel(logging.INFO)

    audit_logger = logging.getLogger('custodia.audit')
    if len(audit_logger.handlers) == 0:
        audit_fmt = logging.Formatter(LOGGING_FORMAT, LOGGING_DATEFORMAT)
        audit_hdrl = logging.FileHandler(auditlog)
        audit_hdrl.setFormatter(audit_fmt)
        audit_logger.addHandler(audit_hdrl)

        custodia_logger.debug('Custodia audit log: %s', auditlog)


AUDIT_NONE = 0
AUDIT_GET_ALLOWED = 1
AUDIT_GET_DENIED = 2
AUDIT_SET_ALLOWED = 3
AUDIT_SET_DENIED = 4
AUDIT_DEL_ALLOWED = 5
AUDIT_DEL_DENIED = 6
AUDIT_LAST = 7
AUDIT_SVC_NONE = 8
AUDIT_SVC_AUTH_PASS = 9
AUDIT_SVC_AUTH_FAIL = 10
AUDIT_SVC_AUTHZ_PASS = 11
AUDIT_SVC_AUTHZ_FAIL = 12
AUDIT_SVC_LAST = 13
AUDIT_MESSAGES = [
    "AUDIT FAILURE",
    "ALLOWED: '%(client)s' requested key '%(key)s'",  # AUDIT_GET_ALLOWED
    "DENIED: '%(client)s' requested key '%(key)s'",   # AUDIT_GET_DENIED
    "ALLOWED: '%(client)s' stored key '%(key)s'",     # AUDIT_SET_ALLOWED
    "DENIED: '%(client)s' stored key '%(key)s'",      # AUDIT_SET_DENIED
    "ALLOWED: '%(client)s' deleted key '%(key)s'",    # AUDIT_DEL_ALLOWED
    "DENIED: '%(client)s' deleted key '%(key)s'",     # AUDIT_DEL_DENIED
    "AUDIT FAILURE 7",
    "AUDIT FAILURE 8",
    "PASS: '%(cli)s' authenticated as '%(name)s'",  # SVC_AUTH_PASS
    "FAIL: '%(cli)s' authenticated as '%(name)s'",  # SVC_AUTH_FAIL
    "PASS: '%(cli)s' authorized for '%(name)s'",    # SVC_AUTHZ_PASS
    "FAIL: '%(cli)s' authorized for '%(name)s'",    # SVC_AUTHZ_FAIL
    "AUDIT FAILURE 13",
]


class AuditLog(object):
    def __init__(self, logger):
        self.logger = logger

    def key_access(self, origin, action, client, keyname):
        if action <= AUDIT_NONE or action >= AUDIT_LAST:
            action = AUDIT_NONE
        msg = AUDIT_MESSAGES[action]
        args = {'client': client, 'key': keyname}
        self.logger.info(msg, args, extra={'origin': origin})

    def svc_access(self, origin, action, client, name):
        if action <= AUDIT_SVC_NONE or action >= AUDIT_SVC_LAST:
            action = AUDIT_NONE
        msg = AUDIT_MESSAGES[action]
        args = {'cli': client, 'name': name}
        self.logger.info(msg, args, extra={'origin': origin})

auditlog = AuditLog(logging.getLogger('custodia.audit'))


class CustodiaPlugin(object):

    def __init__(self, config=None):
        self.config = config if config is not None else dict()
        self._auditlog = auditlog
        self.origin = self.config.get('facility_name', self.__class__.__name__)
        l = logging.getLogger(
            'custodia.plugins.%s' % self.__class__.__name__)
        self.logger = logging.LoggerAdapter(l, {'origin': self.origin})
        if self.config.get('debug', 'false').lower() == 'true':
            l.setLevel(logging.DEBUG)
        else:
            l.setLevel(logging.INFO)

    def audit_key_access(self, *args, **kwargs):
        self._auditlog.key_access(self.origin, *args, **kwargs)

    def audit_svc_access(self, *args, **kwargs):
        self._auditlog.svc_access(self.origin, *args, **kwargs)