Skip to content

Closing a run with many open timers or activities exceeds PHP's execution limit (close time grows faster than the inventory) #958

Closed

Description

@rmcdaniel

What happens

On published Server 2.11.5 (Core 2.15.1), terminating a run that holds many open timers takes far longer than linear time. Past about 800 open timers it exceeds PHP's 30-second max_execution_time: the request answers 500 and the run stays open. Cancelling a run with 1,089 open activities also answers 500.

The default StructuralLimits allow 2,000 pending timers and 2,000 pending activities per run, so these are valid runs.

Measurements

Published 2.11.5 image, SQLite, with the repair-pass/schedule:evaluate maintenance loop stopped. Requests are raw worker HTTP on protocol 1.20. Each workflow task opens 99 start_timer commands (3,600 s) and an open_signal_wait; a signal brings the next task. The run is then terminated over HTTP.

Open timers POST /api/workflows/{id}/terminate
198 200 in 4.0 s
396 200 in 10.3 s
792 200 in 28.9 s
1,089 500 after 30 s (Maximum execution time of 30 seconds exceeded); run stays waiting

Doubling the inventory roughly triples the close time.

Activities behave the same way: POST .../cancel on a run with 1,089 open activities answers 500. With the maintenance loop running, both closes fail earlier with SQLSTATE[HY000]: General error: 5 database is locked.

Expected

WorkflowStub::attemptTerminalCommand cancels every open activity and timer, and should finish within the request budget for any inventory the structural limits admit.

Context

The native Rust server (durable-workflow/server#325) cancels the same inventory in one linear transaction. It follows the Workflow source here because no published reference can record a passing close at this size. I have not profiled where PHP spends the time. A per-event projection or history scan inside the cancellation loop would fit the measurements, but that is unconfirmed.

Completed delivery — 2026-10-29

Published Core 2.15.7, source 3aa98b8473b130dbc141457f76ccc32e4aa58062, is installed in the accepted Server 2.11.6 / chart 0.3.6 tuple. Normal image and chart verification 40885194236 passed every required gate. Both architecture artifacts match the qualified Server/Core source bytes, and anonymous pulls pass from both registries. Final tuple and qualification.

Two separate fresh amd64 installed-image runs each normally admitted 2,000 timers plus 2,000 activities. Cancellation returns HTTP200 at 27.500472 CPU seconds / 40.710720 wall seconds / 126MiB; termination returns HTTP200 at 27.787926 CPU seconds / 40.692728 wall seconds / 124MiB. PHP limits remain 128MiB / 30 CPU seconds and structural limits remain unchanged. Terminal event counts/projections, pre-expiry late-result fencing, unchanged full canonical-row digests after repeat409, and exactly12 finite maintenance iterations per case pass. Each maintenance log retains two caught heartbeat-prune lock errors; final candidates and failure arrays are zero/empty. Complete installed evidence. The completed synthetic backend was removed and absence verified.

Selected published PHP/Python/Rust cancellation and cleanup consumers pass on the same immutable bytes. The separately discovered, pre-existing concurrent Python condition replay defect remains open as durable-workflow/sdk-python#223 / #956; it is not claimed fixed here. Earlier full Core and published-upgrade qualification remains in #959. This terminal-close requirement is delivered and verified.

Activity

  1. rmcdaniel commented on Oct 28, 2026

    @rmcdaniel
    MemberAuthor

    General accepts the PHP implementation and qualification handoff from rust-server. The published 2.11.5 / Core 2.15.1 measurements above remain the current HTTP evidence; they are not yet a profile of current Core 2.15.6.

    Current source confirms the default limits of 2,000 pending activities and 2,000 pending timers. The terminal-command path iterates all admitted inventory. Timer cancellation scans loaded history for both a prior cancellation and the scheduling payload per timer; activity cancellation repeatedly loads prior cancellation history. These are candidate sources of repeated work, not yet a measured attribution of the reported request time.

    Next: reproduce/profile current PHP close behavior, repair the repeated work while preserving complete cancellation/history/claim/projection semantics, and qualify admitted timer/activity inventories, mixed inventory and retry/fence controls within the existing request budget. Lower limits, raised execution timeouts, incomplete closes or permanently stopped maintenance are not acceptance. Native cap changes and frozen fixtures remain with the Rust owner. Server #843's unrelated qualified signal fix continues through its current CI first.

  2. rmcdaniel commented on Oct 28, 2026

    @rmcdaniel
    MemberAuthor

    General diagnosis update, 2026-10-28:

    Current published Core 2.15.6 reproduces superlinear terminal-close work with real WorkflowStub start/signal admission and protocol 1.20 bridge completions. In an isolated PHP 8.3.36 / Laravel / SQLite-file source API probe, terminate takes 2,111 ms for 198 timers and 5,217 ms for 396 timers. SQL accounts for about 198 ms and 430 ms respectively. This is a Core API measurement, not HTTP/SAPI request-budget acceptance.

    Configured-history-model instrumentation measures 268,607 attribute reads at 198 timers and 1,013,833 at 396. Sampled call stacks attribute most to repeated TimerCancellation::record and scheduledPayload scans. Activity cancellation separately reloads the growing ActivityCancelled prefix once per execution. The candidate repair builds run-scoped lookups once inside the existing terminal-command transaction and preserves normal event writes, cancellation payloads and model hooks.

    The first candidate reduces the 198-timer instrumented reads to 30,619. The same uninstrumented small source API cases take 1,473 ms and 3,004 ms. These measurements describe this local workload only.

    The regression-test candidate currently passes eight cases / 175 assertions: cancel/terminate with timer, activity and mixed inventories; duplicate requests; rollback then retry; prior cancellation receipts and latest scheduled timer metadata. Read-only original-root-method overlay produces six expected resource-growth failures and two passing controls, with no test errors. Full ECS and PHPStan pass. The first PHPStan attempt used insufficient shared-memory scratch and failed with SIGBUS/internal cache-write errors; a correctly provisioned rerun passes without a source workaround.

    The 2,000-timer plus 2,000-activity admission probe admitted all 4,000 items, then its close attempt failed with SQLite no such savepoint: trans2. No close-time or maximum-inventory acceptance is claimed. Diagnosis must recover the original database failure and verify complete close within the existing request budget, including actual Server HTTP and maintenance/retry behavior. No limit or timeout has been weakened. The candidate is not ready for release.

    The newly corrected Symfony Mime advisory and Server #845/#846 take immediate priority. General retains this PHP defect and will continue its full boundary qualification after the narrow security correction. Native cap work and frozen fixtures remain Rust-owned.

  3. rmcdaniel commented on Oct 29, 2026

    @rmcdaniel
    MemberAuthor

    Uploaded 2.11.6 candidate: both fresh default-maximum closes passed on the unchanged amd64 image at sha256:c20c901eaa8dedfa04e5b89280f93b23a5e84e143410e3ceb63ff0881d701641, Server source d13ebdb5eccc3d33b9d3c0e1ebc9ab0cb116e121, published Core 2.15.7. This is candidate evidence; normal release acceptance is still pending Server #857.

    Each separate fresh run normally admitted 2,000 timers and 2,000 activities through 41 raw-worker HTTP batches on protocol 1.20, with no source overlay or structural-limit increase. Each close ran under PHP memory_limit=128M and max_execution_time=30 while the finite maintenance loop was active.

    Operation HTTP CPU Wall time Peak memory
    Cancel, 12:10:03–12:10:44 UTC 200 27.500472 s 40.710720 s 126 MiB
    Terminate, 12:22:40–12:23:20 UTC 200 27.787926 s 40.692728 s 124 MiB

    Both runs have exactly 2,000 TimerCancelled, 2,000 ActivityCancelled, and one matching workflow terminal event. Canonical history and timeline each contain 8,166 events, all projection diagnostics agree, and open task/wait counts are zero. Repeating the close returns 409 run_not_active without changing the complete inventory or the SHA-256 digest of all canonical raw rows. A real outstanding activity completion is fenced with 409 run_cancelled / run_terminated, recorded=false, before its original five-minute lease expiry.

    Each maintenance process completed exactly 12 iterations and exited successfully; all report failure arrays are empty, one existing task was repaired, and final candidates are zero. Each log also contains two caught SQLite heartbeat-prune database is locked errors, matching the separately recorded source behavior. The logs are not exception-free. Projection inspection used a separate 512 MiB diagnostic process; endpoint memory stayed at 128 MiB.

    The cancellation observer initially missed metrics because it compared a path against unparsed JSON with escaped slashes. Parsing the original logged JSON recovered those metrics without replaying cancellation. Termination used a fresh run after that observer correction. This checks raw HTTP behavior, not SDK consumer paths or arm64 execution. Keep #958 open through the normal image gates and affected installed-consumer follow-through.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions