Merge pull request #208 from grillazz/198-add-simple-caching

198 add structlog

app/api/health.py

@@ -6,9 +6,9 @@ from pydantic import EmailStr
 from starlette.concurrency import run_in_threadpool
 
 from app.services.smtp import SMTPEmailService
-from app.utils.logging import AppLogger
+from app.utils.logging import AppStructLogger
 
-logger = AppLogger().get_logger()
+logger = AppStructLogger().get_logger()
 
 router = APIRouter()
 

app/api/ml.py

@@ -4,9 +4,9 @@ from fastapi import APIRouter, Depends, Form
 from fastapi.responses import StreamingResponse
 
 from app.services.llm import get_llm_service
-from app.utils.logging import AppLogger
+from app.utils.logging import AppStructLogger
 
-logger = AppLogger().get_logger()
+logger = AppStructLogger().get_logger()
 
 router = APIRouter()
 

app/api/stuff.py

@@ -5,9 +5,9 @@ from sqlalchemy.ext.asyncio import AsyncSession
 from app.database import get_db
 from app.models.stuff import Stuff
 from app.schemas.stuff import StuffResponse, StuffSchema
-from app.utils.logging import AppLogger
+from app.utils.logging import AppStructLogger
 
-logger = AppLogger().get_logger()
+logger = AppStructLogger().get_logger()
 
 router = APIRouter(prefix="/v1/stuff")
 

app/api/user.py

@@ -7,9 +7,9 @@ from app.database import get_db
 from app.models.user import User
 from app.schemas.user import TokenResponse, UserLogin, UserResponse, UserSchema
 from app.services.auth import create_access_token
-from app.utils.logging import AppLogger
+from app.utils.logging import AppStructLogger
 
-logger = AppLogger().get_logger()
+logger = AppStructLogger().get_logger()
 
 router = APIRouter(prefix="/v1/user")
 

app/database.py

@@ -3,9 +3,9 @@ from collections.abc import AsyncGenerator
 from sqlalchemy.ext.asyncio import async_sessionmaker, create_async_engine
 
 from app.config import settings as global_settings
-from app.utils.logging import AppLogger
+from app.utils.logging import AppStructLogger
 
-logger = AppLogger().get_logger()
+logger = AppStructLogger().get_logger()
 
 engine = create_async_engine(
     global_settings.asyncpg_url.unicode_string(),

app/main.py

@@ -2,10 +2,6 @@ from contextlib import asynccontextmanager
 from pathlib import Path
 
 import asyncpg
-
-# from apscheduler import AsyncScheduler
-# from apscheduler.datastores.sqlalchemy import SQLAlchemyDataStore
-# from apscheduler.eventbrokers.redis import RedisEventBroker
 from fastapi import Depends, FastAPI, Request
 from fastapi.responses import HTMLResponse
 from fastapi.templating import Jinja2Templates
@@ -17,52 +13,40 @@ from app.api.shakespeare import router as shakespeare_router
 from app.api.stuff import router as stuff_router
 from app.api.user import router as user_router
 from app.config import settings as global_settings
-
-# from app.database import engine
 from app.redis import get_redis
 from app.services.auth import AuthBearer
+from app.utils.logging import AppStructLogger
 
-# from app.services.scheduler import SchedulerMiddleware
+logger = AppStructLogger().get_logger()
-from app.utils.logging import AppLogger
-
-logger = AppLogger().get_logger()
-
 templates = Jinja2Templates(directory=Path(__file__).parent.parent / "templates")
 
-
 @asynccontextmanager
-async def lifespan(_app: FastAPI):
+async def lifespan(app: FastAPI):
-    # Load the redis connection
+    app.redis = await get_redis()
-    _app.redis = await get_redis()
+    postgres_dsn = global_settings.postgres_url.unicode_string()
-
-    _postgres_dsn = global_settings.postgres_url.unicode_string()
-
     try:
-        # TODO: cache with the redis connection
+        app.postgres_pool = await asyncpg.create_pool(
-        # Initialize the postgres connection pool
+            dsn=postgres_dsn,
-        _app.postgres_pool = await asyncpg.create_pool(
-            dsn=_postgres_dsn,
             min_size=5,
             max_size=20,
         )
-        logger.info(f"Postgres pool created: {_app.postgres_pool.get_idle_size()=}")
+        logger.info("Postgres pool created", idle_size=app.postgres_pool.get_idle_size())
         yield
     finally:
-        # close redis connection and release the resources
+        await app.redis.close()
-        await _app.redis.close()
+        await app.postgres_pool.close()
-        # close postgres connection pool and release the resources
-        await _app.postgres_pool.close()
-
-
-app = FastAPI(title="Stuff And Nonsense API", version="0.19.0", lifespan=lifespan)
 
+def create_app() -> FastAPI:
+    app = FastAPI(
+        title="Stuff And Nonsense API",
+        version="0.19.0",
+        lifespan=lifespan,
+    )
     app.include_router(stuff_router)
     app.include_router(nonsense_router)
     app.include_router(shakespeare_router)
     app.include_router(user_router)
     app.include_router(ml_router, prefix="/v1/ml", tags=["ML"])
-
-
     app.include_router(health_router, prefix="/v1/public/health", tags=["Health, Public"])
     app.include_router(
         health_router,
@@ -71,21 +55,24 @@ app.include_router(
         dependencies=[Depends(AuthBearer())],
     )
 
-
     @app.get("/index", response_class=HTMLResponse)
     def get_index(request: Request):
         return templates.TemplateResponse("index.html", {"request": request})
 
+    return app
 
+app = create_app()
+
+# --- Unused/experimental code and TODOs ---
+# from apscheduler import AsyncScheduler
+# from apscheduler.datastores.sqlalchemy import SQLAlchemyDataStore
+# from apscheduler.eventbrokers.redis import RedisEventBroker
+# from app.database import engine
+# from app.services.scheduler import SchedulerMiddleware
 # _scheduler_data_store = SQLAlchemyDataStore(engine, schema="scheduler")
-# _scheduler_event_broker = RedisEventBroker(
+# _scheduler_event_broker = RedisEventBroker(client_or_url=global_settings.redis_url.unicode_string())
-#     client_or_url=global_settings.redis_url.unicode_string()
-# )
 # _scheduler_himself = AsyncScheduler(_scheduler_data_store, _scheduler_event_broker)
-#
 # app.add_middleware(SchedulerMiddleware, scheduler=_scheduler_himself)
-
+# TODO: every non-GET method should reset cache
-
+# TODO: scheduler tasks needing DB should access connection pool via request
-# TODO: every not GET meth should reset cache
-# TODO: every scheduler task which needs to act on database should have access to connection pool via request - maybe ?
 # TODO: https://stackoverflow.com/questions/16053364/make-sure-only-one-worker-launches-the-apscheduler-event-in-a-pyramid-web-app-ru

app/models/base.py

@@ -6,9 +6,9 @@ from sqlalchemy.exc import IntegrityError, SQLAlchemyError
 from sqlalchemy.ext.asyncio import AsyncSession
 from sqlalchemy.orm import DeclarativeBase, declared_attr
 
-from app.utils.logging import AppLogger
+from app.utils.logging import AppStructLogger
 
-logger = AppLogger().get_logger()
+logger = AppStructLogger().get_logger()
 
 
 class Base(DeclarativeBase):

app/services/auth.py

@@ -6,9 +6,9 @@ from fastapi.security import HTTPAuthorizationCredentials, HTTPBearer
 
 from app.config import settings as global_settings
 from app.models.user import User
-from app.utils.logging import AppLogger
+from app.utils.logging import AppStructLogger
 
-logger = AppLogger().get_logger()
+logger = AppStructLogger().get_logger()
 
 
 async def get_from_redis(request: Request, key: str):

app/services/smtp.py

@@ -7,10 +7,10 @@ from fastapi.templating import Jinja2Templates
 from pydantic import EmailStr
 
 from app.config import settings as global_settings
-from app.utils.logging import AppLogger
+from app.utils.logging import AppStructLogger
 from app.utils.singleton import SingletonMetaNoArgs
 
-logger = AppLogger().get_logger()
+logger = AppStructLogger().get_logger()
 
 
 @define

app/utils/logging.py

@@ -1,24 +1,65 @@
 import logging
+import os
+from logging.handlers import RotatingFileHandler
+from pathlib import Path
 
-from rich.console import Console
+import orjson
-from rich.logging import RichHandler
+import structlog
+from attrs import define, field
+from whenever._whenever import Instant
 
-from app.utils.singleton import SingletonMeta
+from app.utils.singleton import SingletonMetaNoArgs
 
 
-class AppLogger(metaclass=SingletonMeta):
+# TODO: merge this wrapper with the one in structlog under one hood of AppLogger
-    _logger = None
+class BytesToTextIOWrapper:
+    def __init__(self, handler, encoding="utf-8"):
+        self.handler = handler
+        self.encoding = encoding
 
-    def __init__(self):
+    def write(self, b):
-        self._logger = logging.getLogger(__name__)
+        if isinstance(b, bytes):
+            self.handler.stream.write(b.decode(self.encoding))
+        else:
+            self.handler.stream.write(b)
+        self.handler.flush()
 
-    def get_logger(self):
+    def flush(self):
-        return self._logger
+        self.handler.flush()
+
+    def close(self):
+        self.handler.close()
 
 
-class RichConsoleHandler(RichHandler):
+@define(slots=True)
-    def __init__(self, width=200, style=None, **kwargs):
+class AppStructLogger(metaclass=SingletonMetaNoArgs):
-        super().__init__(
+    _logger: structlog.BoundLogger = field(init=False)
-            console=Console(color_system="256", width=width, style=style, stderr=True),
+
-            **kwargs,
+    def __attrs_post_init__(self):
+        _log_date = Instant.now().py_datetime().strftime("%Y%m%d")
+        _log_path = Path(f"{_log_date}_{os.getpid()}.log")
+        _handler = RotatingFileHandler(
+            filename=_log_path,
+            mode="a",
+            maxBytes=10 * 1024 * 1024,
+            backupCount=5,
+            encoding="utf-8"
         )
+        structlog.configure(
+            cache_logger_on_first_use=True,
+            wrapper_class=structlog.make_filtering_bound_logger(logging.INFO),
+            processors=[
+                structlog.contextvars.merge_contextvars,
+                structlog.processors.add_log_level,
+                structlog.processors.format_exc_info,
+                structlog.processors.TimeStamper(fmt="iso", utc=True),
+                structlog.processors.JSONRenderer(serializer=orjson.dumps),
+            ],
+            logger_factory=structlog.BytesLoggerFactory(
+                file=BytesToTextIOWrapper(_handler)
+            )
+        )
+        self._logger = structlog.get_logger()
+
+    def get_logger(self) -> structlog.BoundLogger:
+        return self._logger

compose.yml

@@ -10,7 +10,6 @@ services:
       - .secrets
     command: bash -c "
       uvicorn app.main:app
-      --log-config ./logging-uvicorn.json
       --host 0.0.0.0 --port 8080
       --lifespan=on --use-colors --loop uvloop --http httptools
       --reload --log-level debug

granian-compose.yml

@@ -12,7 +12,6 @@ services:
       granian --interface asgi
       --host 0.0.0.0 --port 8080
       app.main:app --access-log --log-level debug
-      --log-config ./logging-granian.json
      "
     volumes:
       - ./app:/panettone/app

pyproject.toml

@@ -29,6 +29,8 @@ dependencies = [
     "polyfactory>=2.21.0",
     "granian>=2.3.2",
     "apscheduler[redis,sqlalchemy]>=4.0.0a6",
+    "structlog>=25.4.0",
+    "whenever>=0.8.5",
 ]
 
 [tool.uv]

uv.lock

@@ -453,8 +453,10 @@ dependencies = [
     { name = "redis" },
     { name = "rich" },
     { name = "sqlalchemy" },
+    { name = "structlog" },
     { name = "uvicorn", extra = ["standard"] },
     { name = "uvloop" },
+    { name = "whenever" },
 ]
 
 [package.dev-dependencies]
@@ -492,8 +494,10 @@ requires-dist = [
     { name = "redis", specifier = ">=6.2.0" },
     { name = "rich", specifier = ">=14.0.0" },
     { name = "sqlalchemy", specifier = ">=2.0.41" },
+    { name = "structlog", specifier = ">=25.4.0" },
     { name = "uvicorn", extras = ["standard"], specifier = ">=0.34.3" },
     { name = "uvloop", specifier = ">=0.21.0" },
+    { name = "whenever", specifier = ">=0.8.5" },
 ]
 
 [package.metadata.requires-dev]
@@ -1575,6 +1579,15 @@ wheels = [
     { url = "https://files.pythonhosted.org/packages/41/94/8af675a62e3c91c2dee47cf92e602cfac86e8767b1a1ac3caf1b327c2ab0/starlette-0.46.0-py3-none-any.whl", hash = "sha256:913f0798bd90ba90a9156383bcf1350a17d6259451d0d8ee27fc0cf2db609038", size = 71991 },
 ]
 
+[[package]]
+name = "structlog"
+version = "25.4.0"
+source = { registry = "https://pypi.org/simple" }
+sdist = { url = "https://files.pythonhosted.org/packages/79/b9/6e672db4fec07349e7a8a8172c1a6ae235c58679ca29c3f86a61b5e59ff3/structlog-25.4.0.tar.gz", hash = "sha256:186cd1b0a8ae762e29417095664adf1d6a31702160a46dacb7796ea82f7409e4", size = 1369138 }
+wheels = [
+    { url = "https://files.pythonhosted.org/packages/a0/4a/97ee6973e3a73c74c8120d59829c3861ea52210667ec3e7a16045c62b64d/structlog-25.4.0-py3-none-any.whl", hash = "sha256:fe809ff5c27e557d14e613f45ca441aabda051d119ee5a0102aaba6ce40eed2c", size = 68720 },
+]
+
 [[package]]
 name = "tenacity"
 version = "8.5.0"
@@ -1822,6 +1835,31 @@ wheels = [
     { url = "https://files.pythonhosted.org/packages/52/24/ab44c871b0f07f491e5d2ad12c9bd7358e527510618cb1b803a88e986db1/werkzeug-3.1.3-py3-none-any.whl", hash = "sha256:54b78bf3716d19a65be4fceccc0d1d7b89e608834989dfae50ea87564639213e", size = 224498 },
 ]
 
+[[package]]
+name = "whenever"
+version = "0.8.5"
+source = { registry = "https://pypi.org/simple" }
+dependencies = [
+    { name = "tzdata", marker = "sys_platform == 'win32'" },
+]
+sdist = { url = "https://files.pythonhosted.org/packages/83/6e/d8081fe842dc829662bdb318bdad1256f4f3875cb0441294a6fa39eb9199/whenever-0.8.5.tar.gz", hash = "sha256:23c7e0119103ef71aab080caf332e17b2b8ee4cb5e0ab61b393263755c377e19", size = 234290 }
+wheels = [
+    { url = "https://files.pythonhosted.org/packages/23/4a/70bc93422f129aa9ea9397cc731e3ec9f0332d81642ae19ff2ec7b758abc/whenever-0.8.5-cp313-cp313-macosx_10_12_x86_64.whl", hash = "sha256:08c5c77c0387e3fda2726d312a68e374d441cd21ebe98802d07921ff6c6a7ecf", size = 401659 },
+    { url = "https://files.pythonhosted.org/packages/a3/51/b1fba840313edf65083c7afc68f796c9b5b5064db03dc5ccc6029600afaa/whenever-0.8.5-cp313-cp313-macosx_11_0_arm64.whl", hash = "sha256:98c58420616b6c5ab824471e89c2fa0aff939ef28163e5bbfb7dfbea3d3f8098", size = 389978 },
+    { url = "https://files.pythonhosted.org/packages/ef/0b/c964f4842d8dc1f0372199ad9e9ed4276e8a419e2fbdf1f17e417e285cc9/whenever-0.8.5-cp313-cp313-manylinux_2_17_aarch64.manylinux2014_aarch64.whl", hash = "sha256:c4a3dbed6168f68f5bad63c7a543446c530eff102bb24504bc4d87bea29ef62c", size = 417973 },
+    { url = "https://files.pythonhosted.org/packages/3a/70/37b98f97a9364999e98ea9074775ca4c1df09fcded85e9bce3738373ad7d/whenever-0.8.5-cp313-cp313-manylinux_2_17_armv7l.manylinux2014_armv7l.whl", hash = "sha256:ce9b1b4ef98ee92b80d1d2cf518f0767d631cbcd2df3ad4fd1d863fdad2c030c", size = 453330 },
+    { url = "https://files.pythonhosted.org/packages/5d/2a/a8c5cc159da33860e709720034bd39b39f94b8c191da2a0eeaf5d75659c9/whenever-0.8.5-cp313-cp313-manylinux_2_17_ppc64le.manylinux2014_ppc64le.whl", hash = "sha256:739d608ee0586d0972d6f7789c705016e416b3ef8ae5337c1f73605feb23a784", size = 550280 },
+    { url = "https://files.pythonhosted.org/packages/1b/f8/edc24161c6cd3ee93363bd14b4e5ff679239f1d185a1f588d93b60b90221/whenever-0.8.5-cp313-cp313-manylinux_2_17_s390x.manylinux2014_s390x.whl", hash = "sha256:4487c7684f7292e66b9a4c2bd6b5efbd7271c48c4410648d90e967dc5e0144ca", size = 463600 },
+    { url = "https://files.pythonhosted.org/packages/35/db/2f873f0854f577f16f20b651762acd4df279a3fa8b5f855113b609a15465/whenever-0.8.5-cp313-cp313-manylinux_2_17_x86_64.manylinux2014_x86_64.whl", hash = "sha256:ef58e82d825a763860bf1de61c28bba7ffa0a7da3a6456381d441caf6693f845", size = 433784 },
+    { url = "https://files.pythonhosted.org/packages/50/df/555db022bdab1fa39e7b5d3756da1841f499e569cb7fda74a356dba6b89b/whenever-0.8.5-cp313-cp313-manylinux_2_5_i686.manylinux1_i686.whl", hash = "sha256:f3992f8f3424ff52c5c21a95792b2dfbe537df08ab951ef7a0654ba517b7a28e", size = 481548 },
+    { url = "https://files.pythonhosted.org/packages/95/fe/d427a3e3d6ae9c69690f4c2a1b40e301d7abf45a2c6c21aa3040f25fe642/whenever-0.8.5-cp313-cp313-musllinux_1_2_aarch64.whl", hash = "sha256:a1988f40fe0d28902aa3f132e4fb23a18599cf9ad49a54311265425631d8ec96", size = 595909 },
+    { url = "https://files.pythonhosted.org/packages/26/0c/c90389b0f52473cdfb30046ad9369b379ab924d9d2d3be590e09890d49a6/whenever-0.8.5-cp313-cp313-musllinux_1_2_armv7l.whl", hash = "sha256:17d47930a318563180c06dcf3332db3956658751d2d29b367c8e550fdda34b2c", size = 716887 },
+    { url = "https://files.pythonhosted.org/packages/20/45/5e1f15b51a7311579d707fac7250e3c5312e7c2491972b85c1e5859b7fa0/whenever-0.8.5-cp313-cp313-musllinux_1_2_i686.whl", hash = "sha256:0a28c299195fdf9082d7fa7d1aa985d709aef8c206160bd50b52d1913261af3d", size = 653268 },
+    { url = "https://files.pythonhosted.org/packages/c9/73/935c542a6ec07699773c231871f4fd1a727a2fba995599275bbe5ad0b500/whenever-0.8.5-cp313-cp313-musllinux_1_2_x86_64.whl", hash = "sha256:4920995d03e26e225d2a733d9f58e3ed3cce7a33994b0bf2f6d94c9f85059dd4", size = 605528 },
+    { url = "https://files.pythonhosted.org/packages/82/15/bf5332b353239af8120db4934fa6e0b1a4f5772a56185070d85f9523c462/whenever-0.8.5-cp313-cp313-win32.whl", hash = "sha256:f67d1054de92486baf8d48a28c0e2ff5fc78ab2e772b054f69520953727862f5", size = 348552 },
+    { url = "https://files.pythonhosted.org/packages/a9/34/e539f26dff602085c001f15264ca508e3df3cd9a7fd50d0a51c3f9759976/whenever-0.8.5-cp313-cp313-win_amd64.whl", hash = "sha256:f7b7f1814fd3d216c8ff5d62076a46f21b38d03af71a59887efa3fc3e8d1c5bb", size = 343086 },
+]
+
 [[package]]
 name = "wsproto"
 version = "1.2.0"