diff --git a/ankisyncd/config.py b/ankisyncd/config.py index 4bbae2c..7eaaa4c 100644 --- a/ankisyncd/config.py +++ b/ankisyncd/config.py @@ -3,6 +3,8 @@ import logging import os from os.path import dirname, realpath +logger = logging.getLogger("ankisyncd") + paths = [ "/etc/ankisyncd/ankisyncd.conf", os.environ.get("XDG_CONFIG_HOME") and @@ -15,12 +17,12 @@ paths = [ # to the uppercase form of the key. E.g, `ANKISYNCD_SESSION_MANAGER` to set # `session_manager` def load_from_env(conf): - logging.debug("Loading/overriding config values from ENV") + logger.debug("Loading/overriding config values from ENV") for env in os.environ: if env.startswith('ANKISYNCD_'): config_key = env[10:].lower() conf[config_key] = os.getenv(env) - logging.info("Setting {} from ENV".format(config_key)) + logger.info("Setting {} from ENV".format(config_key)) def load(path=None): choices = paths @@ -28,11 +30,11 @@ def load(path=None): if path: choices = [path] for path in choices: - logging.debug("config.location: trying", path) + logger.debug("config.location: trying", path) try: parser.read(path) conf = parser['sync_app'] - logging.info("Loaded config from {}".format(path)) + logger.info("Loaded config from {}".format(path)) load_from_env(conf) return conf except KeyError: diff --git a/ankisyncd/sync_app.py b/ankisyncd/sync_app.py index 043d7f7..73bf5ee 100644 --- a/ankisyncd/sync_app.py +++ b/ankisyncd/sync_app.py @@ -42,6 +42,8 @@ from anki.consts import REM_CARD, REM_NOTE from ankisyncd.users import SimpleUserManager, SqliteUserManager +logger = logging.getLogger("ankisyncd") + class SyncCollectionHandler(anki.sync.Syncer): operations = ['meta', 'applyChanges', 'start', 'applyGraves', 'chunk', 'applyChunk', 'sanityCheck2', 'finish'] @@ -292,12 +294,12 @@ class SyncMediaHandler(anki.sync.MediaSyncer): [(f, ) for f in filenames]) # Remove the files from our media directory if it is present. - logging.debug('Removing %d files from media dir.' % len(filenames)) + logger.debug('Removing %d files from media dir.' % len(filenames)) for filename in filenames: try: os.remove(os.path.join(self.col.media.dir(), filename)) except OSError as err: - logging.error("Error when removing file '%s' from media dir: " + logger.error("Error when removing file '%s' from media dir: " "%s" % (filename, str(err))) def downloadFiles(self, files): @@ -422,7 +424,7 @@ class SyncApp: if "auth_db_path" in config: self.user_manager = SqliteUserManager(config['auth_db_path']) else: - logging.warn("auth_db_path not set, ankisyncd will accept any password") + logger.warn("auth_db_path not set, ankisyncd will accept any password") self.user_manager = SimpleUserManager() self.collection_manager = getCollectionManager() @@ -770,10 +772,10 @@ def main(): httpd = make_server(config['host'], int(config['port']), ankiserver) try: - logging.info("Serving HTTP on {} port {}...".format(*httpd.server_address)) + logger.info("Serving HTTP on {} port {}...".format(*httpd.server_address)) httpd.serve_forever() except KeyboardInterrupt: - logging.info("Exiting...") + logger.info("Exiting...") finally: shutdown() diff --git a/ankisyncd/thread.py b/ankisyncd/thread.py index ebb0fa5..4ac9aaf 100644 --- a/ankisyncd/thread.py +++ b/ankisyncd/thread.py @@ -3,7 +3,7 @@ from ankisyncd.collection import CollectionWrapper, CollectionManager from threading import Thread from queue import Queue -import time, logging +import time, logging, os.path class ThreadingCollectionWrapper: """Provides the same interface as CollectionWrapper, but it creates a new Thread to @@ -12,6 +12,9 @@ class ThreadingCollectionWrapper: def __init__(self, path, setup_new_collection=None): self.path = path self.wrapper = CollectionWrapper(path, setup_new_collection) + # FIXME: this might not work for other collection wrappers, introduce self.wrapper.name? + self._name = os.path.basename(os.path.dirname(self.wrapper.path)) + self.logger = logging.getLogger("ankisyncd." + str(self)) self._queue = Queue() self._thread = None @@ -20,6 +23,9 @@ class ThreadingCollectionWrapper: self.start() + def __str__(self): + return "CollectionThread[{}]".format(self._name) # TODO: self.wrapper.name? + @property def running(self): return self._running @@ -53,7 +59,7 @@ class ThreadingCollectionWrapper: return ret def _run(self): - logging.info('CollectionThread[%s]: Starting...', self.path) + self.logger.info("Starting...") try: while self._running: @@ -64,13 +70,13 @@ class ThreadingCollectionWrapper: else: func_name = func.__class__.__name__ - logging.info('CollectionThread[%s]: Running %s(*%s, **%s)', self.path, func_name, repr(args), repr(kw)) + self.logger.info("Running %s(*%s, **%s)", func_name, repr(args), repr(kw)) self.last_timestamp = time.time() try: ret = self.wrapper.execute(func, args, kw, return_queue) except Exception as e: - logging.error('CollectionThread[%s]: Unable to %s(*%s, **%s): %s', + self.logger.error("Unable to %s(*%s, **%s): %s", self.path, func_name, repr(args), repr(kw), e, exc_info=True) # we return the Exception which will be raise'd on the other end ret = e @@ -78,7 +84,7 @@ class ThreadingCollectionWrapper: if return_queue is not None: return_queue.put(ret) except Exception as e: - logging.error('CollectionThread[%s]: Thread crashed! Exception: %s', self.path, e, exc_info=True) + self.logger.error("Thread crashed! Exception: %s", e, exc_info=True) finally: self.wrapper.close() # clean out old thread object @@ -86,7 +92,7 @@ class ThreadingCollectionWrapper: # in case we got here via an exception self._running = False - logging.info('CollectionThread[%s]: Stopped!', self.path) + self.logger.info("Stopped!") def start(self): if not self._running: @@ -134,6 +140,7 @@ class ThreadingCollectionManager(CollectionManager): self.monitor_frequency = 15 self.monitor_inactivity = 90 + self.logger = logging.getLogger("ankisyncd.ThreadingCollectionManager") monitor = Thread(target=self._monitor_run) monitor.daemon = True @@ -153,7 +160,7 @@ class ThreadingCollectionManager(CollectionManager): cur = time.time() for path, thread in self.collections.items(): if thread.running and thread.wrapper.opened() and thread.qempty() and cur - thread.last_timestamp >= self.monitor_inactivity: - logging.info('Monitor is closing collection on inactive CollectionThread[%s]', thread.path) + self.logger.info("Monitor is closing collection on inactive %s", thread) thread.close() time.sleep(self.monitor_frequency) diff --git a/ankisyncd/users.py b/ankisyncd/users.py index 1a2c807..5418725 100644 --- a/ankisyncd/users.py +++ b/ankisyncd/users.py @@ -5,6 +5,8 @@ import logging import os import sqlite3 as sqlite +logger = logging.getLogger("ankisyncd.users") + class SimpleUserManager: """A simple user manager that always allows any user.""" @@ -32,7 +34,7 @@ class SimpleUserManager: def _create_user_dir(self, username): user_dir_path = os.path.join(self.collection_path, username) if not os.path.isdir(user_dir_path): - logging.info("Creating collection directory for user '{}' at {}" + logger.info("Creating collection directory for user '{}' at {}" .format(username, user_dir_path)) os.makedirs(user_dir_path) @@ -70,7 +72,7 @@ class SqliteUserManager(SimpleUserManager): conn = sqlite.connect(self.auth_db_path) cursor = conn.cursor() - logging.info("Removing user '{}' from auth db".format(username)) + logger.info("Removing user '{}' from auth db".format(username)) cursor.execute("DELETE FROM auth WHERE user=?", (username,)) conn.commit() conn.close() @@ -91,7 +93,7 @@ class SqliteUserManager(SimpleUserManager): conn = sqlite.connect(self.auth_db_path) cursor = conn.cursor() - logging.info("Adding user '{}' to auth db.".format(username)) + logger.info("Adding user '{}' to auth db.".format(username)) cursor.execute("INSERT INTO auth VALUES (?, ?)", (username, pass_hash)) conn.commit() @@ -111,7 +113,7 @@ class SqliteUserManager(SimpleUserManager): conn.commit() conn.close() - logging.info("Changed password for user {}".format(username)) + logger.info("Changed password for user {}".format(username)) def authenticate(self, username, password): """Returns True if this username is allowed to connect with this password. False otherwise.""" @@ -124,7 +126,7 @@ class SqliteUserManager(SimpleUserManager): conn.close() if db_hash is None: - logging.info("Authentication failed for nonexistent user {}." + logger.info("Authentication failed for nonexistent user {}." .format(username)) return False @@ -136,10 +138,10 @@ class SqliteUserManager(SimpleUserManager): actual_value = hashobj.hexdigest() + salt if actual_value == expected_value: - logging.info("Authentication succeeded for user {}".format(username)) + logger.info("Authentication succeeded for user {}".format(username)) return True else: - logging.info("Authentication failed for user {}".format(username)) + logger.info("Authentication failed for user {}".format(username)) return False @staticmethod @@ -156,7 +158,7 @@ class SqliteUserManager(SimpleUserManager): def create_auth_db(self): conn = sqlite.connect(self.auth_db_path) cursor = conn.cursor() - logging.info("Creating auth db at {}." + logger.info("Creating auth db at {}." .format(self.auth_db_path)) cursor.execute("""CREATE TABLE IF NOT EXISTS auth (user VARCHAR PRIMARY KEY, hash VARCHAR)""")