Merge pull request #768 from hotosm/feat/update-logging

Update logging to be more feature rich, persist logs, JSON logs
hotosm · Aug 25, 2023 · 114bdef · 114bdef
2 parents 7298e9e + efa8fe4
commit 114bdef
Show file tree

Hide file tree

Showing 20 changed files with 332 additions and 532 deletions.
diff --git a/docker-compose.deploy.yml b/docker-compose.deploy.yml
@@ -19,6 +19,7 @@ version: "3"
 
 volumes:
   fmtm_db_data:
+  fmtm_logs:
   fmtm_images:
   fmtm_tiles:
   traefik-public-certificates:
@@ -85,6 +86,7 @@ services:
         APP_VERSION: ${API_VERSION}
     container_name: fmtm_api
     volumes:
+      - fmtm_logs:/opt/logs
       - fmtm_images:/opt/app/images
       - fmtm_tiles:/opt/tiles
     depends_on:

diff --git a/docker-compose.noodk.yml b/docker-compose.noodk.yml
@@ -19,6 +19,7 @@ version: "3"
 
 volumes:
   fmtm_db_data:
+  fmtm_logs:
   fmtm_images:
   fmtm_tiles:
 
@@ -50,6 +51,7 @@ services:
         APP_VERSION: debug
     container_name: fmtm_api
     volumes:
+      - fmtm_logs:/opt/logs
       - fmtm_images:/opt/app/images
       - fmtm_tiles:/opt/tiles
       - ./src/backend/app:/opt/app

diff --git a/docker-compose.yml b/docker-compose.yml
@@ -19,6 +19,7 @@ version: "3"
 
 volumes:
   fmtm_db_data:
+  fmtm_logs:
   fmtm_images:
   fmtm_tiles:
   central_db_data:
@@ -51,6 +52,7 @@ services:
         APP_VERSION: debug
     container_name: fmtm_api
     volumes:
+      - fmtm_logs:/opt/logs
       - fmtm_images:/opt/app/images
       - fmtm_tiles:/opt/tiles
       - ./src/backend/app:/opt/app

diff --git a/src/backend/Dockerfile b/src/backend/Dockerfile
@@ -107,12 +107,13 @@ COPY container-entrypoint.sh /
 ENTRYPOINT ["/container-entrypoint.sh"]
 # Add non-root user, permissions
 RUN useradd -r -u 900 -m -c "hotosm account" -d /home/appuser -s /bin/false appuser \
-    && mkdir -p /opt/tiles \
+    && mkdir -p /opt/logs /opt/tiles \
     && chown -R appuser:appuser /opt /home/appuser \
     && chmod +x /container-entrypoint.sh
 # Add volumes for persistence
-VOLUME /opt/app/images
+VOLUME /opt/logs
 VOLUME /opt/tiles
+VOLUME /opt/app/images
 # Change to non-root user
 USER appuser
 
@@ -140,7 +141,7 @@ RUN ls /opt/*.whl >> /opt/python/requirements-debug.txt \
 CMD ["python", "-m", "debugpy", "--listen", "0.0.0.0:5678", \
     "-m", "uvicorn", "app.main:api", \
     "--host", "0.0.0.0", "--port", "8000", \
-    "--reload", "--log-level", "error", "--no-access-log"]
+    "--reload", "--log-level", "critical", "--no-access-log"]
 
 
 
@@ -169,4 +170,4 @@ FROM runtime as prod
 RUN python -c "import compileall; compileall.compile_path(maxlevels=10, quiet=1)"
 # Note: 4 uvicorn workers as running with docker, change to 1 worker for Kubernetes
 CMD ["uvicorn", "app.main:api", "--host", "0.0.0.0", "--port", "8000", \
-    "--workers", "4", "--log-level", "error", "--no-access-log"]
+    "--workers", "4", "--log-level", "critical", "--no-access-log"]
diff --git a/src/backend/app/auth/auth_routes.py b/src/backend/app/auth/auth_routes.py
@@ -18,8 +18,8 @@
 
 """Auth routes, using OSM OAuth2 endpoints."""
 
+from loguru import logger as log
 from fastapi import APIRouter, Depends, HTTPException, Request
-from fastapi.logger import logger as log
 from fastapi.responses import JSONResponse
 from sqlalchemy.orm import Session
 

diff --git a/src/backend/app/central/central_crud.py b/src/backend/app/central/central_crud.py
@@ -15,9 +15,10 @@
 #     You should have received a copy of the GNU General Public License
 #     along with FMTM.  If not, see <https:#www.gnu.org/licenses/>.
 #
+from loguru import logger as log
+
 import base64
 import json
-import logging
 import os
 import pathlib
 import zlib
@@ -27,7 +28,6 @@
 import segno
 import xmltodict
 from fastapi import HTTPException
-from fastapi.logger import logger as logger
 from osm_fieldwork.CSVDump import CSVDump
 from osm_fieldwork.OdkCentral import OdkAppUser, OdkForm, OdkProject
 from pyxform.xls2xform import xls2xform_convert
@@ -38,8 +38,6 @@
 from ..db import db_models
 from ..projects import project_schemas
 
-log = logging.getLogger(__name__)
-
 
 def get_odk_project(odk_central: project_schemas.ODKCentral = None):
     """Helper function to get the OdkProject with credentials."""
@@ -48,17 +46,17 @@ def get_odk_project(odk_central: project_schemas.ODKCentral = None):
         user = odk_central.odk_central_user
         pw = odk_central.odk_central_password
     else:
-        logger.debug("ODKCentral connection variables not set in function")
-        logger.debug("Attempting extraction from environment variables")
+        log.debug("ODKCentral connection variables not set in function")
+        log.debug("Attempting extraction from environment variables")
         url = settings.ODK_CENTRAL_URL
         user = settings.ODK_CENTRAL_USER
         pw = settings.ODK_CENTRAL_PASSWD
 
     try:
-        logger.debug(f"Connecting to ODKCentral: url={url} user={user}")
+        log.debug(f"Connecting to ODKCentral: url={url} user={user}")
         project = OdkProject(url, user, pw)
     except Exception as e:
-        logger.error(e)
+        log.error(e)
         raise HTTPException(
             status_code=500, detail=f"Error creating project on ODK Central: {e}"
         ) from e
@@ -74,17 +72,17 @@ def get_odk_form(odk_central: project_schemas.ODKCentral = None):
         pw = odk_central.odk_central_password
 
     else:
-        logger.debug("ODKCentral connection variables not set in function")
-        logger.debug("Attempting extraction from environment variables")
+        log.debug("ODKCentral connection variables not set in function")
+        log.debug("Attempting extraction from environment variables")
         url = settings.ODK_CENTRAL_URL
         user = settings.ODK_CENTRAL_USER
         pw = settings.ODK_CENTRAL_PASSWD
 
     try:
-        logger.debug(f"Connecting to ODKCentral: url={url} user={user}")
+        log.debug(f"Connecting to ODKCentral: url={url} user={user}")
         form = OdkForm(url, user, pw)
     except Exception as e:
-        logger.error(e)
+        log.error(e)
         raise HTTPException(
             status_code=500, detail=f"Error creating project on ODK Central: {e}"
         ) from e
@@ -99,17 +97,17 @@ def get_odk_app_user(odk_central: project_schemas.ODKCentral = None):
         user = odk_central.odk_central_user
         pw = odk_central.odk_central_password
     else:
-        logger.debug("ODKCentral connection variables not set in function")
-        logger.debug("Attempting extraction from environment variables")
+        log.debug("ODKCentral connection variables not set in function")
+        log.debug("Attempting extraction from environment variables")
         url = settings.ODK_CENTRAL_URL
         user = settings.ODK_CENTRAL_USER
         pw = settings.ODK_CENTRAL_PASSWD
 
     try:
-        logger.debug(f"Connecting to ODKCentral: url={url} user={user}")
+        log.debug(f"Connecting to ODKCentral: url={url} user={user}")
         form = OdkAppUser(url, user, pw)
     except Exception as e:
-        logger.error(e)
+        log.error(e)
         raise HTTPException(
             status_code=500, detail=f"Error creating project on ODK Central: {e}"
         ) from e
@@ -139,11 +137,11 @@ def create_odk_project(name: str, odk_central: project_schemas.ODKCentral = None
                     detail="Could not authenticate to odk central.",
                 )
 
-        logger.debug(f"ODKCentral response: {result}")
-        logger.info(f"Project {name} available on the ODK Central server.")
+        log.debug(f"ODKCentral response: {result}")
+        log.info(f"Project {name} available on the ODK Central server.")
         return result
     except Exception as e:
-        logger.error(e)
+        log.error(e)
         raise HTTPException(
             status_code=500, detail=f"Error creating project on ODK Central: {e}"
         ) from e
@@ -156,7 +154,7 @@ def delete_odk_project(project_id: int, odk_central: project_schemas.ODKCentral
     try:
         project = get_odk_project(odk_central)
         result = project.deleteProject(project_id)
-        logger.info(
+        log.info(
             f"Project {project_id} has been deleted from the ODK Central server."
         )
         return result
@@ -176,15 +174,15 @@ def create_appuser(
         pw = odk_credentials.odk_central_password
 
     else:
-        logger.debug("ODKCentral connection variables not set in function")
-        logger.debug("Attempting extraction from environment variables")
+        log.debug("ODKCentral connection variables not set in function")
+        log.debug("Attempting extraction from environment variables")
         url = settings.ODK_CENTRAL_URL
         user = settings.ODK_CENTRAL_USER
         pw = settings.ODK_CENTRAL_PASSWD
 
     app_user = OdkAppUser(url, user, pw)
     result = app_user.create(project_id, name)
-    logger.info(f"Created app user: {result.json()}")
+    log.info(f"Created app user: {result.json()}")
     return result
 
 
@@ -208,16 +206,16 @@ def upload_xform_media(
         pw = odk_credentials["odk_central_password"]
 
     else:
-        logger.debug("ODKCentral connection variables not set in function")
-        logger.debug("Attempting extraction from environment variables")
+        log.debug("ODKCentral connection variables not set in function")
+        log.debug("Attempting extraction from environment variables")
         url = settings.ODK_CENTRAL_URL
         user = settings.ODK_CENTRAL_USER
         pw = settings.ODK_CENTRAL_PASSWD
 
     try:
         xform = OdkForm(url, user, pw)
     except Exception as e:
-        logger.error(e)
+        log.error(e)
         raise HTTPException(
             status_code=500, detail={"message": "Connection failed to odk central"}
         ) from e
@@ -250,7 +248,7 @@ def create_odk_xform(
     try:
         xform = get_odk_form(odk_credentials)
     except Exception as e:
-        logger.error(e)
+        log.error(e)
         raise HTTPException(
             status_code=500, detail={"message": "Connection failed to odk central"}
         ) from e
@@ -331,7 +329,7 @@ def get_form_list(db: Session, skip: int, limit: int):
             .all()
         )
     except Exception as e:
-        logger.error(e)
+        log.error(e)
         raise HTTPException(e) from e
 
 
@@ -381,11 +379,11 @@ def generate_updated_xform(
         try:
             xls2xform_convert(xlsform_path=xlsform, xform_path=outfile, validate=False)
         except Exception as e:
-            logger.error(f"Couldn't convert {xlsform} to an XForm!", str(e))
+            log.error(f"Couldn't convert {xlsform} to an XForm!", str(e))
             raise HTTPException(status_code=400, detail=str(e)) from e
 
         if os.path.getsize(outfile) <= 0:
-            logger.warning(f"{outfile} is empty!")
+            log.warning(f"{outfile} is empty!")
             raise HTTPException(status=400, detail=f"{outfile} is empty!") from None
 
         xls = open(outfile, "r")
@@ -490,8 +488,8 @@ def generate_updated_xform(
 def create_qrcode(project_id: int, token: str, name: str, odk_central_url: str = None):
     """Create the QR Code for an app-user."""
     if not odk_central_url:
-        logger.debug("ODKCentral connection variables not set in function")
-        logger.debug("Attempting extraction from environment variables")
+        log.debug("ODKCentral connection variables not set in function")
+        log.debug("Attempting extraction from environment variables")
         odk_central_url = settings.ODK_CENTRAL_URL
 
     # Qr code text json in the format acceptable by odk collect.
@@ -555,20 +553,20 @@ def convert_csv(
     csvin.createGeoJson(jsonoutfile)
 
     if len(data) == 0:
-        logger.debug("Parsing csv file %r" % filespec)
+        log.debug("Parsing csv file %r" % filespec)
         # The yaml file is in the package files for osm_fieldwork
         data = csvin.parse(filespec)
     else:
         csvdata = csvin.parse(filespec, data)
         for entry in csvdata:
-            logger.debug(f"Parsing csv data {entry}")
+            log.debug(f"Parsing csv data {entry}")
             if len(data) <= 1:
                 continue
             feature = csvin.createEntry(entry)
             # Sometimes bad entries, usually from debugging XForm design, sneak in
             if len(feature) > 0:
                 if "tags" not in feature:
-                    logger.warning("Bad record! %r" % feature)
+                    log.warning("Bad record! %r" % feature)
                 else:
                     if "lat" not in feature["attrs"]:
                         import epdb

diff --git a/src/backend/app/central/central_routes.py b/src/backend/app/central/central_routes.py
@@ -15,11 +15,11 @@
 #     You should have received a copy of the GNU General Public License
 #     along with FMTM.  If not, see <https:#www.gnu.org/licenses/>.
 #
+from loguru import logger as log
 
 import json
 
 from fastapi import APIRouter, Depends, HTTPException
-from fastapi.logger import logger as logger
 from fastapi.responses import JSONResponse
 from sqlalchemy import (
     column,
@@ -67,7 +67,7 @@ async def create_appuser(
 # async def list_submissions(project_id: int):
 #     """List the submissions data from Central"""
 #     submissions = central_crud.list_submissions(project_id)
-#     logger.info("/central/list_submissions is Unimplemented!")
+#     log.info("/central/list_submissions is Unimplemented!")
 #     return {"data": submissions}
 
 
@@ -170,7 +170,7 @@ async def list_submissions(
 
         return submissions
     except Exception as e:
-        logger.error(e)
+        log.error(e)
         raise HTTPException(status_code=500, detail=str(e)) from e
 
 
@@ -254,7 +254,7 @@ async def get_submission(
 
         return submissions
     except Exception as e:
-        logger.error(e)
+        log.error(e)
         raise HTTPException(status_code=500, detail=str(e)) from e
 
 
@@ -264,7 +264,7 @@ async def get_submission(
 #         filespec: str
 # ):
 #     """Upload the XForm and data files to Central"""
-#     logger.warning("/central/upload is Unimplemented!")
+#     log.warning("/central/upload is Unimplemented!")
 #     return {"message": "Hello World from /central/upload"}
 
 
@@ -278,5 +278,5 @@ async def get_submission(
 #     """
 #     # FileResponse("README.md")
 #     # xxx = central_crud.does_central_exist()
-#     logger.warning("/central/download is Unimplemented!")
+#     log.warning("/central/download is Unimplemented!")
 #     return {"message": "Hello World from /central/download"}
diff --git a/src/backend/app/central/central_schemas.py b/src/backend/app/central/central_schemas.py
@@ -15,10 +15,10 @@
 #     You should have received a copy of the GNU General Public License
 #     along with FMTM.  If not, see <https:#www.gnu.org/licenses/>.
 #
+from loguru import logger as log
 
 from enum import Enum
 
-from fastapi.logger import logger as logger
 from pydantic import BaseModel
 
 
@@ -32,13 +32,13 @@ class Central(CentralBase):
 
 
 class CentralOut(CentralBase):
-    logger.debug("Hello World!")
+    log.debug("Hello World!")
 
 
 class CentralFileType(BaseModel):
     filetype: Enum("FileType", ["xform", "extract", "zip", "xlsform", "all"])
-    logger.debug("Hello World!")
+    log.debug("Hello World!")
 
 
 class CentralDetails(CentralBase):
-    logger.debug("Hello World!")
+    log.debug("Hello World!")