Timeline Event logging

db/constants.py

@@ -0,0 +1,5 @@
+TIMELINE_ORDER_NOT_ISSUED = "ORDER_NOT_ISSUED"
+TIMELINE_ORDER_ISSUED = "ORDER_ISSUED"
+TIMELINE_ORDER_CONFIRMED = "ORDER_CONFIRMED"
+TIMELINE_ORDER_NOT_PUNISHED = "ORDER_NOT_PUNISHED"
+TIMELINE_ORDER_PUNISHED = "ORDER_PUNISHED"

db/models.py

@@ -44,6 +44,9 @@ class User(BaseModel):
         else:
             return f"{self.mastodon_username}@{self.mastodon_server}"
 
+    def __str__(self):
+        return self.telegram_username
+
     class Meta:
         table_name = 'user'
 
@@ -205,3 +208,36 @@ class SkipDay(BaseModel):
 
     class Meta:
         table_name = 'skip_day'
+
+class TimelineEvent(BaseModel):
+    updated_at = DateTimeField(null=False)
+    type = TextField(null=False)
+    text = TextField(null=False)
+    extra = TextField(null=True)
+
+    user = ForeignKeyField(
+        User,
+        column_name='user_id',
+        field='id',
+        null=False,
+        backref="timeline_events"
+    )
+
+    orders_pool = ForeignKeyField(
+        OrdersPool,
+        column_name='orders_pool_id',
+        field='id',
+        null=False,
+        backref="timeline_events"
+    )
+
+    order_status = ForeignKeyField(
+        OrderStatus,
+        column_name='order_status_id',
+        field='id',
+        null=True,
+        backref="timeline_events"
+    )
+
+    class Meta:
+        table_name = 'timeline_event'

db/queries.py

@@ -1,7 +1,9 @@
 import datetime
 from peewee import JOIN, fn
 
-from .models import database, User, OrdersPool, DomSubUsers, Repeat, SkipDay, OrderStatus, MastodonServer
+from util import sqlite_time
+
+from .models import database, User, OrdersPool, DomSubUsers, Repeat, SkipDay, OrderStatus, MastodonServer, TimelineEvent
 
 def initdb():
   database.connect()
@@ -160,3 +162,14 @@ def order_status_outstanding():
     .group_by(OrderStatus)
     .having(fn.COUNT(Punishment.id) == 0)
   )
+
+def timeline_event_put(type, text, user, orders_pool, order_status=None, extra=None):
+  return TimelineEvent.create(
+    updated_at=sqlite_time(datetime.datetime.now(datetime.UTC)),
+    type=type,
+    text=text,
+    user=user,
+    orders_pool=orders_pool,
+    order_status=order_status,
+    extra=extra
+  )

generate.py

@@ -3,7 +3,7 @@ import json
 import logging
 import random
 
-from db.queries import repeat_get, repeat_increment, repeat_clear, repeat_put
+from db.queries import repeat_increment, repeat_clear, repeat_put
 from settings import ORDERS_YML
 
 logger = logging.getLogger(__name__)
@@ -33,7 +33,7 @@ def read_config():
 
 def generate_order(orders_pool):
     if len(orders_pool.orders) == 0:
-        return { }
+        return { "reason": "Orders pool empty" }
 
     # Do we want to repeat?
     if orders_pool.repeat.count() != 0:
@@ -49,7 +49,7 @@ def generate_order(orders_pool):
 
     if orders_pool.probability < random.random():
         # No orders today
-        return { }
+        return { "reason": "No orders this time" }
 
     # Pick new orders
     (result, repeat_p) = pick_order(orders_pool.orders)

main.py

@@ -4,10 +4,11 @@ import argparse
 import asyncio
 import json
 
+from db.constants import TIMELINE_ORDER_ISSUED, TIMELINE_ORDER_NOT_ISSUED
 from scheduling import OrderScheduler
 from generate import generate_order
 from orders import order_issue, order_check
-from db.queries import orders_pool_by_id
+from db.queries import orders_pool_by_id, timeline_event_put
 from telegram.telegram import handle_commands
 from telegram.commands import commands
 
@@ -16,10 +17,28 @@ logger = logging.getLogger(__name__)
 async def do_order_issue(order_pool_id):
     orders_pool = orders_pool_by_id(args.orders_pool_id)
 
-    order_status = await order_issue(orders_pool)
+    issue_result = await order_issue(orders_pool)
 
-    if order_status is not None:
+    if 'order_status' in issue_result:
+        order_status = issue_result['order_status']
         logger.info(f'Issued order id {order_status.id}')
+        timeline_event_put(
+            TIMELINE_ORDER_ISSUED,
+            f"Order issued from {orders_pool.name} - {order_status.text.split("\n")[0]}",
+            user=orders_pool.user,
+            orders_pool=orders_pool,
+            order_status=order_status,
+            extra={
+                "mastodon_status_url": issue_result['mastodon_status']['url']
+            }
+        )
+    elif 'reason' in issue_result:
+        timeline_event_put(
+            TIMELINE_ORDER_NOT_ISSUED,
+            issue_result['reason'],
+            user=orders_pool.user,
+            orders_pool=orders_pool
+        )
 
 if __name__=='__main__':
     logging.basicConfig(

migrations/022_add_timeline_event.py

@@ -0,0 +1,58 @@
+"""Peewee migrations -- 022_add_timeline_event.py.
+
+Some examples (model - class or model name)::
+
+    > Model = migrator.orm['table_name']            # Return model in current state by name
+    > Model = migrator.ModelClass                   # Return model in current state by name
+
+    > migrator.sql(sql)                             # Run custom SQL
+    > migrator.run(func, *args, **kwargs)           # Run python function with the given args
+    > migrator.create_model(Model)                  # Create a model (could be used as decorator)
+    > migrator.remove_model(model, cascade=True)    # Remove a model
+    > migrator.add_fields(model, **fields)          # Add fields to a model
+    > migrator.change_fields(model, **fields)       # Change fields
+    > migrator.remove_fields(model, *field_names, cascade=True)
+    > migrator.rename_field(model, old_field_name, new_field_name)
+    > migrator.rename_table(model, new_table_name)
+    > migrator.add_index(model, *col_names, unique=False)
+    > migrator.add_not_null(model, *field_names)
+    > migrator.add_default(model, field_name, default)
+    > migrator.add_constraint(model, name, sql)
+    > migrator.drop_index(model, *col_names)
+    > migrator.drop_not_null(model, *field_names)
+    > migrator.drop_constraints(model, *constraints)
+
+"""
+
+from contextlib import suppress
+
+import peewee as pw
+from peewee_migrate import Migrator
+
+
+with suppress(ImportError):
+    import playhouse.postgres_ext as pw_pext
+
+
+def migrate(migrator: Migrator, database: pw.Database, *, fake=False):
+    """Write your migrations here."""
+    
+    @migrator.create_model
+    class TimelineEvent(pw.Model):
+        id = pw.AutoField()
+        updated_at = pw.DateTimeField()
+        type = pw.TextField()
+        text = pw.TextField()
+        extra = pw.TextField(null=True)
+        user = pw.ForeignKeyField(column_name='user_id', field='id', model=migrator.orm['user'])
+        orders_pool = pw.ForeignKeyField(column_name='orders_pool_id', field='id', model=migrator.orm['orders_pool'])
+        order_status = pw.ForeignKeyField(column_name='order_status_id', field='id', model=migrator.orm['order_status'], null=True)
+
+        class Meta:
+            table_name = "timeline_event"
+
+
+def rollback(migrator: Migrator, database: pw.Database, *, fake=False):
+    """Write your rollback migrations here."""
+    
+    migrator.remove_model('timeline_event')

orders.py

@@ -2,9 +2,10 @@ import logging
 import datetime
 import asyncio
 
+from db.constants import TIMELINE_ORDER_CONFIRMED, TIMELINE_ORDER_NOT_PUNISHED, TIMELINE_ORDER_PUNISHED
 from util import make_session
 from generate import generate_order, generate_punishment
-from db.queries import order_status_by_id, order_status_put, order_status_confirm
+from db.queries import order_status_by_id, order_status_put, order_status_confirm, timeline_event_put
 from mastodon import Mastodon
 from telegram.telegram import Telegram
 from settings import ENV
@@ -63,14 +64,14 @@ async def order_issue(orders_pool):
       if orders_pool.user.mastodon_username is None:
           logger.info('Cannot issue order without mastodon username')
           await order_telegram_post_need_mastodon(session, orders_pool)
-          return
+          return { "reason": "Cannot issue order without mastodon username" }
 
       orders_info = generate_order(orders_pool)
 
       if 'orders' not in orders_info:
-          logger.info("No orders for today")
+          logger.info(f"{orders_pool} - {orders_info['reason']}")
           await order_telegram_post_none(session, orders_pool)
-          return
+          return { "reason": orders_info['reason'] }
 
       orders_str = "\n".join(orders_info['orders'])
       
@@ -97,14 +98,17 @@ async def order_issue(orders_pool):
           m_status['url']
           )
 
-      return order_status_put(
+      return {
+        "order_status" : order_status_put(
           orders_pool,
           orders_pool.user,
           m_status['id'],
           created_at,
           due_at,
           orders_str
-          )
+        ),
+        "mastodon_status": m_status
+      }
 
 async def punishment_mastodon_post(session, orders_pool, punishment_str, reply_id=None):
     user = orders_pool.user
@@ -136,8 +140,7 @@ async def punishment_telegram_post(session, orders_pool, punishment_str, m_url):
 async def punishment_issue(session, order_status):
     if order_status.pool is None or order_status.pool.punishment_pool is None:
         logger.info(f'Unable to issue a punishment for {order_status.id}, no punishment pool for order pool {order_status.pool.name}')
-        # TODO: No punishment mastodon/telegram posts
+        return { "reason": "No punishment pool"}
-        return
 
     punishment_pool = order_status.pool.punishment_pool
 
@@ -158,15 +161,18 @@ async def punishment_issue(session, order_status):
         punishment_status['url']
     )
 
-    order_status_put(
+    return {
-        punishment_pool,
+        "order_status": order_status_put(
-        order_status.user,
+            punishment_pool,
-        punishment_status['id'],
+            order_status.user,
-        punishment_status['created_at'],
+            punishment_status['id'],
-        None,
+            punishment_status['created_at'],
-        punishment_str,
+            None,
-        punishment_for=order_status
+            punishment_str,
-    )
+            punishment_for=order_status
+        ),
+        "mastodon_status": punishment_status
+    }
 
 order_check_lock = asyncio.Lock()
 async def order_check(order_status_id):
@@ -191,6 +197,16 @@ async def order_check(order_status_id):
                     confirmed_at = d['created_at']
                     order_status_confirm(order_status.id, confirmed_at)
                     logger.info('Confirmed order %s' % (order_status.id))
+                    timeline_event_put(
+                        TIMELINE_ORDER_CONFIRMED,
+                        f'Order confirmed - {order_status.text.split("\n")[0]}',
+                        order_status.user,
+                        order_status.pool,
+                        order_status,
+                        extra={
+                            "mastodon_status_url": d['url']
+                        }
+                    )
                     break
                 
             if confirmed_at is None:
@@ -200,4 +216,25 @@ async def order_check(order_status_id):
                 if(due_at < datetime.datetime.now(datetime.UTC)):
                     logger.info('Time to issue a punishment for %s' % order_status.id)
 
-                    await punishment_issue(session, order_status)
+                    issue_result = await punishment_issue(session, order_status)
+
+                    if 'order_status' in issue_result:
+                        punishment_status = issue_result['order_status']
+                        timeline_event_put(
+                            TIMELINE_ORDER_PUNISHED,
+                            f'Order punished - {punishment_status.text.split("\n")[0]}',
+                            punishment_status.user,
+                            punishment_status.pool,
+                            punishment_status,
+                            extra={
+                                "mastodon_status_url": issue_result['mastodon_status']['url']
+                            }
+                        )
+                    elif 'reason' in issue_result:
+                        timeline_event_put(
+                            TIMELINE_ORDER_NOT_PUNISHED,
+                            f'Order not punished - {issue_result['reason']}',
+                            order_status.user,
+                            order_status.pool,
+                            order_status
+                        )

scheduling.py

@@ -4,9 +4,10 @@ import pytz
 
 from scheduler.asyncio import Scheduler
 
+from db.constants import TIMELINE_ORDER_ISSUED, TIMELINE_ORDER_NOT_ISSUED
 from settings import TIMEZONE, SCHEDULE_SYNC_INTERVAL
 from orders import order_issue, order_check
-from db.queries import orders_pool_by_id, orders_pool_scheduled, orders_pool_since, skip_day_contains, order_status_outstanding
+from db.queries import orders_pool_by_id, orders_pool_scheduled, orders_pool_since, skip_day_contains, order_status_outstanding, timeline_event_put
 from util import order_time, sqlite_time
 
 logger = logging.getLogger(__name__)
@@ -63,27 +64,56 @@ class OrderScheduler():
       or
       (not orders_pool.weekdays and day_of_week in WEEKDAYS)
     ):
-      logger.info(f'{orders_pool.name}[{orders_pool.user.telegram_username}] Not scheduled for today')
+      logger.info(f'{orders_pool} Not scheduled for today')
+      timeline_event_put(
+        TIMELINE_ORDER_NOT_ISSUED,
+        f"{orders_pool.name} is not scheduled for today",
+        user=orders_pool.user,
+        orders_pool=orders_pool
+      )
       return
 
     # Skip stored dates
     today = datetime.datetime.now(tz=self.tz).strftime("%Y-%m-%d")
-    logger.info('Today %s' % today)
     if (skip_day_contains(orders_pool.user, today)):
-      logger.info('Today is a skip day')
+      logger.info(f'{orders_pool} Today is a skip day')
+      timeline_event_put(
+        TIMELINE_ORDER_NOT_ISSUED,
+        f"Today is a skip day",
+        user=orders_pool.user,
+        orders_pool=orders_pool
+      )
       return
     
     logger.info(f'Issuing order for {orders_pool.name}[{orders_pool.user.telegram_username}]')
 
-    order_status = await order_issue(orders_pool)
+    issue_result = await order_issue(orders_pool)
 
-    if order_status is not None:
+    if 'order_status' in issue_result:
+      order_status = issue_result['order_status']
       # Schedule check
       self.scheduler.once(
         order_status.due_at + GRACE_PERIOD,
         self.scheduled_check,
         args=(order_status.id,)
       )
+      timeline_event_put(
+        TIMELINE_ORDER_ISSUED,
+        f"Order issued - {order_status.text.split("\n")[0]}",
+        user=orders_pool.user,
+        orders_pool=orders_pool,
+        order_status=order_status,
+        extra={
+          "mastodon_status_url": issue_result['mastodon_status']['url']
+        }
+      )
+    elif 'reason' in issue_result:
+      timeline_event_put(
+        TIMELINE_ORDER_NOT_ISSUED,
+        issue_result['reason'],
+        user=orders_pool.user,
+        orders_pool=orders_pool
+      )
 
   async def scheduled_check(self, outstanding_order_id):
     await order_check(outstanding_order_id)