From 43d23c4a48c44eb054e6c4424d48ca00ae49fbe0 Mon Sep 17 00:00:00 2001 From: Oleg Silkin Date: Sat, 20 Jul 2019 09:06:34 -0400 Subject: [PATCH] Logging updates --- config/conf.json | 9 ++++-- main.py | 73 +++++++++++++++++++++++++++++++++++++++++++++++- src/app.py | 31 ++++---------------- src/database.py | 2 +- src/handles.py | 22 +++++++-------- src/settings.py | 3 -- 6 files changed, 95 insertions(+), 45 deletions(-) diff --git a/config/conf.json b/config/conf.json index 1dcbdfe..f62352e 100644 --- a/config/conf.json +++ b/config/conf.json @@ -6,9 +6,14 @@ "DEFAULT": "database/default.db", "TEST": "tests/test.db", "ERROR_LOG": "logs/error.log", - "LOG": "logs/server.log" + "DEBUG_LOG": "logs/debug.log", + "SERVER_LOG": "logs/server.log" + }, + "LOGGING": { + "FORMAT": "%(asctime)s | %(levelname)s | %(name)s | %(module)s.%(funcName)s:%(lineno)d | %(message)s", + "AIOHTTP_FORMAT": "%(asctime)s | %(levelname)s | %(name)s | %(message)s", + "DATEFMT": "%Y-%m-%d %H:%M:%S" }, - "LOGGING_FORMAT": "%(asctime)s - %(levelname)s - %(module)s - %(funcName)s - %(message)s", "HOST": "localhost", "PORT": 5921, "BACKUP_INT": 3600, diff --git a/main.py b/main.py index c0e855e..293d625 100644 --- a/main.py +++ b/main.py @@ -1,4 +1,75 @@ +import logging.config +import logging +import os +from src.settings import config + from src.app import run_app + +def config_logging_from_settings(conf): + _config = { + "version": 1, + "disable_existing_loggers": False, + "formatters": { + "standard": { + "format": conf['LOGGING']['FORMAT'], + "datefmt": conf['LOGGING']['DATEFMT'] + }, + "aiohttp": { + "format": conf['LOGGING']['AIOHTTP_FORMAT'], + "datefmt": conf['LOGGING']['DATEFMT'] + } + }, + "handlers": { + "console": { + "level": "DEBUG", + "formatter": "standard", + "class": "logging.StreamHandler", + "stream": "ext://sys.stdout" + }, + "debug": { + "level": "DEBUG", + "formatter": "standard", + "class": "logging.handlers.RotatingFileHandler", + "filename": conf['PATH']['DEBUG_LOG'], + "maxBytes": 10485760, + "backupCount": 5 + }, + "error": { + "level": "ERROR", + "formatter": "standard", + "class": "logging.handlers.RotatingFileHandler", + "filename": conf['PATH']['ERROR_LOG'], + "maxBytes": 10485760, + "backupCount": 5 + }, + "server": { + "level": "NOTSET", + "formatter": "aiohttp", + "class": "logging.handlers.RotatingFileHandler", + "filename": conf['PATH']['SERVER_LOG'], + "maxBytes": 10485760, + "backupCount": 5 + } + }, + "loggers": { + "": { + "handlers": ["console", "debug", "error"], + "level": "DEBUG", + "propogate": True + }, + "aiohttp.access": { + "handlers": ["server"], + "level": "INFO", + "propogate": False + } + } + + } + logging.config.dictConfig(_config) + + if __name__ == '__main__': - run_app() + config_logging_from_settings(config) + logger = logging.getLogger(__name__) + run_app(config) \ No newline at end of file diff --git a/src/app.py b/src/app.py index e173189..78da115 100644 --- a/src/app.py +++ b/src/app.py @@ -11,29 +11,8 @@ from aiohttp import web import schema.db_helpers from src.database import obtain_connection, DatabaseWriter from src.handles import api_endpoint -from src.settings import config_path, get_config - -config = get_config(config_path) logger = logging.getLogger(__name__) -logger.setLevel(logging.DEBUG) - -formatter = logging.Formatter(config['LOGGING_FORMAT']) -debug_handler = logging.FileHandler(config['PATH']['LOG']) -error_handler = logging.FileHandler(config['PATH']['ERROR_LOG']) -stdout_handler = logging.StreamHandler() - -debug_handler.setLevel(logging.DEBUG) -error_handler.setLevel(logging.ERROR) -stdout_handler.setLevel(logging.DEBUG) - -debug_handler.setFormatter(formatter) -error_handler.setFormatter(formatter) -stdout_handler.setFormatter(formatter) - -logger.addHandler(debug_handler) -logger.addHandler(error_handler) -logger.addHandler(stdout_handler) async def setup_db_schema(app): @@ -45,7 +24,7 @@ async def setup_db_schema(app): async def close_comment_scheduler(app): - logger.debug('Closing comment_scheduler') + logger.info('Closing comment_scheduler') await app['comment_scheduler'].close() @@ -78,7 +57,7 @@ def insert_to_config(app, conf=None, db_file=None): async def cleanup_background_tasks(app): - logger.debug('Ending background backup loop') + logger.info('Ending background backup loop') app['waitful_backup'].cancel() await app['waitful_backup'] app['reader'].close() @@ -90,17 +69,17 @@ def create_app(conf, db_path='DEFAULT', **kwargs): insert_to_config(app, conf, db_path) app.on_startup.append(setup_db_schema) app.on_startup.append(start_background_tasks) - app.on_shutdown.append(close_comment_scheduler) app.on_shutdown.append(cleanup_background_tasks) + app.on_shutdown.append(close_comment_scheduler) aiojobs.aiohttp.setup(app, **kwargs) app.add_routes([web.post('/api', api_endpoint)]) return app -def run_app(): +def run_app(config): appl = create_app(conf=config, db_path='DEFAULT', close_timeout=5.0) try: - asyncio.run(web.run_app(appl, access_log=logger, host=config['HOST'], port=config['PORT'])) + asyncio.run(web.run_app(appl, access_log=logging.getLogger('aiohttp.access'), host=config['HOST'], port=config['PORT'])) except asyncio.CancelledError: pass except ValueError: diff --git a/src/database.py b/src/database.py index 50edca3..cb385c4 100644 --- a/src/database.py +++ b/src/database.py @@ -95,7 +95,7 @@ def insert_comment(conn: sqlite3.Connection, claim_id: str, comment: str, parent """, (comment_id, claim_id, channel_id, comment, parent_id, timestamp, signature, signing_ts) ) - logger.debug('Inserted Comment into DB, `comment_id`: %s', comment_id) + logger.info('Inserted Comment into DB, `comment_id`: %s', comment_id) return comment_id diff --git a/src/handles.py b/src/handles.py index 5c202f0..2fc4696 100644 --- a/src/handles.py +++ b/src/handles.py @@ -84,21 +84,19 @@ async def process_json(app, body: dict) -> dict: method = body['method'] params = body.get('params', {}) clean_input_params(params) + logger.debug(f'Received Method {method}, params: {params}') try: if asyncio.iscoroutinefunction(METHODS[method]): result = await METHODS[method](app, params) else: result = METHODS[method](app, params) response['result'] = result - except TypeError as te: - logger.exception('Got TypeError: %s', te) - response['error'] = ERRORS['INVALID_PARAMS'] - except ValueError as ve: - logger.exception('Got ValueError: %s', ve) - response['error'] = ERRORS['INVALID_PARAMS'] - except Exception as e: - logger.exception('Got unknown exception: %s', e) - response['error'] = ERRORS['INTERNAL'] + except Exception as err: + logger.exception(f'Got {type(err).__name__}: {err}') + if type(err) in (ValueError, TypeError): + response['error'] = make_error('INVALID_PARAMS', err) + else: + response['error'] = make_error('INTERNAL', err) else: response['error'] = ERRORS['METHOD_NOT_FOUND'] return response @@ -107,7 +105,6 @@ async def process_json(app, body: dict) -> dict: @atomic async def api_endpoint(request: web.Request): try: - logger.info('Received POST request from %s', request.remote) body = await request.json() if type(body) is list or type(body) is dict: if type(body) is list: @@ -127,5 +124,6 @@ async def api_endpoint(request: web.Request): 'error': ERRORS['PARSE_ERROR'] }) except Exception as e: - logger.exception('Exception raised by request from %s: %s', request.remote, e) - return web.json_response({'error': ERRORS['INVALID_REQUEST']}) + logger.exception(f'Exception raised by request from {request.remote}: {e}') + logger.debug(f'Request headers: {request.headers}') + return make_error('INVALID_REQUEST', e) diff --git a/src/settings.py b/src/settings.py index 6f8b30c..110e2b8 100644 --- a/src/settings.py +++ b/src/settings.py @@ -1,9 +1,7 @@ # cython: language_level=3 import json -import logging import pathlib -logger = logging.getLogger(__name__) root_dir = pathlib.Path(__file__).parent.parent config_path = root_dir / 'config' / 'conf.json' @@ -18,4 +16,3 @@ def get_config(filepath): config = get_config(config_path) -logger.info('Loaded conf.json: %s', json.dumps(config, indent=4))