Add some logging

Still investigating performance on staging.
Wanting to look at database write time.

README.md

@@ -6,7 +6,7 @@ you can try it out.
 
 ## Configuration
 The application expects certain environment variables to be set with values
-which configure the service. The easiest way to do this is to create a .env file
+which configure the service. One way to do this is to create a .env file
 and place it in the application root. The following settings should be 
 included.
 
@@ -39,10 +39,13 @@ the master branch but may be different for development purposes.
 
 The location of the repo.
 *   `RULES_REPO="https://github.com/BiologicalRecordsCentre/record-cleaner-rules.git"`
+
 The branch of the repo.
 *   `RULES_BRANCH="txt_to_csv"`
+
 The directory of the repo.
 *   `RULES_DIR="record-cleaner-rules"`
+
 The sub-direcotry of the csv rules.
 *   `RULES_SUBDIR="rules_as_csv"`
 
@@ -60,14 +63,19 @@ These settings tailor the application for its hosting environment.
 
 The type of environment: [dev|test|prod]. Defaults to prod.
 *   `ENVIRONMENT="prod"`
+
 The location for creating a data directory. Defaults to '.'
 Use . to indicate a path relative to application root.
 *   `DATA_DIR="."`
+
 The location for a backup of the data directory. Defaults to '' implying
 no backups exist. If, on startup, there is no database in the DATA_DIR but
 there is one in the BACKUP_DIR, then it is copied in.
 *   `BACKUP_DIR="/path/to/persistent/storage"`
 
+Log level: [DEBUG|INFO|WARNING|ERROR|CRITICAL]. Defaults to WARNING.
+*   LOG_LEVEL="INFO"
+
 ## Development
 
 ## Testing

app/database.py

@@ -1,4 +1,5 @@
 from collections.abc import Generator
+import logging
 import os
 import shutil
 from typing import TypeAlias, Annotated
@@ -12,6 +13,8 @@
 
 env_settings = get_env_settings()
 
+logger = logging.getLogger(__name__)
+
 # Locate the directory for the database.
 basedir = env_settings.data_dir
 if basedir[0] == '.':
@@ -33,7 +36,7 @@
         if os.path.exists(sqlite_backup_path):
             # Copy in the backup.
             shutil.copy(sqlite_backup_path, sqlite_file_path)
-
+            logger.info('Database restored from backup.')
 
 sqlite_url = f"sqlite:///{sqlite_file_path}"
 

app/main.py

@@ -1,3 +1,6 @@
+import logging
+import sys
+
 from fastapi import FastAPI, Request, status
 from fastapi.encoders import jsonable_encoder
 from fastapi.responses import JSONResponse
@@ -9,6 +12,16 @@
 from app.utility.vice_county.vc_checker import VcChecker
 from app.user.user_repo import UserRepo
 
+# Initialise logging.
+logging.basicConfig(
+    level=settings.env.log_level,
+    format='%(asctime)s %(levelname)s: %(name)s: %(message)s',
+    datefmt='%a, %b %d %Y %I:%M:%S %p',
+    stream=sys.stdout
+)
+logger = logging.getLogger(__name__)
+logger.info('Record Cleaner starting...')
+
 # Instantiate the app.
 app = FastAPI(
     title="Record Cleaner Service",

app/routes.py

@@ -1,3 +1,5 @@
+import logging
+
 from fastapi import APIRouter, Depends, Request
 from pydantic import BaseModel
 
@@ -13,6 +15,8 @@
 from app.validate.validate_routes import router as validate_router
 from app.verify.verify_routes import router as verify_router
 
+logger = logging.getLogger(__name__)
+
 
 class Service(BaseModel):
     title: str
@@ -56,6 +60,7 @@ class SettingResponse(BaseModel):
     summary="Show service information.",
     response_model=Service)
 async def read_service(request: Request):
+    logger.info('TEST TEST TEST TEST TEST TEST')
     base_url = str(request.base_url)[:-1]
     return Service(
         title=app.app.title,

app/rule/rule_repo.py

@@ -1,5 +1,6 @@
 import datetime
 import json
+import logging
 import os
 import shutil
 import subprocess
@@ -21,6 +22,8 @@
 from .stage.stage_repo import StageRepo
 from .tenkm.tenkm_repo import TenkmRuleRepo
 
+logger = logging.getLogger(__name__)
+
 
 class RuleRepo:
     basedir = os.path.abspath(os.path.dirname(__file__))
@@ -124,11 +127,14 @@ def update_thread(self, full: bool):
             .strftime('%Y-%m-%d %H:%M:%S')
         )
 
+        logger.info("Rule update started.")
+
         try:
             self.rules_commit = self.git_update()
             result = self.db_update(full)
             result['commit'] = self.rules_commit
             settings.db.rules_update_result = json.dumps(result)
+            logger.info("Rule update complete.")
         except Exception as e:
             result = {
                 'ok': False,

app/settings_env.py

@@ -20,6 +20,7 @@ class EnvSettings(BaseSettings):
     environment: str = 'prod'  # ['dev'|'test'|'prod']
     data_dir: str = '.'
     backup_dir: str = ''
+    log_level: str = 'WARNING'
 
     model_config = SettingsConfigDict(env_file=".env")