Merge pull request #165 from grillazz/158-granian-poc

refine uvicorn logger config

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
 

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

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

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
         )

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

config.ini

@@ -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 = (100, "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")
-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")
-formatter = default
-
-[formatter_default]
-format = [%(process)d|%(name)-12s] %(message)s
-class = logging.Formatter

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 --log-config ./logging-config.json
     volumes:
       - .:/home/code
     ports:

logging-config.json

@@ -0,0 +1,56 @@
+{
+  "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]"
+    },
+    "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"
+    }
+  }
+}

uvicorn-logging.json

@@ -0,0 +1,70 @@
+{
+  "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"
+    },
+    "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": [
+        "stream"
+      ],
+      "propagate": false,
+      "level": "TRACE"
+    },
+    "uvicorn.access": {
+      "handlers": [
+        "uvicorn"
+      ],
+      "propagate": false,
+      "level": "TRACE",
+      "qualname": "uvicorn.access"
+    },
+    "sqlalchemy.engine.Engine": {
+      "handlers": [
+        "sqlalchemy"
+      ],
+      "level": "ERROR",
+      "propagate": false,
+      "qualname": "sqlalchemy.engine.Engine"
+    }
+  }
+}