Add logging for watchdog

Signed-off-by: Christoph Auer <cau@zurich.ibm.com>

Author: cau-git

docling_jobkit/orchestrators/rq/orchestrator.py

@@ -276,7 +276,7 @@ async def _watchdog_task(self) -> None:
         may recreate Task objects on every poll, resetting started_at to the current
         time and making a task.started_at-based check unreliable.
         """
-        _log.debug("Watchdog starting")
+        _log.warning("Watchdog starting")
         # Maps task_id -> time the watchdog first observed the task in STARTED state.
         # Independent of task.started_at which may be reset by polling machinery.
         first_seen_started: dict[str, datetime.datetime] = {}
@@ -285,6 +285,14 @@ async def _watchdog_task(self) -> None:
             try:
                 now = datetime.datetime.now(datetime.timezone.utc)
 
+                all_statuses = {
+                    tid: t.task_status for tid, t in list(self.tasks.items())
+                }
+                _log.warning(
+                    f"Watchdog scan: {len(self.tasks)} tasks in memory, "
+                    f"statuses={all_statuses}"
+                )
+
                 # Determine which tasks are currently in STARTED state.
                 currently_started = {
                     task_id
@@ -295,11 +303,17 @@ async def _watchdog_task(self) -> None:
                 # Remove tasks that are no longer STARTED (completed, failed, gone).
                 for task_id in list(first_seen_started.keys()):
                     if task_id not in currently_started:
+                        _log.warning(
+                            f"Watchdog: task {task_id} left STARTED, removing from tracking"
+                        )
                         del first_seen_started[task_id]
 
                 # Record first observation time for newly STARTED tasks.
                 for task_id in currently_started:
                     if task_id not in first_seen_started:
+                        _log.warning(
+                            f"Watchdog: first observation of STARTED task {task_id}"
+                        )
                         first_seen_started[task_id] = now
 
                 # Check tasks that have been STARTED long enough to be past grace period.
@@ -309,9 +323,22 @@ async def _watchdog_task(self) -> None:
                     if (now - first_seen).total_seconds() > _WATCHDOG_GRACE_PERIOD
                 ]
 
+                _log.warning(
+                    f"Watchdog: {len(currently_started)} started, "
+                    f"{len(first_seen_started)} tracked, "
+                    f"{len(candidates)} past grace period"
+                )
+
                 for task_id in candidates:
                     key = f"{_HEARTBEAT_KEY_PREFIX}:{task_id}"
                     alive = await self._async_redis_conn.exists(key)
+                    age = (
+                        now - first_seen_started[task_id]
+                    ).total_seconds()
+                    _log.warning(
+                        f"Watchdog: checking task {task_id} "
+                        f"(age={age:.0f}s), heartbeat key alive={bool(alive)}"
+                    )
                     if not alive:
                         _log.warning(
                             f"Task {task_id} heartbeat key missing — "