Enhance logging capabilities and error handling

pyproject.toml

@@ -1,6 +1,6 @@
 [tool.poetry]
 name = "telegram-mood-tracker"
-version = "0.4.0"
+version = "0.4.4"
 description = ""
 authors = ["Tobias Waslowski <[email protected]>"]
 readme = "README.md"

scripts/run.sh

@@ -14,6 +14,7 @@ sudo docker run -d --rm \
   --log-driver=awslogs \
   --log-opt awslogs-region="$LOG_REGION" \
   --log-opt awslogs-group="$LOG_GROUP" \
+  --log-opt awslogs-multiline-pattern='^ERROR' \
   --security-opt seccomp:unconfined \
   -v "$HOME/.aws/credentials:/root/.aws/credentials:ro" \
   -v ./config.yaml:/app/config.yaml \

src/app.py

@@ -24,7 +24,7 @@
 
 TOKEN = os.environ.get("TELEGRAM_TOKEN")
 logging.basicConfig(
-    format="%(asctime)s - %(name)s - %(levelname)s - %(message)s", level=logging.INFO
+    format=" %(levelname)s - %(asctime)s - %(name)s - %(message)s", level=logging.INFO
 )
 logging.getLogger("httpx").setLevel(logging.WARNING)
 

src/handlers/error_handler.py

@@ -4,11 +4,14 @@
 from telegram.ext import CallbackContext
 
 
-async def error_handler(update: Update, context: CallbackContext):
+async def error_handler(update: Update, context: CallbackContext) -> None:
     """Log all errors."""
     error_message = context.error
     logging.error(msg="Exception while handling an update:", exc_info=error_message)
     # This fails when the error is not directly caused by a user updated, e.g. in a JobQueue job
+    if update is None:
+        logging.error("Update is None, cannot send error message to user.")
+        return
     await update.effective_user.send_message(
         text=f"An error occurred while processing your message: {error_message}."
     )

src/handlers/record_handlers.py

@@ -157,7 +157,7 @@ def store_record(
     :param user_record: the temporary record being saved
     :return:
     """
-    logging.info(f"Record for user {user_id} is complete: {user_record}")
+    logging.info(f"Persisting record for user {user_id}: {user_record}")
     record_repository.create_record(
         user_id,
         user_record.data,

src/handlers/util.py

@@ -1,13 +1,14 @@
 import logging
 
 from telegram import Update
+from telegram.error import TimedOut
 from tenacity import retry, stop_after_attempt, wait_fixed, retry_if_exception_type
 
 
 @retry(
     stop=stop_after_attempt(3),
     wait=wait_fixed(1),
-    retry=retry_if_exception_type(TimeoutError),
+    retry=retry_if_exception_type((TimeoutError, TimedOut)),
 )
 async def send(update: Update, text: str):
     """

src/model/record.py

@@ -21,6 +21,9 @@ def serialize(self):
             "timestamp": self.timestamp.isoformat(),
         }
 
+    def __str__(self):
+        return f"user_id: {self.user_id}, data: {self.data}, timestamp: {self.timestamp.isoformat()}"
+
 
 class TempRecord(BaseModel):
     """
@@ -36,6 +39,9 @@ def __init__(self, **data):
         super().__init__(**data)
         self.data = {metric.name: None for metric in self.metrics}
 
+    def __str__(self):
+        return f"data: {self.data}, timestamp: {self.timestamp.isoformat()}"
+
     def update_data(self, metric_name: str, value: int):
         if metric_name in self.data:
             self.data[metric_name] = value

src/notifier.py

@@ -3,6 +3,7 @@
 import datetime
 from functools import partial
 
+from telegram.error import TimedOut
 from telegram.ext import CallbackContext, JobQueue
 
 from pyautowire import Injectable, autowire
@@ -29,7 +30,7 @@ async def reminder(self, context: CallbackContext, user_id: int, text: str = Non
     @retry(
         stop=stop_after_attempt(3),
         wait=wait_fixed(1),
-        retry=retry_if_exception_type(TimeoutError),
+        retry=retry_if_exception_type((TimeoutError, TimedOut)),
     )
     async def send_from_context(context: CallbackContext, user_id: int, text: str):
         """Send a message to a user from a context."""

src/repository/db_utils.py

@@ -0,0 +1,21 @@
+"""
+Mechanisms for manually interacting with the database for diagnostics work etc.
+"""
+import logging
+import os
+
+from src.config.config import ConfigurationProvider
+from src.repository.initialize import initialize_database
+from src.repository.record_repository import RecordRepository
+from src.repository.user_repository import UserRepository
+
+
+def init() -> (UserRepository, RecordRepository):
+    configuration = ConfigurationProvider().get_configuration().register()
+    return initialize_database(configuration)
+
+
+if __name__ == "__main__":
+    logging.basicConfig(level=logging.INFO)
+    user_id = int(os.getenv("USER_ID"))
+    user_repository, record_repository = init()

src/repository/dynamodb/dynamodb_record_repository.py

@@ -1,4 +1,5 @@
 import datetime
+import logging
 
 import boto3
 from boto3.dynamodb.conditions import Key
@@ -11,15 +12,25 @@ class DynamoDBRecordRepository(RecordRepository):
     def __init__(self, dynamodb: boto3.resource):
         self.table = dynamodb.Table("record")
         self.table.load()
+        logging.info("DynamoDBRecordRepository initialized.")
 
     def get_latest_record_for_user(self, user_id: int) -> Record | None:
+        result = self.get_latest_records_for_user(user_id, 1)
+        if result:
+            return result[0]
+
+    def get_latest_records_for_user(
+        self, user_id: int, limit: int
+    ) -> list[Record] | None:
+        logging.info(f"Retrieving {limit} latest records for user {user_id}")
         result = self.table.query(
             KeyConditionExpression=Key("user_id").eq(user_id),
             ScanIndexForward=False,
-            Limit=1,
+            Limit=limit,
         )
         if result.get("Items"):
-            return self.parse_record(result["Items"][0])
+            return [self.parse_record(record) for record in result["Items"]]
+        return []
 
     def create_record(self, user_id: int, record_data: dict, timestamp: str):
         self.table.put_item(

src/repository/dynamodb/dynamodb_user_repository.py

@@ -1,4 +1,5 @@
 import json
+import logging
 
 import boto3
 from pyautowire import autowire
@@ -12,6 +13,7 @@ class DynamoDBUserRepository(UserRepository):
     def __init__(self, dynamodb: boto3.resource):
         self.table = dynamodb.Table("user")
         self.table.load()
+        logging.info("DynamoDBUserRepository initialized.")
 
     @autowire("configuration")
     def create_user(self, user_id: int, configuration: Configuration) -> User:

src/repository/mongodb/mongodb_record_repository.py

@@ -13,6 +13,14 @@ def __init__(self, mongo_client: MongoClient):
         super().__init__()
         mood_tracker = mongo_client["mood_tracker"]
         self.records = mood_tracker["records"]
+        logging.info("MongoDBRecordRepository initialized.")
+
+    def get_latest_records_for_user(self, user_id: int, limit: int) -> list[Record]:
+        result = self.records.find(
+            {"user_id": user_id}, sort=[("timestamp", pymongo.DESCENDING)], limit=limit
+        )
+        if result:
+            return [self.parse_record(r) for r in result]
 
     def get_latest_record_for_user(self, user_id: int) -> Record | None:
         result = self.records.find_one(

src/repository/mongodb/mongodb_user_repository.py

@@ -13,6 +13,7 @@ def __init__(self, mongo_client: MongoClient):
         super().__init__()
         mood_tracker = mongo_client["mood_tracker"]
         self.user = mood_tracker["user"]
+        logging.info("MongoDBUserRepository initialized.")
 
     def find_user(self, user_id: int) -> User | None:
         result = self.user.find_one({"user_id": user_id})

src/repository/record_repository.py

@@ -21,6 +21,10 @@ def modify_timestamp(timestamp: str, offset: int) -> datetime.datetime:
     def get_latest_record_for_user(self, user_id: int) -> Record | None:
         pass
 
+    @abstractmethod
+    def get_latest_records_for_user(self, user_id: int, limit: int) -> list[Record]:
+        pass
+
     @abstractmethod
     def create_record(self, user_id: int, record_data: dict, timestamp: str):
         pass