From 5a118df3f90bd5ab3f39c12487ea1f578aa380ae Mon Sep 17 00:00:00 2001
From: Frederick Yin <fkfd@fkfd.me>
Date: Sat, 23 Oct 2021 16:48:15 +0800
Subject: Routine logging and test thereof

---
 jimbrella/routine.py | 55 +++++++++++++++++++++++++++++++++++++++++++++-------
 1 file changed, 48 insertions(+), 7 deletions(-)

(limited to 'jimbrella/routine.py')

diff --git a/jimbrella/routine.py b/jimbrella/routine.py
index 692807e..6a88d41 100644
--- a/jimbrella/routine.py
+++ b/jimbrella/routine.py
@@ -1,3 +1,4 @@
+import logging
 from .database import Database
 from .jform import JForm
 from .config import *
@@ -39,8 +40,22 @@ def chronological_merge(*sheet_lists) -> list:
 def sync_database(takeaway: JForm, giveback: JForm, db: Database):
     takeaway_unread = takeaway.get_unread()
     giveback_unread = giveback.get_unread()
+    logging.info(
+        "Sync database: found %d unread takeaway sheet(s) and %d unread giveback sheet(s)",
+        len(takeaway_unread),
+        len(giveback_unread),
+    )
     unread = chronological_merge(takeaway_unread, giveback_unread)
+    # NOTE: beyond this point `takeaway_unread` and `giveback_unread` are empty
+    #       because chronological_merge popped all their elements
     for sheet in unread:
+        log_args = (
+            sheet["name"],
+            sheet["id"],
+            sheet["phone"],
+            sheet["key"],
+            sheet["date"].isoformat(timespec="seconds"),
+        )
         if sheet["jform_name"] == "takeaway":
             try:
                 db.take_away(
@@ -50,23 +65,49 @@ def sync_database(takeaway: JForm, giveback: JForm, db: Database):
                     sheet["id"],
                     sheet["phone"],
                 )
+                logging.info(
+                    "%s (ID: %s, phone: %s) borrowed umbrella #%d at %s", *log_args
+                )
             except UmbrellaStatusError:
-                pass
+                logging.warning(
+                    "%s (ID: %s, phone: %s) attempted to borrow inavailable umbrella #%d at %s",
+                    *log_args
+                )
             except UmbrellaNotFoundError:
-                pass
+                logging.warning(
+                    "%s (ID: %s, phone: %s) attempted to borrow non-existent umbrella #%d at %s",
+                    *log_args
+                )
         elif sheet["jform_name"] == "giveback":
             try:
-                db.give_back(sheet["key"], sheet["date"])
+                db.give_back(sheet["key"])
+                logging.info(
+                    "%s (ID: %s, phone: %s) returned umbrella #%d at %s", *log_args
+                )
             except UmbrellaStatusError:
-                pass
+                logging.warning(
+                    "%s (ID: %s, phone: %s) attempted to return available umbrella #%d at %s",
+                    *log_args
+                )
             except UmbrellaNotFoundError:
-                pass
+                logging.warning(
+                    "%s (ID: %s, phone: %s) attempted to return non-existent umbrella #%d at %s",
+                    *log_args
+                )
 
 
 def process_overdue(db: Database):
     overdue = Database.find_overdue(db.read())
-    for umb in overdue:
-        db.mark_overdue(umb["serial"], local_now())
+    # mark and log umbrellas that were not, but just became overdue
+    for umb in filter(lambda u: u["status"] == "lent", overdue):
+        db.mark_overdue(umb["serial"])
+        logging.warning(
+            "Umbrella #%d is now overdue, tenant: %s (ID: %s, phone: %s)",
+            umb["serial"],
+            umb["tenant_name"],
+            umb["tenant_id"],
+            umb["tenant_phone"],
+        )
 
 
 if __name__ == "__main__":
-- 
cgit v1.2.3