diff --git a/packages/flamenco-worker-python/flamenco-worker.cfg b/packages/flamenco-worker-python/flamenco-worker.cfg
index 524f73dc5cd8b832bc72d5aa2c54520213111a32..caf545992f9a76b7137fa98931939bd975ed6b68 100644
--- a/packages/flamenco-worker-python/flamenco-worker.cfg
+++ b/packages/flamenco-worker-python/flamenco-worker.cfg
@@ -2,3 +2,36 @@
manager_url = http://localhost:8083/
job_types = sleep blender-render
task_update_queue_db = flamenco-worker.db
+
+[loggers]
+keys = root,flamenco_worker
+
+[logger_root]
+level = WARNING
+handlers = console,file
+
+[logger_flamenco_worker]
+level = INFO
+qualname = flamenco_worker
+handlers = console,file
+propagate = 0
+
+[handlers]
+keys = console,file
+
+[handler_console]
+class = logging.StreamHandler
+formatter = flamenco
+args = (sys.stderr,)
+
+[handler_file]
+class = logging.handlers.TimedRotatingFileHandler
+formatter = flamenco
+# (filename, when, interval, backupCount, encoding, delay, utc, atTime=None)
+args = ('/tmp/flamenco-worker.log', 'midnight', 1, 7, 'utf8', True, True)
+
+[formatters]
+keys = flamenco
+
+[formatter_flamenco]
+format = %(asctime)-15s %(levelname)8s %(name)s %(message)s
diff --git a/packages/flamenco-worker-python/flamenco_worker/cli.py b/packages/flamenco-worker-python/flamenco_worker/cli.py
index 7e10f82c82941e17b436149e6d0bc1740a3fdc3d..a3ea94e47d3dd69a673f3229c7d9a352e805a485 100644
--- a/packages/flamenco-worker-python/flamenco_worker/cli.py
+++ b/packages/flamenco-worker-python/flamenco_worker/cli.py
@@ -11,48 +11,18 @@ def main():
parser = argparse.ArgumentParser()
parser.add_argument('-c', '--config',
help='Load this configuration file instead of the default files.')
- parser.add_argument('-q', '--quiet', action='store_true',
- help='Log less (only WARNING and more severe).')
parser.add_argument('-v', '--verbose', action='store_true',
- help='Log more (DEBUG and more severe).')
+ help='Show configuration before starting, '
+ 'and asyncio task status at shutdown.')
args = parser.parse_args()
- # Set up logging
- if args.quiet:
- level = 'WARNING'
- elif args.verbose:
- level = 'DEBUG'
- else:
- level = 'INFO'
- logging.config.dictConfig({
- 'version': 1,
- 'formatters': {
- 'default': {'format': '%(asctime)-15s %(levelname)8s %(name)s %(message)s'}
- },
- 'handlers': {
- 'console': {
- 'class': 'logging.StreamHandler',
- 'formatter': 'default',
- 'stream': 'ext://sys.stderr',
- }
- },
- 'loggers': {
- 'flamenco_worker': {'level': level},
- },
- 'root': {
- 'level': 'WARNING',
- 'handlers': [
- 'console',
- ],
- }
- })
-
- log = logging.getLogger(__name__)
- log.debug('Starting')
-
# Load configuration
from . import config
confparser = config.load_config(args.config, args.verbose)
+ config.configure_logging(confparser)
+
+ log = logging.getLogger(__name__)
+ log.debug('Starting')
# Construct the AsyncIO loop
loop = construct_asyncio_loop()
@@ -126,11 +96,12 @@ def main():
log.warning('Closing asyncio loop')
# Report on the asyncio task status
- all_tasks = asyncio.Task.all_tasks()
- if not len(all_tasks):
- log.debug('no more scheduled tasks, this is a clean shutdown.')
- elif all(task.done() for task in all_tasks):
- log.debug('all %i tasks are done, this is a clean shutdown.', len(all_tasks))
+ if args.verbose:
+ all_tasks = asyncio.Task.all_tasks()
+ if not len(all_tasks):
+ log.info('no more scheduled tasks, this is a clean shutdown.')
+ elif all(task.done() for task in all_tasks):
+ log.info('all %i tasks are done, this is a clean shutdown.', len(all_tasks))
import gc
import traceback
@@ -145,15 +116,15 @@ def main():
# noinspection PyBroadException
try:
res = task.result()
- log.debug(' task #%i: %s result=%r', task_idx, task, res)
+ log.info(' task #%i: %s result=%r', task_idx, task, res)
except asyncio.CancelledError:
# No problem, we want to stop anyway.
- log.debug(' task #%i: %s cancelled', task_idx, task)
+ log.info(' task #%i: %s cancelled', task_idx, task)
except Exception:
print('{}: resulted in exception'.format(task))
traceback.print_exc()
# for ref in gc.get_referrers(task):
- # log.debug(' - referred by %s', ref)
+ # log.info(' - referred by %s', ref)
loop.close()
diff --git a/packages/flamenco-worker-python/flamenco_worker/config.py b/packages/flamenco-worker-python/flamenco_worker/config.py
index f8f6710a7c0e76afbdfe418d6dca3dca11918f5b..4f3b112ae618704810cc5c037802d6d6e96cb108 100644
--- a/packages/flamenco-worker-python/flamenco_worker/config.py
+++ b/packages/flamenco-worker-python/flamenco_worker/config.py
@@ -48,7 +48,12 @@ def load_config(config_file: str = None,
show_effective_config: bool = False) -> configparser.ConfigParser:
"""Loads one or more configuration files."""
- confparser = configparser.ConfigParser()
+ # Logging and the default interpolation of configparser both use the
+ # same syntax for variables. To make it easier to work with, we use
+ # another interpolation for config files, so they now use ${loglevel}
+ # whereas logging still uses %(levelname)s.
+ confparser = configparser.ConfigParser(
+ interpolation=configparser.ExtendedInterpolation())
confparser.read_dict(DEFAULT_CONFIG)
if config_file:
@@ -64,10 +69,19 @@ def load_config(config_file: str = None,
if show_effective_config:
import sys
log.info('Effective configuration:')
- to_show = configparser.ConfigParser()
+ to_show = configparser.ConfigParser(
+ interpolation=configparser.ExtendedInterpolation()
+ )
to_show.read_dict(confparser)
if to_show.get(CONFIG_SECTION, 'worker_secret'):
to_show.set(CONFIG_SECTION, 'worker_secret', '-hidden-')
to_show.write(sys.stderr)
return confparser
+
+
+def configure_logging(confparser: configparser.ConfigParser):
+ import logging.config
+
+ logging.config.fileConfig(confparser, disable_existing_loggers=True)
+ logging.captureWarnings(capture=True)