chore(task-processor): add better logging for failed tasks (#4186)

task_processor/processor.py

@@ -99,7 +99,15 @@ def _run_task(task: typing.Union[Task, RecurringTask]) -> typing.Tuple[Task, Tas
         task_run.finished_at = timezone.now()
         task.mark_success()
     except Exception as e:
-        logger.warning(e)
+        logger.warning(
+            "Failed to execute task '%s'. Exception was: %s",
+            task.task_identifier,
+            str(e),
+            exc_info=True,
+        )
+        logger.debug("args: %s", str(task.args))
+        logger.debug("kwargs: %s", str(task.kwargs))
+
         task.mark_failure()
 
         task_run.result = TaskResult.FAILURE

tests/unit/task_processor/test_unit_task_processor_processor.py

@@ -210,9 +210,18 @@ def _a_task():
     )
 
 
-def test_run_task_runs_task_and_creates_task_run_object_when_failure(db):
+def test_run_task_runs_task_and_creates_task_run_object_when_failure(
+    db: None, caplog: pytest.LogCaptureFixture
+) -> None:
     # Given
-    task = Task.create(_raise_exception.task_identifier, scheduled_for=timezone.now())
+    task_processor_logger = logging.getLogger("task_processor")
+    task_processor_logger.propagate = True
+    task_processor_logger.level = logging.DEBUG
+
+    msg = "Error!"
+    task = Task.create(
+        _raise_exception.task_identifier, args=(msg,), scheduled_for=timezone.now()
+    )
     task.save()
 
     # When
@@ -229,6 +238,21 @@ def test_run_task_runs_task_and_creates_task_run_object_when_failure(db):
     task.refresh_from_db()
     assert not task.completed
 
+    assert len(caplog.records) == 3
+
+    warning_log = caplog.records[0]
+    assert warning_log.levelname == "WARNING"
+    assert warning_log.message == (
+        f"Failed to execute task '{task.task_identifier}'. Exception was: {msg}"
+    )
+
+    debug_log_args, debug_log_kwargs = caplog.records[1:]
+    assert debug_log_args.levelname == "DEBUG"
+    assert debug_log_args.message == f"args: ['{msg}']"
+
+    assert debug_log_kwargs.levelname == "DEBUG"
+    assert debug_log_kwargs.message == "kwargs: {}"
+
 
 def test_run_task_runs_failed_task_again(db):
     # Given
@@ -440,8 +464,8 @@ def _dummy_task(key: str = DEFAULT_CACHE_KEY, value: str = DEFAULT_CACHE_VALUE):
 
 
 @register_task_handler()
-def _raise_exception():
-    raise Exception()
+def _raise_exception(msg: str):
+    raise Exception(msg)
 
 
 @register_task_handler()