Log all ankisyncd events under ankisyncd.*

This commit is contained in:
flan 2019-03-08 11:43:11 +01:00
parent 4214fc3da0
commit 47cf75d8d6
4 changed files with 37 additions and 24 deletions

View File

@ -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:

View File

@ -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()

View File

@ -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)

View File

@ -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)""")