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

add structure file logging with log files rotating

app/api/health.py

@@ -1,4 +1,3 @@
-import logging
 from typing import Annotated
 
 from fastapi import APIRouter, Depends, Query, Request, status
@@ -34,7 +33,7 @@ async def redis_check(request: Request):
     try:
         redis_info = await redis_client.info()
     except Exception as e:
-        logging.error(f"Redis error: {e}")
+        await logger.aerror(f"Redis error: {e}")
     return redis_info
 
 
@@ -88,7 +87,7 @@ async def smtp_check(
         "subject": subject,
     }
 
-    logger.info("Sending email with data: %s", email_data)
+    await logger.ainfo("Sending email.", email_data=email_data)
 
     await run_in_threadpool(
         smtp.send_email,

app/api/stuff.py

@@ -21,13 +21,13 @@ 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)}")
+        await logger.aerror(f"Error inserting instances of Stuff: {repr(ex)}")
         raise HTTPException(
             status_code=status.HTTP_422_UNPROCESSABLE_ENTITY, detail=repr(ex)
         ) from ex
     else:
-        logger.info(
-            f"{len(stuff_instances)} instances of Stuff inserted into database."
+        await logger.ainfo(
+            f"{len(stuff_instances)} Stuff instances inserted into the database."
         )
         return True
 

app/api/user.py

@@ -18,7 +18,7 @@ router = APIRouter(prefix="/v1/user")
 async def create_user(
     payload: UserSchema, request: Request, db_session: AsyncSession = Depends(get_db)
 ):
-    logger.info(f"Creating user: {payload}")
+    await logger.ainfo(f"Creating user: {payload}")
     _user: User = User(**payload.model_dump())
     await _user.save(db_session)
 

app/database.py

@@ -29,5 +29,5 @@ async def get_db() -> AsyncGenerator:
         try:
             yield session
         except Exception as e:
-            logger.error(f"Error getting database session: {e}")
+            await logger.aerror(f"Error getting database session: {e}")
             raise

app/main.py

@@ -30,7 +30,7 @@ async def lifespan(app: FastAPI):
             min_size=5,
             max_size=20,
         )
-        logger.info("Postgres pool created", idle_size=app.postgres_pool.get_idle_size())
+        await logger.ainfo("Postgres pool created", idle_size=app.postgres_pool.get_idle_size())
         yield
     finally:
         await app.redis.close()

app/models/base.py

@@ -30,7 +30,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)}")
+            await logger.aerror(f"Error inserting instance of {self}: {repr(ex)}")
             raise HTTPException(
                 status_code=status.HTTP_422_UNPROCESSABLE_ENTITY, detail=repr(ex)
             ) from ex

app/services/auth.py

@@ -40,7 +40,7 @@ class AuthBearer(HTTPBearer):
             raise HTTPException(
                 status_code=403, detail="Invalid token or expired token."
             )
-        logger.info(f"Token verified: {credentials.credentials}")
+        await logger.ainfo(f"Token verified: {credentials.credentials}")
         return credentials.credentials
 
 

app/services/scheduler.py

@@ -15,9 +15,9 @@ logger = AppLogger().get_logger()
 async def tick():
     async with AsyncSessionFactory() as session:
         stmt = text("select 1;")
-        logger.info(f">>>> Be or not to be...{datetime.now()}")
+        await logger.ainfo(f">>>> Be or not to be...{datetime.now()}")
         result = await session.execute(stmt)
-        logger.info(f">>>> Result: {result.scalar()}")
+        await logger.ainfo(f">>>> Result: {result.scalar()}")
         return True
 
 

app/utils/logging.py

@@ -11,27 +11,63 @@ from whenever._whenever import Instant
 from app.utils.singleton import SingletonMetaNoArgs
 
 
-# TODO: merge this wrapper with the one in structlog under one hood of AppLogger
-class BytesToTextIOWrapper:
-    def __init__(self, handler, encoding="utf-8"):
+class RotatingBytesLogger:
+    """Logger that respects RotatingFileHandler's rotation capabilities."""
+
+    def __init__(self, handler):
         self.handler = handler
-        self.encoding = encoding
 
-    def write(self, b):
-        if isinstance(b, bytes):
-            self.handler.stream.write(b.decode(self.encoding))
-        else:
-            self.handler.stream.write(b)
-        self.handler.flush()
+    def msg(self, message):
+        """Process a message and pass it through the handler's emit method."""
+        if isinstance(message, bytes):
+            message = message.decode("utf-8")
 
-    def flush(self):
-        self.handler.flush()
+        # Create a log record that will trigger rotation checks
+        record = logging.LogRecord(
+            name="structlog",
+            level=logging.INFO,
+            pathname="",
+            lineno=0,
+            msg=message.rstrip("\n"),
+            args=(),
+            exc_info=None
+        )
 
-    def close(self):
-        self.handler.close()
+        # Check if rotation is needed before emitting
+        if self.handler.shouldRollover(record):
+            self.handler.doRollover()
+
+        # Emit the record through the handler
+        self.handler.emit(record)
+
+    # Required methods to make it compatible with structlog
+    def debug(self, message):
+        self.msg(message)
+
+    def info(self, message):
+        self.msg(message)
+
+    def warning(self, message):
+        self.msg(message)
+
+    def error(self, message):
+        self.msg(message)
+
+    def critical(self, message):
+        self.msg(message)
 
 
-@define(slots=True)
+class RotatingBytesLoggerFactory:
+    """Factory that creates loggers that respect file rotation."""
+
+    def __init__(self, handler):
+        self.handler = handler
+
+    def __call__(self, *args, **kwargs):
+        return RotatingBytesLogger(self.handler)
+
+
+@define
 class AppStructLogger(metaclass=SingletonMetaNoArgs):
     _logger: structlog.BoundLogger = field(init=False)
 
@@ -40,8 +76,7 @@ class AppStructLogger(metaclass=SingletonMetaNoArgs):
         _log_path = Path(f"{_log_date}_{os.getpid()}.log")
         _handler = RotatingFileHandler(
             filename=_log_path,
-            mode="a",
-            maxBytes=10 * 1024 * 1024,
+            maxBytes=10 * 1024 * 1024,  # 10MB
             backupCount=5,
             encoding="utf-8"
         )
@@ -55,9 +90,7 @@ class AppStructLogger(metaclass=SingletonMetaNoArgs):
                 structlog.processors.TimeStamper(fmt="iso", utc=True),
                 structlog.processors.JSONRenderer(serializer=orjson.dumps),
             ],
-            logger_factory=structlog.BytesLoggerFactory(
-                file=BytesToTextIOWrapper(_handler)
-            )
+            logger_factory=RotatingBytesLoggerFactory(_handler)
         )
         self._logger = structlog.get_logger()