Repository navigation
Explain intermittent first-task startup stalls with published Python workers #123
Description
Observed startup stalls
During the installed Python SDK 2.5.6 qualification, two of six ordinary worker cases produced no first workflow command within the unchanged 30-second test budget. The timer workflow task-family-748dc7a97489, run 01m4phedje0fgb22mm1gtf216y, and mixed-worker workflow task-family-a2362adac658, run 01m4phfy607frxrmcdabkz4rqr, remained pending. Their histories contain StartAccepted/WorkflowStarted and no handler result. SQL inspection after shutdown shows ready tasks with no lease owner or claim error. The timer task has attempt count 1 and a RepairRequested event, while the mixed task has attempt count 0. This does not establish that both tasks were never claimed. The timer registration was absent after shutdown; the mixed registration remained active. Registration/poll wire evidence was not captured in that first attempt, so the failing phase and cause are not established.
Tuple: published Python 2.5.6, wheel SHA256 8bfa26ac97840bd1d93eb6dbed872281e1ee28ad50f4d285a2cbaaca37502496, Server 2.6.0 index sha256:8cc64fd0b577ebe02ac4dc49856585f1d6295363d2c16083d008e699dfc4b0b6, Workflow 2.5.12, MySQL 8.0, Redis 7. Python 3.12, httpx 0.28.1, fastavro 1.13.1. The worker source bytes match release commit 7da889ce010b92c00d2b998d1b45dccf4ee4f4f0.
The isolated built-wheel run passes all six cases. An unchanged installed-registry repeat also passes all six in 17.29 seconds with real response tracing, including all eight successful registrations and deregistrations. Activity-only workers use only activity polls; workflow-only workers use workflow/query polls; mixed workers use all three. The wire trace also records a correctly fenced stale activity completion. This proves the #119 polling correction but does not explain the original startup stalls. No polling-fix regression or SDK/Server cause is asserted.
Investigation and acceptance
- Reproduce with the ordinary published
tests/integration/test_worker_task_families.pyworker driver and the same 30-second budget. Capture registration/discovery latency, poll responses and cleanup for both success and failure, including the cloned query client. - Distinguish registration delay, backend admission/matching, transport delay and a runner limitation before changing code or increasing timeouts.
- Inspect the original task/run, eligibility and deadline through API and database evidence. Explain whether a stopped startup leaves a live registration and whether replacement workers can recover original work safely.
- If a product defect is established, fix it in its owning SDK/Workflow/Server surface, add the smallest executing regression, publish and verify the affected artifacts. If the runner is responsible, correct its lifecycle/diagnostic assumption and repeat the published qualification.
This is a qualification finding from #119, not a Cloud incident or performance claim. Keep the broader Workflow #753 recovery work and .github #122 execution qualification open.
Activity
rmcdaniel commentedon Oct 12, 2026
Three bounded repetitions of the unchanged six-case driver pass with installed PyPI SDK 2.5.6 and the same published Server 2.6.0 image. Times are 17.40, 16.87 and 16.73 seconds. The original per-case 30-second wait and shutdown budgets are unchanged. All 18 original runs finish with the expected result. Actual wire capture records 24 successful registrations and 24 successful deregistrations, including the cloned query clients. The slowest registration is 235 ms, the slowest request 951 ms, and no HTTP error response occurs. API histories and final database task/registration state are retained.
The original failing mixed-worker traceback narrows that case to
run_untilawaiting_register, thenPOST /worker/registerwaiting for HTTP response headers. Server had a persisted active registration after shutdown. The missing original wire trace still prevents identifying why that reply was delayed. These repetitions do not establish a fix or a resource-pressure cause.Next investigation is a bounded delayed-registration-acknowledgement experiment: let the real Server accept registration, hold only its reply, allow the original startup budget to expire, and inspect shutdown plus replacement recovery of the original run. Keep #123 open. Do not infer this is the separate Nexus fixture fingerprint mismatch or the PHP heartbeat-budget defect.
A separate explicit-protocol check passes the same six cases in 16.48 seconds with
DURABLE_WORKFLOW_WORKER_PROTOCOL_VERSION=1.20. The runtime actually advertises worker protocol 1.20 and cooperative cancellation. This checks ordinary Python execution with the explicit setting. It is not a changed default, a three-SDK release qualification or an older-Server compatibility proof.rmcdaniel commentedon Oct 12, 2026
The bounded delayed-registration-reply experiment uses unchanged published Python SDK 2.5.6 and Server 2.6.0. Only the real Server's registration reply is held after its successful 201 response. The original 30-second
run_untilbudget is preserved.With a two-second reply delay, the original timer workflow completes in 5.40 seconds and the worker deregisters. With a 35-second delay, registration commits but
run_untilexpires in 30.03 seconds before the first workflow task. The SDK has not acknowledged registration and sends no deregistration. A replacement completes the same original run and result with exactly oneWorkflowCompletedevent. SQL retains the old registration and heartbeat, while the Server's 30-second freshness rule excludes it from the active API roster. No stale claim or duplicated completion is observed.Calling
stop()during a 15-second registration reply hold takes 15.13 seconds despite a three-secondshutdown_timeout. The documented drain deadline begins after registration, so this measures the startup boundary rather than proving a drain-contract regression. Once the reply arrives, cleanup deregisters and a replacement completes the original pending run once.The experiment reproduces the originally awaited registration phase and demonstrates original-run recovery. It does not establish why the original reply was delayed. Keep #123 open. The next useful SDK work is registration-phase diagnostics and executing delayed-reply coverage, while preserving the original result budget and registration-incarnation authority. No timeout increase or default-protocol attribution is warranted.
All task containers, both database volumes, network and dependency scratch are removed. The published source and original failing records remain unchanged.
rmcdaniel commentedon Oct 12, 2026
Stable backport
Backport #126 onto published 2.5.7 and prepare 2.5.8. A startup timeout now identifies the worker, workflow and existing wait budget. Discovery/registration regressions and the post-startup timeout control execute without changing deadlines, polling or cleanup authority.
Main contains the unqualified 2.6.0 Nexus producer candidate. This branch includes only the reviewed diagnostic, its tests/docs and aligned 2.5.8 package declarations. No producer API is included.
The equivalent main change passes all normal checks, including real HTTP integration. The stable branch receives independent source/package qualification, then exact registry and published Server verification. #123 stays open because the original unconstrained registration delay remains unexplained.
rmcdaniel commentedon Oct 12, 2026
Python 2.5.8 is published from
b30d38fa2e457a361a1a955eabd1e51e1c28c0b7, the narrow stable backport in #127. All stable source checks and publication/registry checks pass.Fresh installed worker code matches that release source byte-for-byte. Both pinned and default PyPI resolution select 2.5.8. Wheel SHA256
6873d8e5473aa457c292b76b6e8960876d1513f6da601cbf7ca4c6e013e44e9d, sdist SHA256ff15015635f5abd652f4d71e850f4acccf62a7456f2f25e97b4f26499212ad40.The real HTTP delayed-registration check uses unmodified published Server 2.6.1 at
sha256:ef043e5c582761e486a64a2ab4226476e17ae4f71682ef59d6b9ddd784d246b6and the SDK's actual default 1.20. A two-second held reply completes normally in 5.30 seconds. With a 35-second held reply after Server HTTP 201, the new startup error occurs at 30.03 seconds under the unchanged 30-second wait budget, includes worker/workflow identities and preserves its cause. No task polling or deregistration occurs before acknowledgment. A replacement completes the original run once with the correct timer result.The original unconstrained registration delay remains unexplained, so #123 stays open. This release improves diagnosis without extending budgets or shipping the unqualified producer APIs from main. The live worker documentation contains the new explanation. Sample App #205 is the remaining pinned-image follow-through. Other package and Server consumers do not require unchanged releases for this Python-only diagnostic. Cloud and Rust retain their frozen qualification tuples and decide their own adoption.
rmcdaniel commentedon Oct 12, 2026
Pinned consumer delivery is complete in Sample App #205. All 18 source checks, 45 activity recovery cases, nine external-effect cases and ten main workflows pass with actual Python 2.5.8. Both native published image checks pass, and anonymous Docker Hub/GHCR main and immutable reads match index sha256:6f36155ac6427017ee2a31420348a5dde7512f4117863ef6b3e37f1302f41ed9. The diagnostic is available in the shipped development image. The original unconstrained registration delay remains under investigation and #123 stays open.
rmcdaniel commentedon Oct 13, 2026
Rechecked the retained original failure and the unchanged ordinary driver. The driver's bytes still match the earlier retained driver (SHA-256
e65d1b288388989b228c973a6d7ad46d7d474a60d9e3c6ca018486e3d7f5ac7e). Its original per-scenario 30-second result/startup budgets and 10-second shutdown waits are unchanged.Installed PyPI 2.5.9, wheel
12031fe9677d918d77b37c73bb80c2c45be71a34fcdf2438e159b519894d4ca8, passes all six cases in 21.69 seconds against unchanged published Server 2.6.1 (sha256:ef043e5c582761e486a64a2ab4226476e17ae4f71682ef59d6b9ddd784d246b6), Workflow 2.5.12, MySQL 8.0 and Redis 7. Tracing covers all HTTP clients, including the cloned query client: eight successful registrations, eight successful registration deletions, 157 query-poll replies and no HTTP error response. The slowest registration is 97 ms. All six original runs return the expected value; all their task rows are completed, have repair count zero, and no registration remains for their queues.Additional original evidence: the timer's
RepairRequestedat 2026-10-11 22:31:29.531827 UTC explicitly originates fromDELETE /api/worker/registrations/py-worker-fb55023b. The task already has attempt count 1. This is cleanup recovering a claimed task, not proof that initial matching never happened. The mixed-worker traceback still places its timeout in registration while waiting for response headers; its accepted registration survives in the original SQL snapshot.The original logs lack per-request duration and the failed timer's SDK claim/hydration/callback/publication trace. Neither the current pass nor these cleanup records establish why the first command/reply was delayed. No product correction or timeout increase is warranted from this evidence. #123 remains open; the next reproduction must preserve discovery, registration, task owner/lease, payload/callback/publication phases and typed error bodies before shutdown. The original failures remain unchanged.