Merge pull request #139 from eitchtee/dev

feat: cleanup and format logs

app/WYGIWYH/logs/ProcrastinateFilter.py

@@ -0,0 +1,19 @@
+import logging
+
+
+class ProcrastinateFilter(logging.Filter):
+    # from https://github.com/madzak/python-json-logger/blob/master/src/pythonjsonlogger/jsonlogger.py#L19
+    _reserved_log_keys = frozenset(
+        """args asctime created exc_info exc_text filename
+        funcName levelname levelno lineno module msecs message msg name pathname
+        process processName relativeCreated stack_info thread threadName""".split()
+    )
+
+    def filter(self, record: logging.LogRecord):
+        record.procrastinate = {}
+        for key, value in vars(record).items():
+            if not key.startswith("_") and key not in self._reserved_log_keys | {
+                "procrastinate"
+            }:
+                record.procrastinate[key] = value  # type: ignore
+        return True

app/WYGIWYH/settings.py

@@ -278,28 +278,42 @@ if "procrastinate" in sys.argv:
         "disable_existing_loggers": False,
         "formatters": {
             "procrastinate": {
-                "format": "%(asctime)s %(levelname)-7s %(name)s %(message)s"
+                "format": "[%(asctime)s] - %(levelname)s - %(name)s - %(message)s -> %(procrastinate)s",
+                "datefmt": "%Y-%m-%d %H:%M:%S",
+            },
+            "standard": {
+                "format": "[%(asctime)s] - %(levelname)s - %(name)s - %(message)s",
+                "datefmt": "%Y-%m-%d %H:%M:%S",
+            },
+        },
+        "filters": {
+            "procrastinate": {
+                "()": "WYGIWYH.logs.ProcrastinateFilter.ProcrastinateFilter",
+                "name": "procrastinate",
             },
         },
         "handlers": {
             "procrastinate": {
-                "level": "DEBUG",
+                "level": "INFO",
                 "class": "logging.StreamHandler",
                 "formatter": "procrastinate",
+                "filters": ["procrastinate"],
             },
             "console": {
                 "class": "logging.StreamHandler",
+                "formatter": "standard",
+                "level": "INFO",
             },
         },
         "loggers": {
             "procrastinate": {
                 "handlers": ["procrastinate"],
-                "level": "INFO",
+                "propagate": True,
-                "propagate": False,
             },
             "root": {
-                "handlers": ["console"],
+                "handlers": None,
                 "level": "INFO",
+                "propagate": False,
             },
         },
     }
@@ -308,24 +322,25 @@ else:
         "version": 1,
         "disable_existing_loggers": False,
         "formatters": {
-            "procrastinate": {
+            "standard": {
-                "format": "%(asctime)s %(levelname)-7s %(name)s %(message)s"
+                "format": "[%(asctime)s] - %(levelname)s - %(name)s - %(message)s",
+                "datefmt": "%Y-%m-%d %H:%M:%S",
             },
         },
         "handlers": {
-            "procrastinate": {
-                "level": "DEBUG",
-                "class": "logging.StreamHandler",
-                "formatter": "procrastinate",
-            },
             "console": {
                 "class": "logging.StreamHandler",
+                "formatter": "standard",
+                "level": "INFO",
+            },
+            "procrastinate": {
+                "level": "INFO",
+                "class": "logging.StreamHandler",
             },
         },
         "loggers": {
             "procrastinate": {
                 "handlers": None,
-                "level": "INFO",
                 "propagate": False,
             },
             "root": {

app/apps/common/tasks.py

@@ -11,7 +11,7 @@ logger = logging.getLogger(__name__)
 
 
 @app.periodic(cron="0 4 * * *")
-@app.task(queueing_lock="remove_old_jobs", pass_context=True)
+@app.task(queueing_lock="remove_old_jobs", pass_context=True, name="remove_old_jobs")
 async def remove_old_jobs(context, timestamp):
     try:
         return await builtin_tasks.remove_old_jobs(
@@ -30,7 +30,7 @@ async def remove_old_jobs(context, timestamp):
 
 
 @app.periodic(cron="0 6 1 * *")
-@app.task(queueing_lock="remove_expired_sessions")
+@app.task(queueing_lock="remove_expired_sessions", name="remove_expired_sessions")
 async def remove_expired_sessions(timestamp=None):
     """Cleanup expired sessions by using Django management command."""
     try:

app/apps/import_app/tasks.py

@@ -9,7 +9,7 @@ from apps.import_app.services import ImportServiceV1
 logger = logging.getLogger(__name__)
 
 
-@app.task
+@app.task(name="process_import")
 def process_import(import_run_id: int, file_path: str):
     try:
         import_run = ImportRun.objects.get(id=import_run_id)

app/apps/rules/tasks.py

@@ -18,7 +18,7 @@ from apps.transactions.models import (
 logger = logging.getLogger(__name__)
 
 
-@app.task
+@app.task(name="check_for_transaction_rules")
 def check_for_transaction_rules(
     instance_id: int,
     signal,

app/apps/transactions/tasks.py

@@ -13,7 +13,7 @@ logger = logging.getLogger(__name__)
 
 
 @app.periodic(cron="0 0 * * *")
-@app.task
+@app.task(name="generate_recurring_transactions")
 def generate_recurring_transactions(timestamp=None):
     try:
         RecurringTransaction.generate_upcoming_transactions()
@@ -26,7 +26,7 @@ def generate_recurring_transactions(timestamp=None):
 
 
 @app.periodic(cron="10 1 * * *")
-@app.task
+@app.task(name="cleanup_deleted_transactions")
 def cleanup_deleted_transactions(timestamp=None):
     with cachalot_disabled():
         if settings.ENABLE_SOFT_DELETE and settings.KEEP_DELETED_TRANSACTIONS_FOR == 0:

docker/dev/procrastinate/start

@@ -12,4 +12,4 @@ done
 
 rm -f /tmp/migrations_complete
 
-exec watchfiles --filter python "python manage.py procrastinate worker"
+exec python manage.py procrastinate worker

docker/dev/supervisord/supervisord.conf

@@ -20,7 +20,7 @@ directory=/usr/src/app
 command=/bin/bash /start
 stdout_logfile=/dev/fd/1
 stdout_logfile_maxbytes=0
-stderr_logfile=/dev/fd/2
+stderr_logfile=/dev/fd/1
 stderr_logfile_maxbytes=0
 autorestart=true
 startretries=5
@@ -33,7 +33,7 @@ numprocs=%(ENV_TASK_WORKERS)s
 numprocs_start=1
 stdout_logfile=/dev/fd/1
 stdout_logfile_maxbytes=0
-stderr_logfile=/dev/fd/2
+stderr_logfile=/dev/fd/1
 stderr_logfile_maxbytes=0
 autorestart=true
 startretries=5

docker/prod/supervisord/supervisord.conf

@@ -17,7 +17,7 @@ directory=/usr/src/app
 command=/bin/bash /start
 stdout_logfile=/dev/fd/1
 stdout_logfile_maxbytes=0
-stderr_logfile=/dev/fd/2
+stderr_logfile=/dev/fd/1
 stderr_logfile_maxbytes=0
 autorestart=true
 startretries=5
@@ -31,7 +31,7 @@ numprocs=%(ENV_TASK_WORKERS)s
 numprocs_start=1
 stdout_logfile=/dev/fd/1
 stdout_logfile_maxbytes=0
-stderr_logfile=/dev/fd/2
+stderr_logfile=/dev/fd/1
 stderr_logfile_maxbytes=0
 autorestart=true
 startretries=5