Skip to content

Keep journal retry observations buffered until terminal failure - #852

Merged
coneilen merged 1 commit into
scgopi:mainfrom
coneilen:coneilen-journal-first-open-budget
Oct 17, 2026
Merged

coneilen merged 1 commit into
scgopi:mainfrom
coneilen:coneilen-journal-first-open-budget

Conversation

@coneilen

@coneilen coneilen commented Oct 16, 2026 •

Copy link
Copy Markdown
Collaborator

Summary

Keep caller preparation and disk-durable retry/success-observation flushing out of the numbered journal reader's 1000ms I/O budget, without relaxing absolute deadlines, retry limits or the legacy manifest budget. Reserve durability for terminal failures and retain actor primary failures alongside unchanged cleanup assertions.

Refs #851.

Changes

  • Start the numbered-reader I/O clock once, at the first Open attempt inside Read-CapJournalObject, not at transaction creation or sequence discovery. Keep 1000ms, seven global retries, eight Open attempts per sequence, hard absolute clipping and no late success; final-manifest transactions retain their creation-started budget.
  • Use OS-buffered Flush() for successes and retryable/transient observations. DeadlineExhausted and CopyFailed intrinsically end the read; Open/manifest callsites explicitly request durable Flush(true) only for non-retryable HRESULTs or exhausted retry/attempt caps. A failure label alone is not terminality. Success/unknown decisions remain buffered even if supplied an erroneous terminal switch. Existing success-write counts and ordering are unchanged.
  • Add observationTransactionId and attempted observationOrdinal. previousObservationWriteMs and previousObservationOrdinal refer to the previous COMPLETED serialization/Open/Write/selected Flush/Dispose in the same transaction/run; both are null on the first record. Failed attempts reserve ordinals without advancing the completed pair, so gaps are intentional. No record claims its own completed latency, invents zero latency, or requires an extra success write/rewrite.
  • Retain failure-only preOpenMs/first-Open state and narrow seven-day CI failure uploads from the actual producer temporary directory. Workflow bytes are unchanged in R2. No supervisor, worker, process-identity, selector or product changes.
  • Preserve the historical 69 ordinary / 72 real-seed inventory, add R1's two first-Open groups and R2's one observation group: current full expectations are 72 ordinary / 75 real-seed cases. Keep existing assertions and thresholds. Both new 1500ms preparation seams and the new 60ms Flush/Dispose measurement seams use elapsed-stopwatch loops with post-loop caps, rather than assuming requested sleep duration equals measured duration.
  • Extend the existing observation contract with two injected sharing errors followed by actual file I/O. On actor-cleanup failure only, append owned Reader/Writer primary files with bounded reads of 16KiB plus a truncation probe, explicit missing/read-error/truncation diagnostics, and no weakening of exit/kernel/EOF/generation assertions or recovery.

Test plan

RED: pwsh -NoProfile -File Tools\windows\Tests\UiCaptureDriver.Tests.ps1 -JournalObservationContractOnly -ScratchRoot D:\gj53f\red -> 1 executed, 0 passed, 1 expected behavioral failure on unchanged a1df/2EFF production: actual retry reader JournalUnavailable totalMs=1569.734 after first injected sharing error; previous whole observation write 1529.172ms, injected durable delay 1516.9978ms.
GREEN: pwsh -NoProfile -File Tools\windows\Tests\UiCaptureDriver.Tests.ps1 -FixtureContractOnly -JournalTimingContractOnly -JournalFirstOpenContractOnly -JournalObservationContractOnly -ScratchRoot D:\gj53f\green -> 5 executed, 5 passed, 0 failed; retry303.5474ms including all4observations and actual final deadline check, 2injected sharing errors/3Open attempts/2retries/4buffered/0durable; expected injected deadline-observer stderr retained.
REGRESSION: pwsh -NoProfile -File D:\gcs\j52r3\Invoke-852TerminalObservationGreen.ps1 -RunRoot D:\gj53 -ExpectedControllerSha256 DEA8CA07E5FDC49359187467A56EB1AFC43EA4AD8E6BDF14B4B9211AB28E51CC -RuntimeDeadlineUtc '2026-10-17T01:25:25.0381513+00:00' -OuterDeadlineUtc '2026-10-17T02:01:15.0070326Z' -> ONE contained run, 75 executed, 75 passed, 0 failed, 75 unique cases; controller PASS and exit 0; all prior75 retained.

The R3 RED extends the actual reader/file-I/O seam with a transparent FileStream subclass. The loaded observation writer and numbered reader each substitute ONLY their uniquely matched static Open constructor; all other reader/writer/budget code remains real. Both exact original functions restore in nested finally blocks before either restore assertion. This is not byte-identical execution of those constructors, a missing-API/compile proxy, production injection configuration, or proof of kernel sharing violations. The seam compiles C# in-process, not a native target fixture. A separate probe executes two typed injected HRESULT80070020 errors and a real nonempty third Open, then resets counters before the timed path. On old policy, the timed path stops after the FIRST slow durable retry observation, so it does not falsely claim two timed RED retries. Revised GREEN executes both injected errors and the real third Open, all four buffered observations and actual caller-equivalent final deadline check inside the under-1000ms timing window.

R3 focused GREEN also covers the original four-subcase timing contract, prebuilt binder, caller preparation, absolute pre-Open refusal/clipping, once-only clock/counters, legacy manifest timing and deadline-observer primary-error preservation. The observation group retains the unchanged two-success-record assertions, first-record nulls, same GUID/ordinal binding, full Flush/Dispose measurement and failed ordinal gap. Terminal fixtures cover the actual reader retry cap, manifest retry cap, injected AccessDenied, CopyFailed/DeadlineExhausted and transient manifest buffering. Rendered harness assertion tests retain known Reader/Writer primary text alongside the original cleanup failure, with missing/read-error/truncation coverage. Existing production observer masking risks remain separate; this harness change does not fix or establish all production primary-error preservation.

The full run prepared both C fixtures BEFORE the added suite job, consumed/rehashed all 14 artifacts, and retained every original 74 case including the original 59. Three real-zmx cases each executed two phases. Job counts were 0 before teardown, 0 at finally and 0 after teardown, queried BEFORE handle close; actual stdout/stderr EOF was proved, with no owned vctip. The 33 release statuses are exactly 2 CLEANUP_UNPROVEN, 4 FAILED_ZERO_SURVIVORS, 21 REFUSED_NO_WORKER and 6 RELEASED_ZERO_SURVIVORS; the two negative UNPROVEN records are not clean evidence. There are 10 full clean proofs. Root's independent retained-file proof verifies 96 numbered envelopes/payloads/predecessors and canonical-LAST-stdout binding, six real-ready phases, 14 fixtures and eight source pins.

The R3 run retained all prior 75 case names exactly, including the original 59, and the full retry contract measured291.0686ms. Operator-disclosed deletion of 30 external non-git D: residual directories (~6.9GB) around01:04-01:07Z overlapped release/preparation/suite start. An earlier coordinator assertion of no archive-I/O overlap was incorrect. The operator explicitly accepted a PASS normally; this PASS had no replacement/repeat. No zero-load or deletion-causation claim is made.

Retained R1 evidence and hosted failures

R1 remains historical, not rewritten into R2 evidence. Its RED command pwsh -NoProfile -File Tools\windows\Tests\UiCaptureDriver.Tests.ps1 -JournalFirstOpenContractOnly -JournalTimingContractOnly -ScratchRoot D:\gj5f\red produced 3 executed / 1 passed / 2 expected behavioral failures on unchanged 584A core. Caller delay failed at the actual caller-equivalent pre-read Assert-CapJournalTime (totalMs=1514.926), not at an observed throw inside Read-CapJournalObject; absolute refusal lacked preOpenMs. R1 focused GREEN2 at D:\gj5f\green2 produced 3/3/0. Its exact full command and retained 74/74/0 evidence remain in canonical R1 body SHA D8E779304121F073A7425538414A4D0F941FE75EE92CB0AA56427DE1FC3950AB, report 7EE3FBCB11CCF78420ED4FF1697ED81C39D83720084F3F3F448351CD0B308E7F, and controller result C7B537D75A5FC3F229A16D27FD72467344BD9D417439854F43A0795A000107A4.

Both R1 Windows 2022 and Windows 2025 hosted hardening jobs on exact head 408bacfc6a002b64c6a9046031a79acdd78f0e50 FAILED. The first-Open fix plus local 74-case pass was not sufficient hosted acceptance. The failure-upload branch positively executed and retained nonempty suite artifacts on BOTH failed hardening jobs; this supersedes R1's publication-time statement that runtime upload had not yet run. It does not establish every producer/failure branch or universal privacy.

Win22's absolute-preparation case measured 1490.8409ms BEFORE observation writing, independently disproving flush cost as an explanation of that particular assertion failure. The first group's aggregate failed conjunct was not recorded because the stopped delay value was missing; its ReadVerified observation alone cannot identify the failed conjunct. R2 retains measured delay even on assertion failure. Individual hosted Flush durations, tick causation, JIT, AMSI and Defender attribution remain UNPROVEN; the deterministic injected-flush RED establishes the changed behavior, not a retrospective hosted-cause measurement.

Three earlier retained CI logs contain four primary timing occurrences from #845 and parked #850. Historical source and observed non-null Open/Copy counters classify these as numbered-reader transactions, not legacy final-manifest transactions. There is no complete call stack/exact call ordinal or proven common cause. #846, #849 and #851 are related capture-core failures, not a claim of harmless flakes. #850 selector work remains absent and parked.

Source review and mechanical provenance

  • R3 follow-up to R2 reviewer 4d53c01c-4a22-453f-bfc9-6d52cf9e6ba1 was attempted but NOT delivered (NO_AGENT_FOUND). The R3 grant expressly allowed one bounded lost-context replacement. NEW background Sonnet5.5 HIGH reviewer bf348dca-caf2-4cb1-b486-24b92754f146 accepted only the frozen R3 delta, full response SHA 65F82F636CA2C837634138B5658C9D685115FDF05D92642B796FD56250ABAE51. This is not the same reviewer or a fresh whole-core review. Limits remain: aggregate terminal fixture counters are not branch-independent proof; manifest attempt8 terminality is source-reviewed only; injected HRESULTs are not kernel-sharing evidence.

  • R1 original synchronous Sonnet 5.5 HIGH reviewer eea1447b-70ff-41cf-9e36-34a7afd5df0b returned NOT ACCEPTED on the wrong CI temporary root while accepting reviewed core boundaries. Its follow-up was attempted but not delivered because synchronous agents cannot receive write_agent. Authorized background replacement 27bdc265-dfea-4388-8ee8-b40a74cecadb accepted the frozen R1 corrections only, not a fresh whole-core review.

  • R2 follow-up to 27bdc265 was attempted but NOT delivered: NO_AGENT_FOUND. The operator authorized a new background replacement, Sonnet 5.5 HIGH 4d53c01c-4a22-453f-bfc9-6d52cf9e6ba1, for frozen R2 delta only. Its initial verdict was NOT ACCEPTED because two raw 60ms sleeps did not guarantee the unchanged 120ms measured assertion (full response SHA 77B32C36F3CEFB795D5C5900C716AC5339FB50C8661C54338C937B90DF07283E).

  • After explicit authorization, ONLY those two measurement seams changed to stopwatch-bounded loops with typed post-loop caps. The SAME live background reviewer accepted that narrow correction, full response SHA 3152636C0202AC68D4534E3477F837CD484CDF814BCE95B35D55E2D792A54DD9. This closes its sole R2 finding, not a new whole-project/core review or hosted acceptance. All prior refusals and beforeimages remain retained.

  • R1's private precommit CRLF guard failure happened before staging/commit and was corrected only under explicit formatting authority. R2's post-run broad artifact-listing tool timed out; its partial output is preserved as UNUSED, not inventory evidence or a native failure. No runtime rerun followed. R2 publication is an explicitly authorized single amend of existing R1 commit, not an extra commit; source/controller EOLs are untouched.

Acceptance limits and sealed evidence

R2 LOCAL evidence remains distinct: its RED at D:\gj52f\red on unchanged C225 produced1/0/1, actual JU1850.755ms/injected durable1504.588ms; focused GREEN2 at D:\gj52f\green2 produced5/5/0; one full D:\gj52 run produced75/75/0. The exact commands, failed/passing logs and original full body are retained, canonical R2 body SHA A85B07E27B15B5270C4A0881969E20577E65373BC0112C5B2E3D60CF59A232D9. This local PASS did not establish hosted acceptance.

On R2 head a1df96689f02c1b7aae19000172e161fed890d4b, actual Windows2022 passed72/72, while Windows2025 executed72/passed70/failed2. The actor-cleanup wrapper hid a REAL Reader JournalUnavailable, not an independent harmless cleanup failure. Artifact12082798789 (ui-capture-hardening-windows-2025-pwsh-1), classification proof and #846 comment6227558365 bind sequence1/HRESULT80070020/retries2/total1586.517ms. Reader-failed.json contains the primary; Writer-failed.json propagates it; cleanup has two wrapper failures and zero receipts. previousObservationWriteMs327.6588 and837.3747 measure WHOLE serialization/Open/Write/selected Flush/Dispose, NOT isolated Flush durations. R3 fixes the demonstrated policy error of durable transient observations; older #846 causation and individual hosted Flush/JIT/AMSI/tick attribution are not established. There was NO diagnostic rerun request or API.

Still required: BOTH Windows 2022 AND Windows 2025 hardening GREEN on the actual R3 amended PR head with no REAL JournalUnavailable. ANY #846-shaped failure after R3 must STOP and be classified, not retried into green or addressed by widening the unchanged budget. No public PR-body edit, Ready transition or merge is performed by this owner; this canonical body is for operator verification/update of existing #852.

No GUI capture, visual parity, native keyboard/accessibility, product build or shipping-macOS safety claim follows. macOS make test and make check were NOT RUN on this Windows host.

Historical R2 full packet SHA C020567036BBE899E73E41876E451669B004AB48B46A7F634693F63777AFE33C; report E9A645F101AFDF92E1B353803B2DB553CDEF210A00457316331B416FDCD481B5; result 150CAB126A79225FBB95790D9A37688D100233AB4EACB2ED32730D888BE75D53; configuration 46C5577802A6073091BFBE454F60E94A3EB5F59F84A122B89C8AFE14FE14E731.

R3 full packet SHA A3A467E7204B9B59F5D59ABD97CCD441D51D5E756B70D6DC428A3A3DC76C5717; report BA0E1D7BAC235EF62F0E1AD70C16E51430758F1268D095467618805FA2DCF995; result B3410EEBFE023B4B79B48549DDE1A5D2311DAFB7B0D25F8C2A1B7888B52E1E68; actual configuration 928E4601B917C074AD847FC3AA5AC0FFA8F7861001482D80D205E5038CC5B2CD; independent root proof AEABEA73AA5619AED82F7FA246E17D7FE3003A8C7FEA8A9BEEB329164D829727. Controller proof runRootExists=false/runtimeDeadlineUtc=null fields are PRELAUNCH snapshots only; actual completed result/configuration bind the literal deadlines. Credits and remaining lifetime call telemetry remain UNKNOWN.

Checklist

  • I have read the Contributing Guidelines
  • I have signed off my commits (git commit -s) per the DCO
  • Tests pass locally (make test)
  • Code follows the existing style (make check)
  • I added the test/contract before the implementation and observed the intended RED failure

@coneilen
coneilen force-pushed the coneilen-journal-first-open-budget branch from 408bacf to a1df966 Compare October 17, 2026 00:31
@coneilen coneilen changed the title Start journal I/O budgets at the first Open attempt Keep journal preparation and durable observation flushes out of read budgets Oct 17, 2026
Start numbered-reader I/O timing at first Open and retain hard absolute
deadlines and the legacy manifest budget. Buffer retryable and successful
observations; reserve durable flushing for terminal read failures.
Retain completed-write diagnostics and CI artifacts, and surface actor
primary errors alongside unchanged cleanup assertions in the test harness.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot-Session: 13b34e6e-54e6-40c7-84ca-1aa28ec53c76
Signed-off-by: Colin Neilens <coneilen@microsoft.com>
@coneilen
coneilen force-pushed the coneilen-journal-first-open-budget branch from a1df966 to bd6bb43 Compare October 17, 2026 01:21
@coneilen coneilen changed the title Keep journal preparation and durable observation flushes out of read budgets Keep journal retry observations buffered until terminal failure Oct 17, 2026
@coneilen
coneilen marked this pull request as ready for review October 17, 2026 01:55
@coneilen
coneilen merged commit 77ec221 into scgopi:main Oct 17, 2026
26 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant