Merge pull request Azure-Samples#8 from pamelafox/main

Improvements to get logging working

Author: bobtabor-msft

src/fastapi_app/app.py

@@ -1,3 +1,4 @@
+import logging
 import os
 import pathlib
 from datetime import datetime
@@ -12,9 +13,14 @@
 
 from .models import Restaurant, Review, engine
 
+# Setup logger and Azure Monitor:
+logger = logging.getLogger("app")
+logger.setLevel(logging.INFO)
 if os.getenv("APPLICATIONINSIGHTS_CONNECTION_STRING"):
     configure_azure_monitor()
 
+
+# Setup FastAPI app:
 app = FastAPI()
 parent_path = pathlib.Path(__file__).parent.parent
 app.mount("/mount", StaticFiles(directory=parent_path / "static"), name="static")
@@ -32,7 +38,7 @@ def get_db_session():
 
 @app.get("/", response_class=HTMLResponse)
 async def index(request: Request, session: Session = Depends(get_db_session)):
-    print("root called")
+    logger.info("root called")
     statement = (
         select(Restaurant, func.avg(Review.rating).label("avg_rating"), func.count(Review.id).label("review_count"))
         .outerjoin(Review, Review.restaurant == Restaurant.id)
@@ -53,7 +59,7 @@ async def index(request: Request, session: Session = Depends(get_db_session)):
 
 @app.get("/create", response_class=HTMLResponse)
 async def create_restaurant(request: Request):
-    print("Request for add restaurant page received")
+    logger.info("Request for add restaurant page received")
     return templates.TemplateResponse("create_restaurant.html", {"request": request})
 
 
@@ -62,7 +68,7 @@ async def add_restaurant(
     request: Request, restaurant_name: str = Form(...), street_address: str = Form(...), description: str = Form(...),
     session: Session = Depends(get_db_session)
 ):
-    print(f"name: {restaurant_name} address: {street_address} description: {description}")
+    logger.info("name: %s address: %s description: %s", restaurant_name, street_address, description)
     restaurant = Restaurant()
     restaurant.name = restaurant_name
     restaurant.street_address = street_address

src/fastapi_app/models.py

@@ -1,3 +1,4 @@
+import logging
 import os
 import typing
 from datetime import datetime
@@ -6,12 +7,15 @@
 from dotenv import load_dotenv
 from sqlmodel import Field, SQLModel, create_engine
 
+logger = logging.getLogger("app")
+logger.setLevel(logging.INFO)
+
 sql_url = ""
 if os.getenv("WEBSITE_HOSTNAME"):
-    print("Connecting to Azure PostgreSQL Flexible server based on AZURE_POSTGRESQL_CONNECTIONSTRING...")
+    logger.info("Connecting to Azure PostgreSQL Flexible server based on AZURE_POSTGRESQL_CONNECTIONSTRING...")
     env_connection_string = os.getenv("AZURE_POSTGRESQL_CONNECTIONSTRING")
     if env_connection_string is None:
-        print("Missing environment variable AZURE_POSTGRESQL_CONNECTIONSTRING")
+        logger.info("Missing environment variable AZURE_POSTGRESQL_CONNECTIONSTRING")
     else:
         # Parse the connection string
         details = dict(item.split('=') for item in env_connection_string.split())
@@ -23,7 +27,7 @@
         )
 
 else:
-    print("Connecting to local PostgreSQL server based on .env file...")
+    logger.info("Connecting to local PostgreSQL server based on .env file...")
     load_dotenv()
     POSTGRES_USERNAME = os.environ.get("DBUSER")
     POSTGRES_PASSWORD = os.environ.get("DBPASS")

src/gunicorn.conf.py

@@ -6,6 +6,6 @@
 bind = "0.0.0.0:8000"
 workers = (multiprocessing.cpu_count() * 2) + 1
 
-worker_class = "uvicorn.workers.UvicornWorker"
+worker_class = "my_uvicorn_worker.MyUvicornWorker"
 
 timeout = 600

src/my_uvicorn_worker.py

@@ -0,0 +1,50 @@
+from uvicorn_worker import UvicornWorker
+
+logconfig_dict = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "formatters": {
+        "default": {
+            "()": "uvicorn.logging.DefaultFormatter",
+            "format": "%(asctime)s - %(message)s",
+        },
+        "access": {
+            "()": "uvicorn.logging.AccessFormatter",
+            "format": "%(asctime)s - %(message)s",
+        },
+    },
+    "handlers": {
+        "default": {
+            "formatter": "default",
+            "class": "logging.StreamHandler",
+            "stream": "ext://sys.stderr",
+        },
+        "access": {
+            "formatter": "access",
+            "class": "logging.StreamHandler",
+            "stream": "ext://sys.stdout",
+        },
+    },
+    "loggers": {
+        "root": {"level": "INFO", "handlers": ["default"]},
+        "uvicorn.error": {
+            "level": "INFO",
+            "handlers": ["default"],
+            "propagate": False,
+        },
+        "uvicorn.access": {
+            "level": "INFO",
+            "handlers": ["access"],
+            "propagate": False,
+        },
+    },
+}
+
+
+class MyUvicornWorker(UvicornWorker):
+    CONFIG_KWARGS = {
+        "loop": "asyncio",
+        "http": "auto",
+        "lifespan": "off",
+        "log_config": logconfig_dict,
+    }

src/pyproject.toml

@@ -7,6 +7,7 @@ dependencies = [
     "fastapi",
     "jinja2",
     "uvicorn[standard]",
+    "uvicorn-worker",
     "python-multipart",
     "psycopg2",
     "sqlmodel",