Logging upgrades

app/main.py

@@ -87,7 +87,7 @@ def main():
     subscription_path = subscriber.subscription_path(settings.GCP_PROJECT_ID, settings.PUBSUB_SUBSCRIPTION_ID)
     messages=get_messages(subscriber, subscription_path)
     if len(messages)==0:
-        logger.warning("No messages found.")
+        logger.info("0 messages found.")
         return
 
     def ack(ids: list[str]) -> None:

app/process.py

@@ -1,6 +1,7 @@
 """processes notifications"""
 import logging
 import json
+from collections import Counter
 from typing import Callable
 
 from google.pubsub import ReceivedMessage
@@ -35,7 +36,7 @@ def _parse_message(payload)-> tuple[NotificationParams, SimplifiedNotification]:
             logger.error(f"unhandled action type: {full_note.action}, skipping message")
             raise ValueError(f"unhandled action: {full_note.action}")
 
-    simple_note=SimplifiedNotification(time=full_note.time, user_id=full_note.user_id, data=data)
+    simple_note=SimplifiedNotification(time=full_note.time, user_id=full_note.user_id, action=full_note.action, data=data)
     return full_note, simple_note
 
 def _convert_messages(messages: list[ReceivedMessage], ack_fn: Callable[[list[str]], None]) -> dict[int, ConsolidatedNotifications]:
@@ -115,7 +116,6 @@ def _build_email_tasks(all_notifications: dict[int, ConsolidatedNotifications])
             logger.error(f"submission {sub_id}: no tapir_users row for moderator ids {missing}")
 
         if not to_emails:
-            logger.info(f"submission {sub_id}: no recipients after exclusions, skipping")
             continue
 
         #email data
@@ -133,13 +133,13 @@ def _send_email_tasks(
     sub_infos: dict[int, SubEmailData],
     ids_to_contact: dict[int, UserContact],
     ack_fn: Callable[[list[str]], None],
-) -> None:
+) -> list[int]:
     """render and send emails, acking each submission only after its email sends"""
 
     if settings.REDIRECT_EMAILS:
         logger.info(f"REDIRECT_EMAILS active — all emails → {settings.REDIRECT_RECIPIENT}")
 
-    sent = 0
+    sent_sub_ids: list[int] = []
     for task in email_tasks:
         sub = sub_infos.get(task.submission_id)
         if sub is None:
@@ -167,11 +167,11 @@ def _send_email_tasks(
             )
             ack_fn(task.notifications.ack_ids)  # ack on success or all-refused (terminal)
             if accepted:
-                sent += 1
+                sent_sub_ids.append(task.submission_id)
         except Exception:
             logger.exception(f"Failed to send email for submission {task.submission_id}, will redeliver")
 
-    logger.info(f"Sent {sent}/{len(email_tasks)} email(s) to relay")
+    return sent_sub_ids
 
 
 def process_messages(messages: list[ReceivedMessage], ack_fn: Callable[[list[str]], None]) -> None:
@@ -188,7 +188,7 @@ def process_messages(messages: list[ReceivedMessage], ack_fn: Callable[[list[str
         return
 
     if not all_notifications:
-        logger.info("No valid notifications after parsing, nothing to send")
+        logger.warning("No valid notifications after parsing, nothing to send")
         return
 
     #determine who to email what
@@ -203,11 +203,11 @@ def process_messages(messages: list[ReceivedMessage], ack_fn: Callable[[list[str
             skipped_sub_ids.append(sub_id)
 
     if not email_tasks:
-        logger.warning(f"No emails to send — submissions with no recipients: {sorted(skipped_sub_ids)}")
+        logger.warning(f"No emails to send — no recipients after exclusions for submissions: {sorted(skipped_sub_ids)}")
         return
 
     if skipped_sub_ids:
-        logger.info(f"Skipped submissions (no recipients): {sorted(skipped_sub_ids)}")
+        logger.info(f"Skipped submissions (no recipients after exclusions): {sorted(skipped_sub_ids)}")
 
     #fetch submission data — if batch query fails, skip all sends (will redeliver)
     try:
@@ -217,6 +217,23 @@ def process_messages(messages: list[ReceivedMessage], ack_fn: Callable[[list[str
         return
 
     #send emails
-    _send_email_tasks(email_tasks, sub_infos, ids_to_contact, ack_fn)
-    logger.info(f"Processed {len(messages)} messages, built {len(email_tasks)} email task(s).")
-    return
+    sent_sub_ids = _send_email_tasks(email_tasks, sub_infos, ids_to_contact, ack_fn)
+
+    #stat logging
+    action_counts = Counter(
+        change.action.value
+        for n in all_notifications.values()
+        for change in n.changes
+    )
+    action_summary = ", ".join(f"{k}: {v}" for k, v in sorted(action_counts.items()))
+    total_actions = sum(action_counts.values())
+
+    if len(sent_sub_ids) > 20:
+        sub_summary = f"over 20 submissions"
+    else:
+        sub_summary = f"submission ids: {sorted(sent_sub_ids)}" if sent_sub_ids else "none"
+
+    logger.info(
+        f"Stats: {total_actions} actions ({action_summary}) | "
+        f"{len(sent_sub_ids)}/{len(email_tasks)} emails accepted by relay ({sub_summary})"
+    )

app/schema.py

@@ -46,6 +46,7 @@ class CategoryRejectionData(BaseModel):
 class SimplifiedNotification(BaseModel):
     time: datetime
     user_id: int
+    action: NotificationType
     data: Union[CommentData, PromoteData, PropRespData, NewPropData, CategoryRejectionData]
 
 @dataclass

pyproject.toml

@@ -1,6 +1,6 @@
 [tool.poetry]
 name = "mod-notification-handler"
-version = "0.1.0"
+version = "1.0"
 description = "processes notifications for moderators"
 authors = ["Erin Aster <[email protected]>"]
 readme = "README.md"

tests/test_email_content.py

@@ -3,7 +3,7 @@
 
 import pytest
 
-from app.schema import SimplifiedNotification, CommentData, PromoteData, NewPropData, PropRespData, CategoryRejectionData
+from app.schema import SimplifiedNotification, CommentData, PromoteData, NewPropData, PropRespData, CategoryRejectionData, NotificationType
 from app.schema import SubEmailData
 from app.email_content import get_submission_info, _build_category_string, render_change_block, render_email
 from app.schema import EmailTask, ConsolidatedNotifications
@@ -19,8 +19,8 @@
 _USER = "Alice Mod"
 
 
-def _note(data) -> SimplifiedNotification:
-    return SimplifiedNotification(time=_TIME, user_id=1, data=data)
+def _note(data, action=NotificationType.COMMENT) -> SimplifiedNotification:
+    return SimplifiedNotification(time=_TIME, user_id=1, action=action, data=data)
 
 
 # ── comment ───────────────────────────────────────────────────────────────────
@@ -228,8 +228,8 @@ def test_render_email_contains_all_sections_and_footer():
 def test_render_email_changes_oldest_first():
     t_old = datetime(2024, 6, 15, 14, 30, tzinfo=timezone.utc)
     t_new = datetime(2024, 6, 15, 14, 32, tzinfo=timezone.utc)
-    older = SimplifiedNotification(time=t_old, user_id=1, data=CommentData(comment="older comment"))
-    newer = SimplifiedNotification(time=t_new, user_id=1, data=CommentData(comment="newer comment"))
+    older = SimplifiedNotification(time=t_old, user_id=1, action=NotificationType.COMMENT, data=CommentData(comment="older comment"))
+    newer = SimplifiedNotification(time=t_new, user_id=1, action=NotificationType.COMMENT, data=CommentData(comment="newer comment"))
     notifications = ConsolidatedNotifications(submission_id=123, changes=[newer, older])
     task = EmailTask(submission_id=123, to_emails=[], notifications=notifications)
     text, _ = render_email(task, _mock_submission(), {})

tests/test_process_message.py

@@ -7,7 +7,7 @@
 from arxiv.taxonomy.definitions import CATEGORIES_ACTIVE
 
 from app.process import process_messages, _parse_message, _convert_messages, _build_email_tasks
-from app.schema import  CommentData, PromoteData, NewPropData, PropRespData, CategoryRejectionData, ConsolidatedNotifications, SimplifiedNotification
+from app.schema import  CommentData, PromoteData, NewPropData, PropRespData, CategoryRejectionData, ConsolidatedNotifications, SimplifiedNotification, NotificationType
 
 GOOD_COMMENT = {
     "time": "2024-01-01T10:00:00Z",
@@ -314,11 +314,13 @@ def test_consolidate_messages():
 _NOTE = SimplifiedNotification(
     time=datetime(2024, 1, 1, tzinfo=timezone.utc),
     user_id=246231,
+    action=NotificationType.COMMENT,
     data=CommentData(comment="test"),
 )
 _NOTE_2 = SimplifiedNotification(
     time=datetime(2024, 1, 2, tzinfo=timezone.utc),
     user_id=681201,
+    action=NotificationType.COMMENT,
     data=CommentData(comment="test reply"),
 )