jpmschweitzer/scheduler
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases 5 Wiki Activity

feat(health-report): name the task that produced each check_history row

Browse Source 
`source` names the code that wrote a row. It cannot name the schedule that
invoked it, and two tasks may share one executor -- so a row could not answer
the question a health record mostly exists to answer: which job broke?

Concretely, on 2026-08-11 a 425 MB probe task and the 5 GB nightly backup both
ran through config_backup_executor. The probe failed and wrote

  source: scheduler/config_backup_executor
  status: critical
  error:  Backup file was not created

which is byte-for-byte what a nightly backup failure would have written. The
row was true and unattributable, and the reflex it invited -- delete the
inconvenient row -- was correctly refused. Attribution is the actual fix: the
record stays intact and starts saying who it is about.

Carried in a ContextVar rather than an argument. Executors are invoked as
execute(config, settings) and there are ten of them, several dormant -- existing
only as a string in a database row and becoming live the moment someone inserts
a task naming them. A signature change would leave those broken in a way nothing
imports, greps or tests would reveal. Injecting the name into `config` was the
other option and is worse: `config` is what a human wrote in the task
definition, and an executor is entitled to reject keys it does not recognise.

Two properties make the ContextVar safe, both verified in the deployed runtime
rather than reasoned about:

  - asyncio.to_thread propagates the context, so reporting still sees the task
    after T-74 moved executor bodies into worker threads. Had it not, every row
    from a real executor would have quietly lost its task while unit tests kept
    passing -- so there is a test that specifically goes through report_async.
  - Each asyncio Task gets its own copy, so the five concurrent executions
    MAX_CONCURRENT_TASKS permits cannot read each other's value. The isolation
    test yields mid-execution to force interleaving; without that it would pass
    even against a shared global.

A plain await does NOT get its own copy and leaks the value to the caller, which
the runtime check showed. Both real entry points go through create_task, but
task_scope resets via token rather than depending on that.

The field is omitted, not nulled, when there is no task: report() is callable
from a script, and a null would claim a task existed with no name.

Mutation-checked: removing the scope from the engine fails both isolation tests.

Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
jpmschweitzer
2026-08-11 12:22:47 +02:00
co-authored by Claude
parent 1c861e2fe1
commit 538bfe5944
6 changed files with 431 additions and 2 deletions
Download Patch File Download Diff File Expand all files Collapse all files
.pql/changelog/ticket_history/2026-08.sql
+86
View File
@@ -45,3 +45,89 @@ So every timeout since 2025-12-07 has been recorded as a generic failure carryin
FIX: catch asyncio.TimeoutError explicitly in _run_executor, ahead of the broad handler, and let it propagate (or return a marker execute_task can distinguish). Note the ordering is the whole bug — a narrower except after a broader one is dead code, and there is no linter configured here to say so.
Related: a thread started by asyncio.to_thread cannot be cancelled, so after T-74 a timeout frees the loop while the work continues to completion. Whatever ''timeout'' comes to mean should say so rather than implying the work stopped.', NULL, '2026-08-11 09:59:05', '2026-08-11 09:59:05.545', '2026-08-11 09:59:05.545', NULL, 'af08842306d6326036b1865b8cbf7c58', 2) ON CONFLICT(hash) DO NOTHING;
INSERT INTO ticket_history (ticket_record_id, field, old_value, new_value, changed_by, changed_at, created_at, updated_at, deleted_at, hash, canonical_version) VALUES ('06FZ0GQAR5KXM3PTG0QT3R1PV8', 'description', 'get_tasks_for_minute (src/tasks/executor.py:70) excludes any task holding a task_executions row with status=''running'':
AND id NOT IN (SELECT task_id FROM task_executions WHERE status = ''running'')
Nothing ever reconciles that row. It is written before the executor runs and updated after, so a process that dies in between leaves it ''running'' permanently — and the task is then excluded from every future minute, forever, with no error, no alarm and no log line. The task simply stops existing as far as the scheduler is concerned.
This is not hypothetical. test_example_task has held a ''running'' row since 2025-12-07 — 5916 hours. It happens to be disabled, so nothing is broken today; the mechanism is what matters, not this instance.
The exposure is real and daily: Watchtower restarts this container every morning at 4 AM. Any task still running at that moment is permanently unscheduled by it. The config backup runs 03:05 and takes ~21 minutes, which is not far off.
The failure mode is the one this system keeps producing: it looks like nothing. A backup that stops running forever produces no failure — it produces silence, and silence reads as health.
FIX: reconcile at startup. Any row left ''running'' when the process starts cannot be running, because the process that owned it is gone. Mark those ''orphaned'' (or ''failed'' with a message naming the restart) during app startup, before the scheduler begins its first minute. Consider also a stale-row guard for rows older than the task''s timeout_seconds, which covers a killed worker without a restart.
The audit trail is preserved either way — this is a status correction, not a deletion.', 'get_tasks_for_minute (src/tasks/executor.py:70) excludes any task holding a task_executions row with status=''running'':
AND id NOT IN (SELECT task_id FROM task_executions WHERE status = ''running'')
Nothing ever reconciles that row. It is written before the executor runs and updated after, so a process that dies in between leaves it ''running'' permanently — and the task is then excluded from every future minute, forever, with no error, no alarm and no log line. The task simply stops existing as far as the scheduler is concerned.
This is not hypothetical. test_example_task has held a ''running'' row since 2025-12-07 — 5916 hours. It happens to be disabled, so nothing is broken today; the mechanism is what matters, not this instance.
The exposure is real and daily: Watchtower restarts this container every morning at 4 AM. Any task still running at that moment is permanently unscheduled by it. The config backup runs 03:05 and takes ~21 minutes, which is not far off.
The failure mode is the one this system keeps producing: it looks like nothing. A backup that stops running forever produces no failure — it produces silence, and silence reads as health.
FIX: reconcile at startup. Any row left ''running'' when the process starts cannot be running, because the process that owned it is gone. Mark those ''orphaned'' (or ''failed'' with a message naming the restart) during app startup, before the scheduler begins its first minute. Consider also a stale-row guard for rows older than the task''s timeout_seconds, which covers a killed worker without a restart.
The audit trail is preserved either way — this is a status correction, not a deletion.
FIXED in v1.6.0 (e45de4f). TaskExecutor.reconcile_orphaned_executions() runs in the lifespan before the scheduler starts.
Proven on the real system rather than in a test. The row that had been ''running'' since 2025-12-07 22:44 was released at startup:
WARNING - Orphaned execution recovered: test_example_task was left ''running''
since 2025-12-07 22:44:00.046695. That task had been excluded from
scheduling until now.
Rows still ''running'' afterwards: 0. Status is ''orphaned'', error names the restart.
''orphaned'' rather than ''failed'' because the outcome is genuinely unknown — a task that completed and never got to update its row looks exactly like one that died halfway, and ''failed'' would assert something nobody observed.
Ordering is part of the fix and is mutation-checked: reconciliation must complete before the first minute is processed, or the first tick still sees the stale rows. Removing the startup call fails the test.
Not extended to a duration-based sweep, deliberately. While the process lives, execute_task''s finally always closes the row out, so a stale row implies a dead owner; a time-based rule would have to distinguish a slow task from a dead one and would eventually close the record of a task that is still working.', NULL, '2026-08-11 10:11:39', '2026-08-11 10:11:39.058', '2026-08-11 10:11:39.058', NULL, '0cec030639664cf075a113be75218e8d', 2) ON CONFLICT(hash) DO NOTHING;
INSERT INTO ticket_history (ticket_record_id, field, old_value, new_value, changed_by, changed_at, created_at, updated_at, deleted_at, hash, canonical_version) VALUES ('06FZ0GQAR5KXM3PTG0QT3R1PV8', 'status', 'backlog', 'done', NULL, '2026-08-11 10:11:39', '2026-08-11 10:11:39.178', '2026-08-11 10:11:39.178', NULL, 'cd26a078365d91d44e6d284e80da39f5', 2) ON CONFLICT(hash) DO NOTHING;
INSERT INTO ticket_history (ticket_record_id, field, old_value, new_value, changed_by, changed_at, created_at, updated_at, deleted_at, hash, canonical_version) VALUES ('06FZ0GQBTCRCTXK6EJF0T8CS2C', 'description', 'execute_task has an `except asyncio.TimeoutError` handler (src/tasks/executor.py:179) that records status=''timeout''. It can never run.
_run_executor wraps the awaited call in `except Exception` (line 219) and returns the error as a value. Since Python 3.11 asyncio.TimeoutError IS the builtin TimeoutError, which inherits OSError -> Exception, so the broad handler catches it first and converts it into an ordinary (None, error) tuple. execute_task then sees a non-None error and files status=''failed''.
Verified in the deployed runtime:
asyncio.TimeoutError is TimeoutError: True
MRO: TimeoutError -> OSError -> Exception -> BaseException
And confirmed against 8 months of history — 18,785 executions, and the count of status=''timeout'' rows is zero:
success 16690 | failed 2093 | running 2 | timeout 0
So every timeout since 2025-12-07 has been recorded as a generic failure carrying a traceback. Operationally that erases the distinction that matters most when a job misbehaves: "this job is too slow for its window" and "this job is broken" need different responses, and right now they look identical in the history.
FIX: catch asyncio.TimeoutError explicitly in _run_executor, ahead of the broad handler, and let it propagate (or return a marker execute_task can distinguish). Note the ordering is the whole bug — a narrower except after a broader one is dead code, and there is no linter configured here to say so.
Related: a thread started by asyncio.to_thread cannot be cancelled, so after T-74 a timeout frees the loop while the work continues to completion. Whatever ''timeout'' comes to mean should say so rather than implying the work stopped.', 'execute_task has an `except asyncio.TimeoutError` handler (src/tasks/executor.py:179) that records status=''timeout''. It can never run.
_run_executor wraps the awaited call in `except Exception` (line 219) and returns the error as a value. Since Python 3.11 asyncio.TimeoutError IS the builtin TimeoutError, which inherits OSError -> Exception, so the broad handler catches it first and converts it into an ordinary (None, error) tuple. execute_task then sees a non-None error and files status=''failed''.
Verified in the deployed runtime:
asyncio.TimeoutError is TimeoutError: True
MRO: TimeoutError -> OSError -> Exception -> BaseException
And confirmed against 8 months of history — 18,785 executions, and the count of status=''timeout'' rows is zero:
success 16690 | failed 2093 | running 2 | timeout 0
So every timeout since 2025-12-07 has been recorded as a generic failure carrying a traceback. Operationally that erases the distinction that matters most when a job misbehaves: "this job is too slow for its window" and "this job is broken" need different responses, and right now they look identical in the history.
FIX: catch asyncio.TimeoutError explicitly in _run_executor, ahead of the broad handler, and let it propagate (or return a marker execute_task can distinguish). Note the ordering is the whole bug — a narrower except after a broader one is dead code, and there is no linter configured here to say so.
Related: a thread started by asyncio.to_thread cannot be cancelled, so after T-74 a timeout frees the loop while the work continues to completion. Whatever ''timeout'' comes to mean should say so rather than implying the work stopped.
FIXED in v1.6.0 (e45de4f). _run_executor now catches asyncio.TimeoutError ahead of the broad handler and re-raises, so execute_task''s timeout branch is reachable for the first time.
A trap surfaced while fixing it, and it is the interesting part. While the branch was unreachable, a timeout travelled the NORMAL path — which does update scheduled_tasks. Making the branch reachable without adding that write would have swapped a wrong status (''failed'') for a stale one (last_status showing the previous run''s outcome indefinitely). _update_task_outcome now mirrors terminal outcomes onto the parent row. A fix that repairs the reported symptom while breaking something adjacent is worse than the bug.
The timeout message also records that the work may still be running: after T-74 executors are handed to asyncio.to_thread, and a thread cannot be cancelled, so wait_for frees the loop while the work continues to completion. Saying "timed out" without that would imply the work stopped.
Mutation-checked: removing the narrow except clause fails the propagation test. A third test pins that ordinary exceptions are still returned rather than raised, so the narrow clause cannot start swallowing anything else.', NULL, '2026-08-11 10:11:39', '2026-08-11 10:11:39.291', '2026-08-11 10:11:39.291', NULL, '8bdb93fdcfbc234e18f3d034ddf25277', 2) ON CONFLICT(hash) DO NOTHING;
INSERT INTO ticket_history (ticket_record_id, field, old_value, new_value, changed_by, changed_at, created_at, updated_at, deleted_at, hash, canonical_version) VALUES ('06FZ0GQBTCRCTXK6EJF0T8CS2C', 'status', 'backlog', 'done', NULL, '2026-08-11 10:11:39', '2026-08-11 10:11:39.421', '2026-08-11 10:11:39.421', NULL, '7bc24ec03ed40ccacd71d7c7269d05af', 2) ON CONFLICT(hash) DO NOTHING;
.pql/changelog/tickets/2026-08.sql
+110
View File
@@ -48,3 +48,113 @@ So every timeout since 2025-12-07 has been recorded as a generic failure carryin
FIX: catch asyncio.TimeoutError explicitly in _run_executor, ahead of the broad handler, and let it propagate (or return a marker execute_task can distinguish). Note the ordering is the whole bug — a narrower except after a broader one is dead code, and there is no linter configured here to say so.
Related: a thread started by asyncio.to_thread cannot be cancelled, so after T-74 a timeout frees the loop while the work continues to completion. Whatever ''timeout'' comes to mean should say so rather than implying the work stopped.', 'backlog', 'medium', NULL, NULL, NULL, '2026-08-11 09:59:05.427', '2026-08-11 09:59:05.545', NULL, 'ae0db866086e38b681b0ea32837df277', 2) ON CONFLICT(record_id) DO UPDATE SET type=excluded.type, parent_record_id=excluded.parent_record_id, title=excluded.title, description=excluded.description, status=excluded.status, priority=excluded.priority, assigned_to=excluded.assigned_to, team=excluded.team, decision_ref=excluded.decision_ref, updated_at=excluded.updated_at, deleted_at=excluded.deleted_at, hash=excluded.hash, canonical_version=excluded.canonical_version WHERE excluded.updated_at >= tickets.updated_at;
INSERT INTO tickets (record_id, type, parent_record_id, title, description, status, priority, assigned_to, team, decision_ref, created_at, updated_at, deleted_at, hash, canonical_version) VALUES ('06FZ0GQAR5KXM3PTG0QT3R1PV8', 'bug', NULL, 'A restart mid-task unschedules that task forever, silently', 'get_tasks_for_minute (src/tasks/executor.py:70) excludes any task holding a task_executions row with status=''running'':
AND id NOT IN (SELECT task_id FROM task_executions WHERE status = ''running'')
Nothing ever reconciles that row. It is written before the executor runs and updated after, so a process that dies in between leaves it ''running'' permanently — and the task is then excluded from every future minute, forever, with no error, no alarm and no log line. The task simply stops existing as far as the scheduler is concerned.
This is not hypothetical. test_example_task has held a ''running'' row since 2025-12-07 — 5916 hours. It happens to be disabled, so nothing is broken today; the mechanism is what matters, not this instance.
The exposure is real and daily: Watchtower restarts this container every morning at 4 AM. Any task still running at that moment is permanently unscheduled by it. The config backup runs 03:05 and takes ~21 minutes, which is not far off.
The failure mode is the one this system keeps producing: it looks like nothing. A backup that stops running forever produces no failure — it produces silence, and silence reads as health.
FIX: reconcile at startup. Any row left ''running'' when the process starts cannot be running, because the process that owned it is gone. Mark those ''orphaned'' (or ''failed'' with a message naming the restart) during app startup, before the scheduler begins its first minute. Consider also a stale-row guard for rows older than the task''s timeout_seconds, which covers a killed worker without a restart.
The audit trail is preserved either way — this is a status correction, not a deletion.
FIXED in v1.6.0 (e45de4f). TaskExecutor.reconcile_orphaned_executions() runs in the lifespan before the scheduler starts.
Proven on the real system rather than in a test. The row that had been ''running'' since 2025-12-07 22:44 was released at startup:
WARNING - Orphaned execution recovered: test_example_task was left ''running''
since 2025-12-07 22:44:00.046695. That task had been excluded from
scheduling until now.
Rows still ''running'' afterwards: 0. Status is ''orphaned'', error names the restart.
''orphaned'' rather than ''failed'' because the outcome is genuinely unknown — a task that completed and never got to update its row looks exactly like one that died halfway, and ''failed'' would assert something nobody observed.
Ordering is part of the fix and is mutation-checked: reconciliation must complete before the first minute is processed, or the first tick still sees the stale rows. Removing the startup call fails the test.
Not extended to a duration-based sweep, deliberately. While the process lives, execute_task''s finally always closes the row out, so a stale row implies a dead owner; a time-based rule would have to distinguish a slow task from a dead one and would eventually close the record of a task that is still working.', 'backlog', 'high', NULL, NULL, NULL, '2026-08-11 09:59:05.153', '2026-08-11 10:11:39.058', NULL, '8d88d4684f803319131765d97772e64d', 2) ON CONFLICT(record_id) DO UPDATE SET type=excluded.type, parent_record_id=excluded.parent_record_id, title=excluded.title, description=excluded.description, status=excluded.status, priority=excluded.priority, assigned_to=excluded.assigned_to, team=excluded.team, decision_ref=excluded.decision_ref, updated_at=excluded.updated_at, deleted_at=excluded.deleted_at, hash=excluded.hash, canonical_version=excluded.canonical_version WHERE excluded.updated_at >= tickets.updated_at;
INSERT INTO tickets (record_id, type, parent_record_id, title, description, status, priority, assigned_to, team, decision_ref, created_at, updated_at, deleted_at, hash, canonical_version) VALUES ('06FZ0GQAR5KXM3PTG0QT3R1PV8', 'bug', NULL, 'A restart mid-task unschedules that task forever, silently', 'get_tasks_for_minute (src/tasks/executor.py:70) excludes any task holding a task_executions row with status=''running'':
AND id NOT IN (SELECT task_id FROM task_executions WHERE status = ''running'')
Nothing ever reconciles that row. It is written before the executor runs and updated after, so a process that dies in between leaves it ''running'' permanently — and the task is then excluded from every future minute, forever, with no error, no alarm and no log line. The task simply stops existing as far as the scheduler is concerned.
This is not hypothetical. test_example_task has held a ''running'' row since 2025-12-07 — 5916 hours. It happens to be disabled, so nothing is broken today; the mechanism is what matters, not this instance.
The exposure is real and daily: Watchtower restarts this container every morning at 4 AM. Any task still running at that moment is permanently unscheduled by it. The config backup runs 03:05 and takes ~21 minutes, which is not far off.
The failure mode is the one this system keeps producing: it looks like nothing. A backup that stops running forever produces no failure — it produces silence, and silence reads as health.
FIX: reconcile at startup. Any row left ''running'' when the process starts cannot be running, because the process that owned it is gone. Mark those ''orphaned'' (or ''failed'' with a message naming the restart) during app startup, before the scheduler begins its first minute. Consider also a stale-row guard for rows older than the task''s timeout_seconds, which covers a killed worker without a restart.
The audit trail is preserved either way — this is a status correction, not a deletion.
FIXED in v1.6.0 (e45de4f). TaskExecutor.reconcile_orphaned_executions() runs in the lifespan before the scheduler starts.
Proven on the real system rather than in a test. The row that had been ''running'' since 2025-12-07 22:44 was released at startup:
WARNING - Orphaned execution recovered: test_example_task was left ''running''
since 2025-12-07 22:44:00.046695. That task had been excluded from
scheduling until now.
Rows still ''running'' afterwards: 0. Status is ''orphaned'', error names the restart.
''orphaned'' rather than ''failed'' because the outcome is genuinely unknown — a task that completed and never got to update its row looks exactly like one that died halfway, and ''failed'' would assert something nobody observed.
Ordering is part of the fix and is mutation-checked: reconciliation must complete before the first minute is processed, or the first tick still sees the stale rows. Removing the startup call fails the test.
Not extended to a duration-based sweep, deliberately. While the process lives, execute_task''s finally always closes the row out, so a stale row implies a dead owner; a time-based rule would have to distinguish a slow task from a dead one and would eventually close the record of a task that is still working.', 'done', 'high', NULL, NULL, NULL, '2026-08-11 09:59:05.153', '2026-08-11 10:11:39.177', NULL, '99284d5f4a53a35637ee10c7b6b66c6e', 2) ON CONFLICT(record_id) DO UPDATE SET type=excluded.type, parent_record_id=excluded.parent_record_id, title=excluded.title, description=excluded.description, status=excluded.status, priority=excluded.priority, assigned_to=excluded.assigned_to, team=excluded.team, decision_ref=excluded.decision_ref, updated_at=excluded.updated_at, deleted_at=excluded.deleted_at, hash=excluded.hash, canonical_version=excluded.canonical_version WHERE excluded.updated_at >= tickets.updated_at;
INSERT INTO tickets (record_id, type, parent_record_id, title, description, status, priority, assigned_to, team, decision_ref, created_at, updated_at, deleted_at, hash, canonical_version) VALUES ('06FZ0GQBTCRCTXK6EJF0T8CS2C', 'bug', NULL, 'The ''timeout'' execution status is unreachable; timeouts are filed as generic failures', 'execute_task has an `except asyncio.TimeoutError` handler (src/tasks/executor.py:179) that records status=''timeout''. It can never run.
_run_executor wraps the awaited call in `except Exception` (line 219) and returns the error as a value. Since Python 3.11 asyncio.TimeoutError IS the builtin TimeoutError, which inherits OSError -> Exception, so the broad handler catches it first and converts it into an ordinary (None, error) tuple. execute_task then sees a non-None error and files status=''failed''.
Verified in the deployed runtime:
asyncio.TimeoutError is TimeoutError: True
MRO: TimeoutError -> OSError -> Exception -> BaseException
And confirmed against 8 months of history — 18,785 executions, and the count of status=''timeout'' rows is zero:
success 16690 | failed 2093 | running 2 | timeout 0
So every timeout since 2025-12-07 has been recorded as a generic failure carrying a traceback. Operationally that erases the distinction that matters most when a job misbehaves: "this job is too slow for its window" and "this job is broken" need different responses, and right now they look identical in the history.
FIX: catch asyncio.TimeoutError explicitly in _run_executor, ahead of the broad handler, and let it propagate (or return a marker execute_task can distinguish). Note the ordering is the whole bug — a narrower except after a broader one is dead code, and there is no linter configured here to say so.
Related: a thread started by asyncio.to_thread cannot be cancelled, so after T-74 a timeout frees the loop while the work continues to completion. Whatever ''timeout'' comes to mean should say so rather than implying the work stopped.
FIXED in v1.6.0 (e45de4f). _run_executor now catches asyncio.TimeoutError ahead of the broad handler and re-raises, so execute_task''s timeout branch is reachable for the first time.
A trap surfaced while fixing it, and it is the interesting part. While the branch was unreachable, a timeout travelled the NORMAL path — which does update scheduled_tasks. Making the branch reachable without adding that write would have swapped a wrong status (''failed'') for a stale one (last_status showing the previous run''s outcome indefinitely). _update_task_outcome now mirrors terminal outcomes onto the parent row. A fix that repairs the reported symptom while breaking something adjacent is worse than the bug.
The timeout message also records that the work may still be running: after T-74 executors are handed to asyncio.to_thread, and a thread cannot be cancelled, so wait_for frees the loop while the work continues to completion. Saying "timed out" without that would imply the work stopped.
Mutation-checked: removing the narrow except clause fails the propagation test. A third test pins that ordinary exceptions are still returned rather than raised, so the narrow clause cannot start swallowing anything else.', 'backlog', 'medium', NULL, NULL, NULL, '2026-08-11 09:59:05.427', '2026-08-11 10:11:39.291', NULL, 'b7379fa662b40c6996f17c36b64010c0', 2) ON CONFLICT(record_id) DO UPDATE SET type=excluded.type, parent_record_id=excluded.parent_record_id, title=excluded.title, description=excluded.description, status=excluded.status, priority=excluded.priority, assigned_to=excluded.assigned_to, team=excluded.team, decision_ref=excluded.decision_ref, updated_at=excluded.updated_at, deleted_at=excluded.deleted_at, hash=excluded.hash, canonical_version=excluded.canonical_version WHERE excluded.updated_at >= tickets.updated_at;
INSERT INTO tickets (record_id, type, parent_record_id, title, description, status, priority, assigned_to, team, decision_ref, created_at, updated_at, deleted_at, hash, canonical_version) VALUES ('06FZ0GQBTCRCTXK6EJF0T8CS2C', 'bug', NULL, 'The ''timeout'' execution status is unreachable; timeouts are filed as generic failures', 'execute_task has an `except asyncio.TimeoutError` handler (src/tasks/executor.py:179) that records status=''timeout''. It can never run.
_run_executor wraps the awaited call in `except Exception` (line 219) and returns the error as a value. Since Python 3.11 asyncio.TimeoutError IS the builtin TimeoutError, which inherits OSError -> Exception, so the broad handler catches it first and converts it into an ordinary (None, error) tuple. execute_task then sees a non-None error and files status=''failed''.
Verified in the deployed runtime:
asyncio.TimeoutError is TimeoutError: True
MRO: TimeoutError -> OSError -> Exception -> BaseException
And confirmed against 8 months of history — 18,785 executions, and the count of status=''timeout'' rows is zero:
success 16690 | failed 2093 | running 2 | timeout 0
So every timeout since 2025-12-07 has been recorded as a generic failure carrying a traceback. Operationally that erases the distinction that matters most when a job misbehaves: "this job is too slow for its window" and "this job is broken" need different responses, and right now they look identical in the history.
FIX: catch asyncio.TimeoutError explicitly in _run_executor, ahead of the broad handler, and let it propagate (or return a marker execute_task can distinguish). Note the ordering is the whole bug — a narrower except after a broader one is dead code, and there is no linter configured here to say so.
Related: a thread started by asyncio.to_thread cannot be cancelled, so after T-74 a timeout frees the loop while the work continues to completion. Whatever ''timeout'' comes to mean should say so rather than implying the work stopped.
FIXED in v1.6.0 (e45de4f). _run_executor now catches asyncio.TimeoutError ahead of the broad handler and re-raises, so execute_task''s timeout branch is reachable for the first time.
A trap surfaced while fixing it, and it is the interesting part. While the branch was unreachable, a timeout travelled the NORMAL path — which does update scheduled_tasks. Making the branch reachable without adding that write would have swapped a wrong status (''failed'') for a stale one (last_status showing the previous run''s outcome indefinitely). _update_task_outcome now mirrors terminal outcomes onto the parent row. A fix that repairs the reported symptom while breaking something adjacent is worse than the bug.
The timeout message also records that the work may still be running: after T-74 executors are handed to asyncio.to_thread, and a thread cannot be cancelled, so wait_for frees the loop while the work continues to completion. Saying "timed out" without that would imply the work stopped.
Mutation-checked: removing the narrow except clause fails the propagation test. A third test pins that ordinary exceptions are still returned rather than raised, so the narrow clause cannot start swallowing anything else.', 'done', 'medium', NULL, NULL, NULL, '2026-08-11 09:59:05.427', '2026-08-11 10:11:39.420', NULL, '333edb040cfa995cf26f45b6fa2cd2f9', 2) ON CONFLICT(record_id) DO UPDATE SET type=excluded.type, parent_record_id=excluded.parent_record_id, title=excluded.title, description=excluded.description, status=excluded.status, priority=excluded.priority, assigned_to=excluded.assigned_to, team=excluded.team, decision_ref=excluded.decision_ref, updated_at=excluded.updated_at, deleted_at=excluded.deleted_at, hash=excluded.hash, canonical_version=excluded.canonical_version WHERE excluded.updated_at >= tickets.updated_at;