From edd5cd333e2465f5b79a063243afd61e65d6d82b Mon Sep 17 00:00:00 2001 From: Simo Sorce Date: Wed, 21 Oct 2015 17:31:21 -0400 Subject: Improve logging format and configuration This patch adda an 'origin' argument to the logger formatting that coms from the configuration parser and ties a log entry to the implementing class as well as the specific configuration facility that instantiated it. Also adds per configuration section debugging unless the global debug statment is true, in which case all objects have debugging forcibly turned on. Signed-off-by: Simo Sorce Reviewed-by: Christian Heimes --- custodia/custodia | 5 ++-- custodia/httpd/authenticators.py | 62 +++++++++++++++------------------------ custodia/httpd/authorizers.py | 37 +++++++++-------------- custodia/httpd/consumer.py | 4 ++- custodia/httpd/server.py | 11 +++---- custodia/log.py | 63 +++++++++++++++++++++++++++++++--------- custodia/secrets.py | 12 +++----- custodia/store/enclite.py | 6 +--- custodia/store/etcdstore.py | 39 ++++++++++++------------- custodia/store/interface.py | 4 ++- custodia/store/sqlite.py | 45 ++++++++++++++-------------- 11 files changed, 146 insertions(+), 142 deletions(-) diff --git a/custodia/custodia b/custodia/custodia index 56652de..8d69dea 100755 --- a/custodia/custodia +++ b/custodia/custodia @@ -82,20 +82,19 @@ def parse_config(cfgfile): raise ValueError('Invalid section, missing "handler"') handler = None - hconf = None + hconf = {'facility_name': s} for opt, val in parser.items(s): if opt == 'handler': try: module, classname = val.rsplit('.', 1) m = importlib.import_module(module) handler = getattr(m, classname) + hconf['facility_name'] = '%s-[%s]' % (classname, s) except Exception as e: # pylint: disable=broad-except raise ValueError('Invalid format for "handler" option ' '[%r]: %s' % (e, val)) else: - if hconf is None: - hconf = dict() hconf[opt] = val config[menu][name] = handler(hconf) diff --git a/custodia/httpd/authenticators.py b/custodia/httpd/authenticators.py index 854fdc7..ecd3d30 100644 --- a/custodia/httpd/authenticators.py +++ b/custodia/httpd/authenticators.py @@ -1,6 +1,5 @@ # Copyright (C) 2015 Custodia Project Contributors - see LICENSE file -import logging import os from cryptography.hazmat.primitives import constant_time @@ -8,14 +7,8 @@ from cryptography.hazmat.primitives import constant_time from custodia import log from custodia.httpd.server import HTTPError -logger = logging.getLogger(__name__) - -class HTTPAuthenticator(object): - - def __init__(self, config=None): - self.config = config - self._auditlog = log.auditlog +class HTTPAuthenticator(log.CustodiaPlugin): def handle(self, request): raise HTTPError(403) @@ -35,19 +28,19 @@ class SimpleCredsAuth(HTTPAuthenticator): def handle(self, request): creds = request.get('creds') if creds is None: - logger.debug('SCA: Missing "creds" from request') + self.logger.debug('SCA: Missing "creds" from request') return False uid = int(creds['gid']) gid = int(creds['uid']) if self._gid == gid or self._uid == uid: - self._auditlog.svc_access(log.AUDIT_SVC_AUTH_PASS, - request['client_id'], - "SCA", "%d, %d" % (uid, gid)) + self.audit_svc_access(log.AUDIT_SVC_AUTH_PASS, + request['client_id'], + "%d, %d" % (uid, gid)) return True else: - self._auditlog.svc_access(log.AUDIT_SVC_AUTH_FAIL, - request['client_id'], - "SCA", "%d, %d" % (uid, gid)) + self.audit_svc_access(log.AUDIT_SVC_AUTH_FAIL, + request['client_id'], + "%d, %d" % (uid, gid)) return False @@ -64,7 +57,7 @@ class SimpleHeaderAuth(HTTPAuthenticator): def handle(self, request): if self.name not in request['headers']: - logger.debug('SHA: No "headers" in request') + self.logger.debug('SHA: No "headers" in request') return None value = request['headers'][self.name] if self.value is None: @@ -72,25 +65,21 @@ class SimpleHeaderAuth(HTTPAuthenticator): pass elif isinstance(self.value, str): if value != self.value: - self._auditlog.svc_access(log.AUDIT_SVC_AUTH_FAIL, - request['client_id'], - "SHA", value) + self.audit_svc_access(log.AUDIT_SVC_AUTH_FAIL, + request['client_id'], value) return False elif isinstance(self.value, list): if value not in self.value: - self._auditlog.svc_access(log.AUDIT_SVC_AUTH_FAIL, - request['client_id'], - "SHA", value) + self.audit_svc_access(log.AUDIT_SVC_AUTH_FAIL, + request['client_id'], value) return False else: - self._auditlog.svc_access(log.AUDIT_SVC_AUTH_FAIL, - request['client_id'], - "SHA", value) + self.audit_svc_access(log.AUDIT_SVC_AUTH_FAIL, + request['client_id'], value) return False - self._auditlog.svc_access(log.AUDIT_SVC_AUTH_PASS, - request['client_id'], - "SHA", value) + self.audit_svc_access(log.AUDIT_SVC_AUTH_PASS, + request['client_id'], value) request['remote_user'] = value return True @@ -112,7 +101,7 @@ class SimpleAuthKeys(HTTPAuthenticator): name = request['headers'].get(self.id_header, None) key = request['headers'].get(self.key_header, None) if name is None and key is None: - logger.debug('SAK: Ignoring request no relevant headers provided') + self.logger.debug('Ignoring request no relevant headers provided') return None validated = False @@ -124,19 +113,16 @@ class SimpleAuthKeys(HTTPAuthenticator): key.encode('utf-8')): validated = True except Exception: - self._auditlog.svc_access(log.AUDIT_SVC_AUTH_FAIL, - request['client_id'], - "SAK", name) + self.audit_svc_access(log.AUDIT_SVC_AUTH_FAIL, + request['client_id'], name) return False if validated: - self._auditlog.svc_access(log.AUDIT_SVC_AUTH_PASS, - request['client_id'], - "SAK", name) + self.audit_svc_access(log.AUDIT_SVC_AUTH_PASS, + request['client_id'], name) request['remote_user'] = name return True - self._auditlog.svc_access(log.AUDIT_SVC_AUTH_FAIL, - request['client_id'], - "SAK", name) + self.audit_svc_access(log.AUDIT_SVC_AUTH_FAIL, + request['client_id'], name) return False diff --git a/custodia/httpd/authorizers.py b/custodia/httpd/authorizers.py index 292abf1..9827407 100644 --- a/custodia/httpd/authorizers.py +++ b/custodia/httpd/authorizers.py @@ -1,18 +1,14 @@ # Copyright (C) 2015 Custodia Project Contributors - see LICENSE file -import logging import os from custodia import log -logger = logging.getLogger(__name__) - -class HTTPAuthorizer(object): +class HTTPAuthorizer(log.CustodiaPlugin): def __init__(self, config=None): - self.config = config - self._auditlog = log.auditlog + super(HTTPAuthorizer, self).__init__(config) self.store_name = None if self.config and 'store' in self.config: self.store_name = self.config['store'] @@ -42,23 +38,21 @@ class SimplePathAuthz(HTTPAuthorizer): # special case to match a path ending in / authz = authz[:-1] if authz == path: - self._auditlog.svc_access(log.AUDIT_SVC_AUTHZ_PASS, - request['client_id'], - "SPA", path) + self.audit_svc_access(log.AUDIT_SVC_AUTHZ_PASS, + request['client_id'], path) return True while path != '': if path in self.paths: - self._auditlog.svc_access(log.AUDIT_SVC_AUTHZ_PASS, - request['client_id'], - "SPA", path) + self.audit_svc_access(log.AUDIT_SVC_AUTHZ_PASS, + request['client_id'], path) return True if path == '/': path = '' else: path, _ = os.path.split(path) - logger.debug('SPA: No path in %s matched %s', self.paths, reqpath) + self.logger.debug('No path in %s matched %s', self.paths, reqpath) return None @@ -72,27 +66,24 @@ class UserNameSpace(HTTPAuthorizer): # Only check if we are in the right (sub)path path = request.get('path', '/') if not path.startswith(self.path): - logger.debug('UNS: %s is not contained in %s', path, self.path) + self.logger.debug('%s is not contained in %s', path, self.path) return None name = request.get('remote_user', None) if name is None: # UserNameSpace requires a user ... - self._auditlog.svc_access(log.AUDIT_SVC_AUTHZ_FAIL, - request['client_id'], - "UNS(%s)" % self.path, path) + self.audit_svc_access(log.AUDIT_SVC_AUTHZ_FAIL, + request['client_id'], path) return False namespace = self.path.rstrip('/') + '/' + name + '/' if not path.startswith(namespace): # Not in the namespace - self._auditlog.svc_access(log.AUDIT_SVC_AUTHZ_FAIL, - request['client_id'], - "UNS(%s)" % self.path, path) + self.audit_svc_access(log.AUDIT_SVC_AUTHZ_FAIL, + request['client_id'], path) return False request['default_namespace'] = name - self._auditlog.svc_access(log.AUDIT_SVC_AUTHZ_PASS, - request['client_id'], - "UNS(%s)" % self.path, path) + self.audit_svc_access(log.AUDIT_SVC_AUTHZ_PASS, + request['client_id'], path) return True diff --git a/custodia/httpd/consumer.py b/custodia/httpd/consumer.py index bf0c393..9f0a6d5 100644 --- a/custodia/httpd/consumer.py +++ b/custodia/httpd/consumer.py @@ -1,15 +1,17 @@ # Copyright (C) 2015 Custodia Project Contributors - see LICENSE file from custodia.httpd.server import HTTPError +from custodia.log import CustodiaPlugin DEFAULT_CTYPE = 'text/html; charset=utf-8' SUPPORTED_COMMANDS = ['GET', 'PUT', 'POST', 'DELETE'] -class HTTPConsumer(object): +class HTTPConsumer(CustodiaPlugin): def __init__(self, config=None): + super(HTTPConsumer, self).__init__(config) self.config = config self.store_name = None if config and 'store' in config: diff --git a/custodia/httpd/server.py b/custodia/httpd/server.py index b1440ab..2608f3c 100644 --- a/custodia/httpd/server.py +++ b/custodia/httpd/server.py @@ -328,9 +328,9 @@ class HTTPRequestHandler(BaseHTTPRequestHandler): elif valid is True: valid_once = True if valid_once is not True: - self.server._auditlog.svc_access(log.AUDIT_SVC_AUTH_FAIL, - request['client_id'], "MAIN", - 'No auth') + self.server._auditlog.svc_access(self.__class__.__name__, + log.AUDIT_SVC_AUTH_FAIL, + request['client_id'], 'No auth') raise HTTPError(403) # auhz framework here @@ -342,8 +342,9 @@ class HTTPRequestHandler(BaseHTTPRequestHandler): if valid is not None: break if valid is not True: - self.server._auditlog.svc_access(log.AUDIT_SVC_AUTHZ_FAIL, - request['client_id'], "MAIN", + self.server._auditlog.svc_access(self.__class__.__name__, + log.AUDIT_SVC_AUTHZ_FAIL, + request['client_id'], request.get('path', '/')) raise HTTPError(403) diff --git a/custodia/log.py b/custodia/log.py index 947af75..a9a0345 100644 --- a/custodia/log.py +++ b/custodia/log.py @@ -7,9 +7,16 @@ custodia_logger = logging.getLogger('custodia') custodia_logger.addHandler(logging.NullHandler()) -LOGGING_FORMAT = "%(asctime)s - %(name)s - %(levelname)s - %(message)s" -LOGGING_AUDITFORMAT = "%(asctime)s %(message)s" -LOGGING_DATEFORMAT = "%Y-%m-%h %H:%M:%S" +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'): @@ -20,18 +27,27 @@ def setup_logging(debug=False, auditlog='custodia.audit.log'): 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_AUDITFORMAT, LOGGING_DATEFORMAT) + audit_fmt = logging.Formatter(LOGGING_FORMAT, LOGGING_DATEFORMAT) audit_hdrl = logging.FileHandler(auditlog) audit_hdrl.setFormatter(audit_fmt) audit_logger.addHandler(audit_hdrl) @@ -63,10 +79,10 @@ AUDIT_MESSAGES = [ "DENIED: '%(client)s' deleted key '%(key)s'", # AUDIT_DEL_DENIED "AUDIT FAILURE 7", "AUDIT FAILURE 8", - "PASS(%(tag)s): '%(cli)s' authenticated as '%(name)s'", # SVC_AUTH_PASS - "FAIL(%(tag)s): '%(cli)s' authenticated as '%(name)s'", # SVC_AUTH_FAIL - "PASS(%(tag)s): '%(cli)s' authorized for '%(name)s'", # SVC_AUTHZ_PASS - "FAIL(%(tag)s): '%(cli)s' authorized for '%(name)s'", # SVC_AUTHZ_FAIL + "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", ] @@ -75,18 +91,39 @@ class AuditLog(object): def __init__(self, logger): self.logger = logger - def key_access(self, action, client, keyname): + 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) + self.logger.info(msg, args, extra={'origin': origin}) - def svc_access(self, action, client, tag, name): + 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, 'tag': tag, 'name': name} - self.logger.info(msg, args) + 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) diff --git a/custodia/secrets.py b/custodia/secrets.py index aeaa560..1c3248d 100644 --- a/custodia/secrets.py +++ b/custodia/secrets.py @@ -17,9 +17,6 @@ from custodia.store.interface import CSStoreExists from custodia.store.sqlite import SqliteStore -logger = logging.getLogger(__name__) - - class Secrets(HTTPConsumer): def __init__(self, *args, **kwargs): @@ -29,7 +26,6 @@ class Secrets(HTTPConsumer): kt = self.config['allowed_keytypes'].split() self.allowed_keytypes = kt self._validator = Validator(self.allowed_keytypes) - self._auditlog = log.auditlog def _db_key(self, trail): if len(trail) < 2: @@ -61,8 +57,8 @@ class Secrets(HTTPConsumer): except CSStoreError: raise HTTPError(500) - logger.debug('parent_exists: %s (%s, %r) -> %r', - basename, default, trail, keylist) + self.logger.debug('parent_exists: %s (%s, %r) -> %r', + basename, default, trail, keylist) if keylist is not None: return True @@ -110,7 +106,7 @@ class Secrets(HTTPConsumer): basename = self._db_container_key(default, trail) try: keylist = self.root.store.list(basename) - logger.debug('list %s returned %r', basename, keylist) + self.logger.debug('list %s returned %r', basename, keylist) if keylist is None: raise HTTPError(404) response['output'] = json.dumps(keylist) @@ -168,7 +164,7 @@ class Secrets(HTTPConsumer): fn(trail, request, response) action = ok finally: - self._auditlog.key_access(action, client, key) + self.audit_key_access(action, client, key) def _get_key(self, trail, request, response): self._audit(log.AUDIT_GET_ALLOWED, log.AUDIT_GET_DENIED, diff --git a/custodia/store/enclite.py b/custodia/store/enclite.py index c5b883f..8c1f9c8 100644 --- a/custodia/store/enclite.py +++ b/custodia/store/enclite.py @@ -1,7 +1,5 @@ # Copyright (C) 2015 Custodia Project Contributors - see LICENSE file -import logging - from jwcrypto.common import json_decode, json_encode from jwcrypto.jwe import JWE from jwcrypto.jwk import JWK @@ -9,8 +7,6 @@ from jwcrypto.jwk import JWK from custodia.store.interface import CSStoreError from custodia.store.sqlite import SqliteStore -logger = logging.getLogger(__name__) - class EncryptedStore(SqliteStore): @@ -40,7 +36,7 @@ class EncryptedStore(SqliteStore): jwe.deserialize(value, self.mkey) return jwe.payload.decode('utf-8') except Exception: - logger.exception("Error parsing key %s", key) + self.logger.exception("Error parsing key %s", key) raise CSStoreError('Error occurred while trying to parse key') def set(self, key, value, replace=False): diff --git a/custodia/store/etcdstore.py b/custodia/store/etcdstore.py index 46c6943..44d7075 100644 --- a/custodia/store/etcdstore.py +++ b/custodia/store/etcdstore.py @@ -2,19 +2,15 @@ from __future__ import print_function -import logging - import etcd from custodia.store.interface import CSStore, CSStoreError, CSStoreExists -logger = logging.getLogger(__name__) - - class EtcdStore(CSStore): def __init__(self, config): + super(EtcdStore, self).__init__(config) self.server = config.get('etcd_server', '127.0.0.1') self.port = int(config.get('etcd_port', 4001)) self.namespace = config.get('namespace', "/custodia") @@ -27,7 +23,8 @@ class EtcdStore(CSStore): # Already exists pass except etcd.EtcdException: - logger.exception("Error creating namespace %s", self.namespace) + self.logger.exception("Error creating namespace %s", + self.namespace) raise CSStoreError('Error occurred while trying to init db') def _absolute_key(self, key): @@ -40,51 +37,51 @@ class EtcdStore(CSStore): return '/'.join([self.namespace] + parts).replace('//', '/') def get(self, key): - logger.debug("Fetching key %s", key) + self.logger.debug("Fetching key %s", key) try: result = self.etcd.get(self._absolute_key(key)) except etcd.EtcdException: - logger.exception("Error fetching key %s", key) + self.logger.exception("Error fetching key %s", key) raise CSStoreError('Error occurred while trying to get key') - logger.debug("Fetched key %s got result: %r", key, result) + self.logger.debug("Fetched key %s got result: %r", key, result) return result.value def set(self, key, value, replace=False): - logger.debug("Setting key %s to value %s (replace=%s)", key, value, - replace) + self.logger.debug("Setting key %s to value %s (replace=%s)", + key, value, replace) path = self._absolute_key(key) try: self.etcd.write(path, value, prevExist=replace) except etcd.EtcdAlreadyExist as err: raise CSStoreExists(str(err)) except etcd.EtcdException: - logger.exception("Error storing key %s", key) + self.logger.exception("Error storing key %s", key) raise CSStoreError('Error occurred while trying to store key') def span(self, key): path = self._absolute_key(key) - logger.debug("Creating directory %s", path) + self.logger.debug("Creating directory %s", path) try: self.etcd.write(path, None, dir=True, prevExist=False) except etcd.EtcdAlreadyExist as err: raise CSStoreExists(str(err)) except etcd.EtcdException: - logger.exception("Error storing key %s", key) + self.logger.exception("Error storing key %s", key) raise CSStoreError('Error occurred while trying to store key') def list(self, keyfilter='/'): path = self._absolute_key(keyfilter) if path != '/': path = path.rstrip('/') - logger.debug("Listing keys matching %s", path) + self.logger.debug("Listing keys matching %s", path) try: result = self.etcd.read(path, recursive=True) except etcd.EtcdKeyNotFound: return None except etcd.EtcdException: - logger.exception("Error listing %s", keyfilter) + self.logger.exception("Error listing %s", keyfilter) raise CSStoreError('Error occurred while trying to list keys') - logger.debug("Searched for %s got result: %r", path, result) + self.logger.debug("Searched for %s got result: %r", path, result) value = set() for entry in result.get_subtree(): if entry.key == path: @@ -96,14 +93,14 @@ class EtcdStore(CSStore): return sorted(value) def cut(self, key): - logger.debug("Removing key %s", key) + self.logger.debug("Removing key %s", key) try: self.etcd.delete(self._absolute_key(key)) except etcd.EtcdKeyNotFound: - logger.debug("Key %s not found", key) + self.logger.debug("Key %s not found", key) return False except etcd.EtcdException: - logger.exception("Error removing key %s", key) + self.logger.exception("Error removing key %s", key) raise CSStoreError('Error occurred while trying to cut key') - logger.debug("Key %s removed", key) + self.logger.debug("Key %s removed", key) return True diff --git a/custodia/store/interface.py b/custodia/store/interface.py index 37857fe..22ca143 100644 --- a/custodia/store/interface.py +++ b/custodia/store/interface.py @@ -2,6 +2,8 @@ import logging +from custodia.log import CustodiaPlugin + logger = logging.getLogger(__name__) @@ -17,7 +19,7 @@ class CSStoreExists(Exception): super(CSStoreExists, self).__init__(message) -class CSStore(object): +class CSStore(CustodiaPlugin): def get(self, key): raise NotImplementedError diff --git a/custodia/store/sqlite.py b/custodia/store/sqlite.py index 936c8d0..4c4b5af 100644 --- a/custodia/store/sqlite.py +++ b/custodia/store/sqlite.py @@ -2,7 +2,6 @@ from __future__ import print_function -import logging import os import sqlite3 import unittest @@ -10,12 +9,10 @@ import unittest from custodia.store.interface import CSStore, CSStoreError, CSStoreExists -logger = logging.getLogger(__name__) - - class SqliteStore(CSStore): def __init__(self, config): + super(SqliteStore, self).__init__(config) if 'dburi' not in config: raise ValueError('Missing "dburi" for Sqlite Store') self.dburi = config['dburi'] @@ -31,11 +28,11 @@ class SqliteStore(CSStore): c = conn.cursor() self._create(c) except sqlite3.Error: - logger.exception("Error creating table %s", self.table) + self.logger.exception("Error creating table %s", self.table) raise CSStoreError('Error occurred while trying to init db') def get(self, key): - logger.debug("Fetching key %s", key) + self.logger.debug("Fetching key %s", key) query = "SELECT value from %s WHERE key=?" % self.table try: conn = sqlite3.connect(self.dburi) @@ -43,9 +40,9 @@ class SqliteStore(CSStore): r = c.execute(query, (key,)) value = r.fetchall() except sqlite3.Error: - logger.exception("Error fetching key %s", key) + self.logger.exception("Error fetching key %s", key) raise CSStoreError('Error occurred while trying to get key') - logger.debug("Fetched key %s got result: %r", key, value) + self.logger.debug("Fetched key %s got result: %r", key, value) if len(value) > 0: return value[0][0] else: @@ -57,8 +54,8 @@ class SqliteStore(CSStore): cur.execute(create) def set(self, key, value, replace=False): - logger.debug("Setting key %s to value %s (replace=%s)", key, value, - replace) + self.logger.debug("Setting key %s to value %s (replace=%s)", + key, value, replace) if key.endswith('/'): raise ValueError('Invalid Key name, cannot end in "/"') if replace: @@ -75,12 +72,12 @@ class SqliteStore(CSStore): except sqlite3.IntegrityError as err: raise CSStoreExists(str(err)) except sqlite3.Error as err: - logger.exception("Error storing key %s", key) + self.logger.exception("Error storing key %s", key) raise CSStoreError('Error occurred while trying to store key') def span(self, key): name = key.rstrip('/') - logger.debug("Creating container %s", name) + self.logger.debug("Creating container %s", name) query = "INSERT into %s VALUES (?, '')" setdata = query % (self.table,) try: @@ -92,12 +89,12 @@ class SqliteStore(CSStore): except sqlite3.IntegrityError as err: raise CSStoreExists(str(err)) except sqlite3.Error: - logger.exception("Error creating key %s", name) + self.logger.exception("Error creating key %s", name) raise CSStoreError('Error occurred while trying to span container') def list(self, keyfilter=''): path = keyfilter.rstrip('/') - logger.debug("Listing keys matching %s", path) + self.logger.debug("Listing keys matching %s", path) child_prefix = path if path == '' else path + '/' search = "SELECT key FROM %s WHERE key LIKE ?" % self.table key = "%s%%" % (path,) @@ -106,9 +103,9 @@ class SqliteStore(CSStore): r = conn.execute(search, (key,)) rows = r.fetchall() except sqlite3.Error: - logger.exception("Error listing %s: [%r]", keyfilter) + self.logger.exception("Error listing %s: [%r]", keyfilter) raise CSStoreError('Error occurred while trying to list keys') - logger.debug("Searched for %s got result: %r", path, rows) + self.logger.debug("Searched for %s got result: %r", path, rows) if len(rows) > 0: parent_exists = False value = list() @@ -121,19 +118,19 @@ class SqliteStore(CSStore): value.append(row[0][len(child_prefix):].lstrip('/')) if value: - logger.debug("Returning sorted values %r", value) + self.logger.debug("Returning sorted values %r", value) return sorted(value) elif parent_exists: - logger.debug("Returning empty list") + self.logger.debug("Returning empty list") return [] elif keyfilter == '': - logger.debug("Returning empty list") + self.logger.debug("Returning empty list") return [] - logger.debug("Returning 'Not Found'") + self.logger.debug("Returning 'Not Found'") return None def cut(self, key): - logger.debug("Removing key %s", key) + self.logger.debug("Removing key %s", key) query = "DELETE from %s WHERE key=?" % self.table try: conn = sqlite3.connect(self.dburi) @@ -141,10 +138,10 @@ class SqliteStore(CSStore): c = conn.cursor() r = c.execute(query, (key,)) except sqlite3.Error: - logger.error("Error removing key %s", key) + self.logger.error("Error removing key %s", key) raise CSStoreError('Error occurred while trying to cut key') - logger.debug("Key %s %s", key, - "removed" if r.rowcount > 0 else "not found") + self.logger.debug("Key %s %s", key, + "removed" if r.rowcount > 0 else "not found") if r.rowcount > 0: return True return False -- cgit