From a58e98c4b158a0eba37e31484755123e3459a76b Mon Sep 17 00:00:00 2001 From: Jakub Miazek Date: Sat, 27 Jul 2024 17:51:49 +0200 Subject: [PATCH 1/4] wip: granian logging --- granian-compose.yml | 2 +- logging-config.json | 55 +++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 56 insertions(+), 1 deletion(-) create mode 100644 logging-config.json diff --git a/granian-compose.yml b/granian-compose.yml index caae030..16ea23f 100644 --- a/granian-compose.yml +++ b/granian-compose.yml @@ -5,7 +5,7 @@ services: env_file: - .env - .secrets - command: granian --interface asgi --host 0.0.0.0 --port 8080 --loop uvloop app.main:app + command: granian --interface asgi --host 0.0.0.0 --port 8080 --loop uvloop app.main:app --log-level debug volumes: - .:/home/code ports: diff --git a/logging-config.json b/logging-config.json new file mode 100644 index 0000000..cd7f8b6 --- /dev/null +++ b/logging-config.json @@ -0,0 +1,55 @@ +{ + "version": 1, + "disable_existing_loggers": false, + "formatters": { + "default": { + "format": "[%(process)d|%(name)-12s] %(message)s", + "class": "logging.Formatter" + } + }, + "handlers": { + "console": { + "class": "app.utils.logging.RichConsoleHandler", + "level": "DEBUG", + "formatter": "default", + "stream": "ext://sys.stdout", + "kwargs": {"omit_repeated_times": "True", "show_time": "False", "enable_link_path": "False", "tracebacks_show_locals": "True", "rich_tracebacks": "True"}, + "args": "(100, 'white')" + + }, + "sqlalchemy": { +// "class": "logging.handlers.TimedRotatingFileHandler", +// "level": "DEBUG", +// "formatter": "verbose", +// "when": "D", +// "backupCount": 0, +// "filename": "./logs/training-stats.log" + }, + "granian": { +// "class": "logging.handlers.TimedRotatingFileHandler", +// "level": "DEBUG", +// "formatter": "verbose", +// "when": "D", +// "backupCount": 0, +// "filename": "./logs/uvicorn.log" + } + }, + "loggers": { + "root": { +// "level": "DEBUG", +// "handlers": ["console"] + }, + "sqlalchemy.engine.Engine": { +// "level": "DEBUG", +// "handlers": ["file"], +// "propagate": true, +// "qualname": "app" + }, + "granian.access": { +// "level": "DEBUG", +// "handlers": ["uvicorn"], +// "propagate": true, +// "qualname": "uvicorn" + } + } +} \ No newline at end of file From 6f0b097d2d649e0150be34e515c5939cc096224a Mon Sep 17 00:00:00 2001 From: Jakub Miazek Date: Sat, 17 Aug 2024 10:45:51 +0200 Subject: [PATCH 2/4] wip: uvicorn logging conf to json --- app/api/stuff.py | 1 + app/models/base.py | 4 ++ app/utils/logging.py | 2 +- compose.yml | 2 +- config.ini | 6 +-- granian-compose.yml | 2 +- logging-config.json | 103 ++++++++++++++++++++------------------- uvicorn-logging-old.json | 52 ++++++++++++++++++++ uvicorn-logging.json | 51 +++++++++++++++++++ 9 files changed, 166 insertions(+), 57 deletions(-) create mode 100644 uvicorn-logging-old.json create mode 100644 uvicorn-logging.json diff --git a/app/api/stuff.py b/app/api/stuff.py index d0629bd..6b7c6f6 100644 --- a/app/api/stuff.py +++ b/app/api/stuff.py @@ -21,6 +21,7 @@ async def create_multi_stuff( db_session.add_all(stuff_instances) await db_session.commit() except SQLAlchemyError as ex: + logger.error(f"Error inserting instances of Stuff: {repr(ex)}") raise HTTPException( status_code=status.HTTP_422_UNPROCESSABLE_ENTITY, detail=repr(ex) ) from ex diff --git a/app/models/base.py b/app/models/base.py index 3f5a531..95d6661 100644 --- a/app/models/base.py +++ b/app/models/base.py @@ -5,6 +5,9 @@ from fastapi import HTTPException, status from sqlalchemy.exc import SQLAlchemyError, IntegrityError from sqlalchemy.ext.asyncio import AsyncSession from sqlalchemy.orm import declared_attr, DeclarativeBase +from app.utils.logging import AppLogger + +logger = AppLogger().get_logger() class Base(DeclarativeBase): @@ -26,6 +29,7 @@ class Base(DeclarativeBase): db_session.add(self) return await db_session.commit() except SQLAlchemyError as ex: + logger.error(f"Error inserting instance of {self}: {repr(ex)}") raise HTTPException( status_code=status.HTTP_422_UNPROCESSABLE_ENTITY, detail=repr(ex) ) from ex diff --git a/app/utils/logging.py b/app/utils/logging.py index 84975ff..4e085c0 100644 --- a/app/utils/logging.py +++ b/app/utils/logging.py @@ -20,5 +20,5 @@ class AppLogger(metaclass=SingletonMeta): class RichConsoleHandler(RichHandler): def __init__(self, width=200, style=None, **kwargs): super().__init__( - console=Console(color_system="256", width=width, style=style), **kwargs + console=Console(color_system="256", width=width, style=style, stderr=True), **kwargs ) diff --git a/compose.yml b/compose.yml index 544838e..7cddf72 100644 --- a/compose.yml +++ b/compose.yml @@ -7,7 +7,7 @@ services: - .secrets command: bash -c " uvicorn app.main:app - --log-config ./config.ini + --log-config ./uvicorn-logging.json --host 0.0.0.0 --port 8080 --lifespan=on --use-colors --loop uvloop --http httptools --reload --log-level debug diff --git a/config.ini b/config.ini index da1e6db..7168ba8 100644 --- a/config.ini +++ b/config.ini @@ -27,20 +27,20 @@ qualname = uvicorn.access [handler_stream] class = app.utils.logging.RichConsoleHandler kwargs = {"omit_repeated_times":True, "show_time": False, "enable_link_path": False, "tracebacks_show_locals": True, "rich_tracebacks": True} -args = (100, "white") +args = (140, "white") formatter = default stream = ext://sys.stdout [handler_sqlalchemy] class = app.utils.logging.RichConsoleHandler kwargs = {"omit_repeated_times":True, "show_time": False, "enable_link_path": False, "tracebacks_show_locals": True, "rich_tracebacks": True} -args = (100, "magenta") +args = (140, "magenta") formatter = default [handler_uvicorn] class = app.utils.logging.RichConsoleHandler kwargs = {"omit_repeated_times":True, "show_time": False, "enable_link_path": False, "tracebacks_show_locals": True, "rich_tracebacks": True} -args = (100, "yellow") +args = (140, "yellow") formatter = default [formatter_default] diff --git a/granian-compose.yml b/granian-compose.yml index 16ea23f..4ef49b4 100644 --- a/granian-compose.yml +++ b/granian-compose.yml @@ -5,7 +5,7 @@ services: env_file: - .env - .secrets - command: granian --interface asgi --host 0.0.0.0 --port 8080 --loop uvloop app.main:app --log-level debug + command: granian --interface asgi --host 0.0.0.0 --port 8080 --loop uvloop app.main:app --log-level debug --log-config ./logging-config.json volumes: - .:/home/code ports: diff --git a/logging-config.json b/logging-config.json index cd7f8b6..5c52017 100644 --- a/logging-config.json +++ b/logging-config.json @@ -1,55 +1,56 @@ { - "version": 1, - "disable_existing_loggers": false, - "formatters": { - "default": { - "format": "[%(process)d|%(name)-12s] %(message)s", - "class": "logging.Formatter" - } + "version": 1, + "disable_existing_loggers": false, + "formatters": { + "generic": { + "()": "logging.Formatter", + "fmt": "[%(process)d|%(name)-12s] %(message)s", + "datefmt": "[%Y-%m-%d %H:%M:%S %z]" }, - "handlers": { - "console": { - "class": "app.utils.logging.RichConsoleHandler", - "level": "DEBUG", - "formatter": "default", - "stream": "ext://sys.stdout", - "kwargs": {"omit_repeated_times": "True", "show_time": "False", "enable_link_path": "False", "tracebacks_show_locals": "True", "rich_tracebacks": "True"}, - "args": "(100, 'white')" - - }, - "sqlalchemy": { -// "class": "logging.handlers.TimedRotatingFileHandler", -// "level": "DEBUG", -// "formatter": "verbose", -// "when": "D", -// "backupCount": 0, -// "filename": "./logs/training-stats.log" - }, - "granian": { -// "class": "logging.handlers.TimedRotatingFileHandler", -// "level": "DEBUG", -// "formatter": "verbose", -// "when": "D", -// "backupCount": 0, -// "filename": "./logs/uvicorn.log" - } - }, - "loggers": { - "root": { -// "level": "DEBUG", -// "handlers": ["console"] - }, - "sqlalchemy.engine.Engine": { -// "level": "DEBUG", -// "handlers": ["file"], -// "propagate": true, -// "qualname": "app" - }, - "granian.access": { -// "level": "DEBUG", -// "handlers": ["uvicorn"], -// "propagate": true, -// "qualname": "uvicorn" - } + "access": { + "()": "logging.Formatter", + "fmt": "[%(process)d|%(name)-12s] %(message)s", + "datefmt": "[%Y-%m-%d %H:%M:%S %z]" } + }, + "handlers": { + "console": { + "formatter": "generic", + "class": "logging.StreamHandler", + "stream": "ext://sys.stdout" + }, + "access": { + "formatter": "access", + "class": "logging.StreamHandler", + "stream": "ext://sys.stdout" + }, + "sqlalchemy": { + "class": "app.utils.logging.RichConsoleHandler", + "formatter": "generic" + } + }, + "loggers": { + "_granian": { + "handlers": [ + "console" + ], + "level": "INFO", + "propagate": false + }, + "granian.access": { + "handlers": [ + "access" + ], + "level": "INFO", + "propagate": false + }, + "sqlalchemy.engine.Engine": { + "handlers": [ + "sqlalchemy" + ], + "level": "ERROR", + "propagate": true, + "qualname": "sqlalchemy.engine.Engine" + } + } } \ No newline at end of file diff --git a/uvicorn-logging-old.json b/uvicorn-logging-old.json new file mode 100644 index 0000000..b21ea96 --- /dev/null +++ b/uvicorn-logging-old.json @@ -0,0 +1,52 @@ + + +{ + "version": 1, + "disable_existing_loggers": false, + "formatters": { + "default": { + "()": "logging.Formatter", + "fmt": "[%(process)d|%(name)-12s] %(message)s" + } + }, + "handlers": { + "stream": { + "formatter": "default", + "class": "app.utils.logging.RichConsoleHandler", + "stream": "ext://sys.stdout" + }, + "uvicorn": { + "formatter": "default", + "class": "app.utils.logging.RichConsoleHandler", + "stream": "ext://sys.stdout" + }, + "sqlalchemy": { + "formatter": "default", + "class": "app.utils.logging.RichConsoleHandler" + } + }, + "loggers": { + "root": { + "handlers": [ + "stream" + ], + "level": "INFO", + "propagate": false + }, + "uvicorn.access": { + "handlers": [ + "uvicorn" + ], + "level": "INFO", + "propagate": false + }, + "sqlalchemy.engine.Engine": { + "handlers": [ + "sqlalchemy" + ], + "level": "ERROR", + "propagate": true, + "qualname": "sqlalchemy.engine.Engine" + } + } +} diff --git a/uvicorn-logging.json b/uvicorn-logging.json new file mode 100644 index 0000000..b96af62 --- /dev/null +++ b/uvicorn-logging.json @@ -0,0 +1,51 @@ +{ + "version": 1, + "disable_existing_loggers": false, + "formatters": { + "default": { + "()": "logging.Formatter", + "fmt": "[%(process)d|%(name)-12s] %(message)s" + } + }, + "handlers": { + "uvicorn": { + "class": "app.utils.logging.RichConsoleHandler", + "omit_repeated_times": true, + "show_time": false, + "enable_link_path": false, + "tracebacks_show_locals": true, + "rich_tracebacks": true, + "formatter": "default", + "width": 140, + "style": "yellow" + }, + "sqlalchemy": { + "class": "app.utils.logging.RichConsoleHandler", + "omit_repeated_times": true, + "show_time": false, + "enable_link_path": false, + "tracebacks_show_locals": true, + "rich_tracebacks": true, + "formatter": "default", + "width": 140, + "style": "magenta" + } + }, + "loggers": { + "root": { + "handlers": [ + "uvicorn" + ], + "propagate": false, + "level": "TRACE" + }, + "sqlalchemy.engine.Engine": { + "handlers": [ + "sqlalchemy" + ], + "level": "ERROR", + "propagate": false, + "qualname": "sqlalchemy.engine.Engine" + } + } +} \ No newline at end of file From d63dfaeed76269d5c1a3f131cab6771d054b3319 Mon Sep 17 00:00:00 2001 From: Jakub Miazek Date: Sat, 17 Aug 2024 11:38:53 +0200 Subject: [PATCH 3/4] replace uvicorn logger config with json --- Dockerfile | 2 +- config.ini | 48 -------------------------------------------- uvicorn-logging.json | 21 ++++++++++++++++++- 3 files changed, 21 insertions(+), 50 deletions(-) delete mode 100644 config.ini diff --git a/Dockerfile b/Dockerfile index 58aa24e..746da00 100644 --- a/Dockerfile +++ b/Dockerfile @@ -27,7 +27,7 @@ RUN apt-get purge -y curl git build-essential \ && rm -rf /var/apt/lists/* \ && rm -rf /var/cache/apt/* -FROM install as app-image +FROM install AS app-image ENV PYTHONPATH=/home/code/ PYTHONHASHSEED=0 diff --git a/config.ini b/config.ini deleted file mode 100644 index 7168ba8..0000000 --- a/config.ini +++ /dev/null @@ -1,48 +0,0 @@ -[loggers] -keys = root, sqlalchemy.engine.Engine, uvicorn.access - -[handlers] -keys = stream, sqlalchemy, uvicorn - -[formatters] -keys = default - -[logger_root] -level = INFO -propagate = 0 -handlers = stream - -[logger_sqlalchemy.engine.Engine] -level = INFO -propagate = 0 -handlers = sqlalchemy -qualname = sqlalchemy.engine.Engine - -[logger_uvicorn.access] -level = INFO -propagate = 0 -handlers = uvicorn -qualname = uvicorn.access - -[handler_stream] -class = app.utils.logging.RichConsoleHandler -kwargs = {"omit_repeated_times":True, "show_time": False, "enable_link_path": False, "tracebacks_show_locals": True, "rich_tracebacks": True} -args = (140, "white") -formatter = default -stream = ext://sys.stdout - -[handler_sqlalchemy] -class = app.utils.logging.RichConsoleHandler -kwargs = {"omit_repeated_times":True, "show_time": False, "enable_link_path": False, "tracebacks_show_locals": True, "rich_tracebacks": True} -args = (140, "magenta") -formatter = default - -[handler_uvicorn] -class = app.utils.logging.RichConsoleHandler -kwargs = {"omit_repeated_times":True, "show_time": False, "enable_link_path": False, "tracebacks_show_locals": True, "rich_tracebacks": True} -args = (140, "yellow") -formatter = default - -[formatter_default] -format = [%(process)d|%(name)-12s] %(message)s -class = logging.Formatter \ No newline at end of file diff --git a/uvicorn-logging.json b/uvicorn-logging.json index b96af62..50d8719 100644 --- a/uvicorn-logging.json +++ b/uvicorn-logging.json @@ -29,16 +29,35 @@ "formatter": "default", "width": 140, "style": "magenta" + }, + "stream": { + "class": "app.utils.logging.RichConsoleHandler", + "omit_repeated_times": true, + "show_time": false, + "enable_link_path": false, + "tracebacks_show_locals": true, + "rich_tracebacks": true, + "formatter": "default", + "width": 140, + "style": "white" } }, "loggers": { "root": { "handlers": [ - "uvicorn" + "stream" ], "propagate": false, "level": "TRACE" }, + "uvicorn.access": { + "handlers": [ + "uvicorn" + ], + "propagate": false, + "level": "TRACE", + "qualname": "uvicorn.access" + }, "sqlalchemy.engine.Engine": { "handlers": [ "sqlalchemy" From 4c886ad89515d3b4207519abcad0620aba749ef3 Mon Sep 17 00:00:00 2001 From: Jakub Miazek Date: Sat, 17 Aug 2024 11:40:28 +0200 Subject: [PATCH 4/4] replace uvicorn logger config with json --- uvicorn-logging-old.json | 52 ---------------------------------------- 1 file changed, 52 deletions(-) delete mode 100644 uvicorn-logging-old.json diff --git a/uvicorn-logging-old.json b/uvicorn-logging-old.json deleted file mode 100644 index b21ea96..0000000 --- a/uvicorn-logging-old.json +++ /dev/null @@ -1,52 +0,0 @@ - - -{ - "version": 1, - "disable_existing_loggers": false, - "formatters": { - "default": { - "()": "logging.Formatter", - "fmt": "[%(process)d|%(name)-12s] %(message)s" - } - }, - "handlers": { - "stream": { - "formatter": "default", - "class": "app.utils.logging.RichConsoleHandler", - "stream": "ext://sys.stdout" - }, - "uvicorn": { - "formatter": "default", - "class": "app.utils.logging.RichConsoleHandler", - "stream": "ext://sys.stdout" - }, - "sqlalchemy": { - "formatter": "default", - "class": "app.utils.logging.RichConsoleHandler" - } - }, - "loggers": { - "root": { - "handlers": [ - "stream" - ], - "level": "INFO", - "propagate": false - }, - "uvicorn.access": { - "handlers": [ - "uvicorn" - ], - "level": "INFO", - "propagate": false - }, - "sqlalchemy.engine.Engine": { - "handlers": [ - "sqlalchemy" - ], - "level": "ERROR", - "propagate": true, - "qualname": "sqlalchemy.engine.Engine" - } - } -}