feat: improve logging messages

amarillo/main.py

@@ -1,5 +1,9 @@
 import logging.config
 import warnings
+from pydantic import ValidationError
+from fastapi.exceptions import RequestValidationError
+from fastapi.encoders import jsonable_encoder
+from fastapi.responses import JSONResponse
 
 from amarillo.configuration import configure_services, configure_admin_token
 from amarillo.services.config import config
@@ -63,14 +67,15 @@ def configure():
     configure_routing()
 
 
-@app.middleware("http")
-async def log_request_data(request: Request, call_next):
-    if request.method == "POST" and config.debug:
-        body = await request.body()
-        logger.info(f"POST Request to {request.url.path} with body: {body.decode('utf-8')}")
-
-    return await call_next(request)
+@app.exception_handler(RequestValidationError)
+async def validation_exception_handler(request: Request, exc: RequestValidationError):
+    logger.warning(f"Request failed %s", exc)
+    return JSONResponse(
+        status_code=422,
+        content=jsonable_encoder({"detail": exc.errors(), "body": exc.body}),
+    )
 
+
 def configure_routing():
     mimetypes.add_type('application/x-protobuf', '.pbf')
     app.mount('/static', StaticFiles(directory='static'), name='static')

amarillo/stores/filebasedstore.py

@@ -23,10 +23,11 @@ async def does_carpool_exist(self, agency_id: str, carpool_id: str):
         return os.path.exists(f"data/carpool/{agency_id}/{carpool_id}.json")
 
     async def store_carpool(self, carpool: Carpool) -> Carpool:
+        logger.info(f"Store Carpool  {carpool.agency}:{carpool.id} ")
         if await self.does_carpool_exist(carpool.agency, carpool.id):
             existing_carpool = await self.load_carpool(carpool.agency, carpool.id)
             if self._are_carpools_equivalent(existing_carpool, carpool):
-                logger.debug(f"Carpool  {carpool.agency}:{carpool.id} already exists and seems equivalent, will copy timestamp if unset")
+                logger.info(f"Carpool  {carpool.agency}:{carpool.id} already exists and seems equivalent, will copy timestamp if unset")
                 if carpool.lastUpdated is None:
                     carpool.lastUpdated = existing_carpool.lastUpdated
 
@@ -49,7 +50,7 @@ async def delete_agency_carpools_older_than(self, agency_id, timestamp):
         for carpool_file_name in glob(f"data/carpool/{agency_id}/*.json"):
             if os.path.getmtime(carpool_file_name) < timestamp:
                 m = re.search(r"([a-zA-Z0-9_-]+)\.json$", carpool_file_name)
-                # TODO log deletion
+                logger.info("Will delete %s as file timestamp is older than {timestamp}", carpool_file_name)
                 await self.delete_carpool(agency_id, m[1])
 
     async def delete_carpool(self, agency_id: str, carpool_id: str):