Add the Bloom Freeze Doctor (BL-16719) - #8229
Conversation
Users tell us Bloom froze, and we get almost nothing to work with. Their problem report is written AFTER they killed Bloom, so it describes a healthy new process, and the log only holds what Bloom managed to write before it stopped responding. Three quite different failures arrive looking identical - the UI stops responding; Bloom exits without reporting anything; or Bloom's window is gone while the process lives on, so the user cannot start Bloom again - and none of them leaves usable evidence. BL-16697 is the live example. Nobody is watching at the moment it happens, and the worst case cannot be watched from outside at all. THE MEASUREMENT THE WHOLE DESIGN RESTS ON: a WinForms UI thread blocked in a managed wait on an STA thread still dispatches SENT messages, so the window answers probes, IsHungAppWindow reports it healthy and Process.Responding returns true while Bloom is completely stuck. Measured on a real Bloom: nine minutes frozen, reported responsive throughout. Since Bloom's UI thread awaits WebView2 constantly, that is likely the COMMON shape of freeze rather than an exotic one. WM_TIMER is not dispatched, which is why detection rests on a UI-thread timer heartbeat published through shared memory, and not on either API that looks built for the job. So this adds a companion Windows app that is already running when the trouble starts, gathers what can only be gathered at that instant, and files a YouTrack card by itself. WHAT BLOOM DOES - Publishes a health heartbeat through a shared-memory page a watcher can read without Bloom's cooperation: a UI-thread beat, whose silence is the freeze signal outside observation cannot see; a separate background beat, so "the UI thread is blocked" can be told from "the whole process is wedged"; what Bloom thinks it is doing; and how far shutdown has got. - Proves its clean exits, from one ProcessExit handler. That runs for a normal return from Main and for Environment.Exit, and NOT for FailFast, TerminateProcess or an access violation - exactly the line worth drawing, and one no future exit path can forget to honour. - Records a session file with the facts a watcher cannot work out from outside, above all WHICH LOG FILE this run is writing to: Bloom recreates Log.txt each run and falls back to a random name when another Bloom holds it, so guessing from the filesystem picks the wrong file in exactly the restart-after-a-freeze case. - Tracks in-flight API requests, so a report can say which request has been running for 47 seconds rather than only that a thread is waiting. - Honours a request to exit when its UI is gone and it holds the single-instance token, and asks for a dump as it crashes - checking with a zero timeout whether anyone is listening, so users without the Doctor never wait. - Detects a debugger, polled once a second and remembered: a debugger attached to a running Bloom and then detached leaves exactly the evidence of a freeze, and terminating from one is a TerminateProcess, so it looks like an unreported crash. Both managed and native debuggers are seen. - A freeze simulator for developer and Alpha builds, inert unless BLOOM_SIMULATE_FREEZE is set AND the channel is one we may deliberately break. Alpha is included on purpose: reproducing a freeze means working with somebody who is having one, and those people run Alpha, not a build from source. WHAT THE DOCTOR DOES Watches for the three failure states, gathers evidence while the process still exists (wait chains, managed stacks, WebView2 processes, Event Log, WER, the right log tail), classifies exits, queues reports on disk because a freeze often arrives with a dead network, and files them to YouTrack. It will not touch a FROZEN Bloom: a frozen Bloom may hold edits that live in the WebView2 DOM and have not reached C#, so killing it would throw away the user's work. A zombie has no UI at all, so there is nothing left to save - which is what makes ending that one safe, and a complete cure, since the next Bloom takes the single-instance lock as soon as the process is gone. HOW IT SHIPS, AND HOW IT IS SWITCHED ON In this repository, as four projects in Bloom.sln, built into Bloom's own output directory beside Bloom.exe, signed by Bloom's build alongside Bloom.exe and BloomPdfMaker.exe, and swept into Bloom's installer by the existing wildcard. It began as a separate repository with its own installer; both turned out to be unconsidered defaults. The Doctor has no use independent of Bloom, and the two programs share a wire format, which a separate repository can only handle by copying files or by publishing a package. Whether it RUNS is a setting, off by default, toggled by "Run Freeze Doctor" in the right-click debug menu on the collections tab. Switching it on starts it immediately rather than at the next restart, because somebody turning it on is usually chasing a freeze now. Switching it off deliberately leaves a running Doctor alone: it is watching this Bloom and may hold a gathered but unfiled report. Not installing it was the old way not to pay for it; a setting is better, because it needs no download and can be turned on during a support conversation. That also removed a Velopack dependency, a vpk pack step, a second signing pass, a rolling release, and an argument about upstream Velopack versus Bloom's fork - which cannot both exist here anyway, since they install the same global command. NO UI UNTIL IT HAS SOMETHING TO SAY. Starting minimised was not enough: a minimised window still exists, still briefly owns a taskbar entry, and can flash on screen. Application.Run(form) shows its form unconditionally, so SetVisibleCore is overridden - the one place WinForms routes every path to visibility through. Until the Doctor files something it is a tray icon and nothing else. The tray icon stays, as the only way to notice it is running, quit it, or hold CTRL to report on a Bloom that is merely slow. THE SHARED WIRE FORMAT One project, BloomBooks.FreezeDoctor.Protocol, referenced by both sides, so there is one definition rather than two. It was briefly two hand-maintained copies and they drifted within two days; it was then briefly a NuGet package, which worked but cost a publish-then-unlist flow, an API key, and a version to keep in step across repositories. The format is built to grow. SchemaVersion is the compatibility generation and is part of the section's NAME, so bumping it makes an old Doctor stop finding the channel rather than misreading it. Additive change is what PayloadBytes is for: the writer records how far it wrote, so a NEWER Doctor reading an OLDER Bloom can tell a field that Bloom never wrote from a real zero - the page is zero-filled, so without it a report would confidently say "0 blocked workers" where the truth is "this Bloom is too old to say". That direction is the common one in the field, since the Doctor is updated with Bloom while Bloom versions linger. Tests pin all of it by value - every offset, that PayloadBytes really is the end of the last field, that no two fields overlap, that the writer never touches a byte beyond the extent, and that a reader accepts a writer which recorded less than it knows about. Before those existed, someone could have reordered two fields, left SchemaVersion alone, and watched both suites stay green while every report quietly became wrong. TESTS 3185 passing in BloomTests, 110 in BloomFreezeDoctor.Tests. KNOWN FOLLOW-UP The Doctor's remaining 44 plain File/Directory call sites are not yet converted to libpalaso's robust wrappers, so build/check-csharp-robustfile.sh exempts its tree for now; the exemption should go away with them. The one that mattered is already done: the outbox's staging-to-final rename, which IS the publish step for a gathered report, was failing about one run in three with "access is denied" and losing the report. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
|
| Filename | Overview |
|---|---|
| src/BloomFreezeDoctor.Core/Outbox/ReportOutbox.cs | Implements persistent report queuing and cross-process drain serialization; the latest lock-timeout fix now exits without entering the drain when another process holds the gate. |
| src/BloomFreezeDoctor/DoctorSupervisor.cs | Coordinates process discovery, evidence gathering, report-now requests, queued submission, and watcher lifecycle without a remaining blocking issue from the reviewed threads. |
| src/BloomFreezeDoctor.Core/FreezeDetector.cs | Implements heartbeat-based freeze, crash, and windowless-process classification with slow-activity and debugger handling. |
| src/BloomFreezeDoctor.Protocol/DoctorChannel.cs | Defines the shared-memory health protocol and compatibility behavior used between Bloom and the Doctor. |
| src/BloomExe/FreezeDoctor/FreezeDoctorSupport.cs | Publishes Bloom health, activity, debugger, shutdown, logging, and diagnostic-signal state to the companion process. |
| src/BloomFreezeDoctor.Core/Outbox/YouTrackSubmitter.cs | Submits queued diagnostic reports and attachments to YouTrack while supporting fingerprint-based report consolidation. |
| src/BloomFreezeDoctor.Tests/ReportOutboxTests.cs | Covers outbox persistence, submission limits, retention, and refusal of a second drain while another process owns the lock. |
| build/Bloom.proj | Builds, signs, and packages the Freeze Doctor alongside Bloom. |
Reviews (15): Last reviewed commit: "Stop the comments pointing at the abando..." | Re-trigger Greptile
Both found by reviewing the single-installer change, and both of the same kind: they fail without anything going red. BLOOM'S BUILD NEVER BUILT THE DOCTOR build/Bloom.proj's BuildInternal builds project by project - BloomExe and WebView2PdfMaker, named individually - rather than building the solution, because solution builds do not support the runtime parameter. So being a member of Bloom.sln does nothing for the official build: BloomFreezeDoctor.exe would never have been produced, never signed, and never included in the installer. And it would have failed quietly. The signing step has ContinueOnError, so signing a file that is not there does not stop the build, and the installer step gathers `output\release\x64\**\*.*` by wildcard, which cannot complain about a file that was never built. The first sign of trouble would have been a user turning the Doctor on and nothing happening. THE DOCTOR WOULD HAVE EXITED MILLISECONDS AFTER STARTING The new "no UI until it has something to say" behaviour refuses to become visible by overriding SetVisibleCore. But Application.Run(form) makes its form visible, and a form that refuses never gets a window handle - so the message loop would have had no window, exited at once, and taken the Doctor with it, tray icon and all, every time Bloom launched it. Nothing unit-tests a message loop, so no test would have caught it. So the first call now forces the handle into existence before declining to show the window. The first version of that fix was wrong in the other direction: it suppressed the window unconditionally on the first call, which would have left a Doctor launched BY A PERSON with no window at all, when they had gone looking for it deliberately. Only the hidden-start case refuses now. Verified BloomFreezeDoctor.exe is produced by a build of the shape Bloom.proj performs. Worth recording how that check first went wrong, since it is a trap in this repo: run in the same shell as build/agent-dotnet.ps1, a plain dotnet build inherits BLOOM_AGENT_BUILD_DIR, which turns off apphost generation for everything except WebView2PdfMaker - so the exe appeared to be missing when it was not. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Both found by Devin on PR #8229, and both verified against the code before changing anything. THE 6.3 WEBVIEW2 FALLBACK COULD NEVER FIRE FindCdpPort ended with return children.Count == 0 ? null : (int?)null; Both arms are null, so the documented fallback to the port 6.3 hardcodes was dead code. A Bloom 6.3 with no session file therefore got no CdpPort, and its WebView2 section was dropped from the report with nothing to say why. The guard around it was right and is kept: WebView2 children that advertise no port mean this is NOT the 6.3 arrangement, and guessing 9222 would interrogate some other program's browser and put the answers on a Bloom card. It is the no-children case that looks like 6.3, and that now returns WebView2Processes.LegacyHardcodedPort as the comment always said it did. FOUR DEDUP SETS MUTATED FROM SEVERAL THREADS AT ONCE _dumpsRequested, _exitsExamined, _zombiesReported and _zombiesEnded are shared across watchers, but every watcher raises Observed on ITS OWN timer thread, so with two Blooms being watched - routine on a developer's machine - they were touched concurrently with no lock. An unsynchronised HashSet can corrupt itself or throw, and worst of all can silently lose an entry, which is what these sets exist to prevent: a second dump of a crashing Bloom while it holds its own death open for us, or a second report of one exit. Telling detail: one of the five call sites, the _zombiesReported.Add after a zombie report is queued, ALREADY held _lock. So locking these was the intention and the other sites were simply missed. Each test-and-claim is now inside _lock, and only the test-and-claim - never the work that follows, which includes gathering and killing processes. The zombie pair is under a single lock together, because "the evidence is gathered AND nobody else has taken the one attempt" is one decision; splitting it would let two threads both conclude they were the one to end the process. DumpRequested() was pulled out of its short-circuit so it is not called while holding the lock. 110 tests pass. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Found by Greptile on PR #8229, and correct. Three separate things ask for a drain - startup, the five-minute timer, and the end of a gather - and all three were fire-and-forget tasks, so two could overlap. Both would then list the SAME pending bundles and both walk the search-then-create flow against YouTrack, which is not atomic. The results are duplicate cards, or duplicate comments on one card, and a combined total that can exceed the deliberate three-per-day cap. That cap exists so that a machine in a bad state cannot spam the tracker, so quietly exceeding it is the worst version of this. Neither the supervisor nor ReportOutbox had any mutual exclusion, so a SemaphoreSlim(1,1) now serialises it, and it is disposed with the supervisor. It WAITS rather than skipping. Skipping would be cheaper and is tempting, since a second concurrent drain would usually find nothing left to do - but ReportNowAsync awaits this and then looks for its own bundle in the queue. Had its drain been skipped because another was already running, it could have reported failure for a report that was in fact about to be filed perfectly well. 110 tests pass.
Found by Devin on PR #8229, and it is the exact failure _workInFlight exists to prevent - on the one path that never got the guard. The field's own comment says why it is there: a Bloom would crash, the Doctor would notice the process was gone, conclude there was nothing left to watch, and exit, cancelling the examination of the very crash it had just seen. It is incremented for the report-gathering job and for the exit examination. The crash DUMP job never incremented it, so ConsiderExiting could see zero work in flight and shut the Doctor down mid-dump. This is also the likeliest path for it to happen, not the least: the dump runs because Bloom is in the act of crashing, so the process is about to disappear - which is precisely the event that makes the Doctor look around and find nothing left to watch. And it is the worst one to lose, because Bloom is holding its own death open for about three seconds waiting for us, so the dump either happens now or never. The decrement goes after SignalDumpComplete, so Bloom is released before our bookkeeping rather than after it. 110 tests pass.
Greptile's follow-up to the previous fix, and it is right: a SemaphoreSlim only serializes callers inside one process. The --drain switch is handled BEFORE the singleton mutex - deliberately, so support can drain the queue whether or not a Doctor is running - and it calls ReportOutbox.DrainAsync directly, bypassing the supervisor entirely. So somebody running "BloomFreezeDoctor --drain" while a Doctor is draining gives two PROCESSES working the same queue, each listing the same pending bundles and each walking the non-atomic search-then-create flow. Duplicate cards, or a combined total past the three-a-day cap that exists so a machine in a bad state cannot spam the tracker. So the gate now lives in ReportOutbox.DrainAsync, where the shared resource is. That makes every caller safe regardless of process or entry point, rather than relying on each new caller to remember. A named Semaphore rather than a Mutex, and that is not a style preference: a Mutex has thread affinity and must be released by the thread that took it, which cannot be guaranteed across the awaits in the drain loop. A named semaphore has no affinity. If the gate cannot be created at all we drain ungated rather than not draining: a report that never reaches the tracker is worse than a rare duplicate, and this is the path by which reports actually get sent. The supervisor keeps its own in-process gate, and its comment now says why neither replaces the other. The named one guards against another process and gives up after a short wait, since the bundles belong to whoever holds it. The in-process one waits indefinitely, which is what keeps ReportNowAsync's "drain, then look for my bundle" honest for our own three callers. 110 tests pass, at normal speed - which also confirms the semaphore is being released correctly across the awaits. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Greptile again, on the fix I made an hour ago, and it is right - including about a claim in my own comment that was simply false. I used a named `Local\` semaphore and wrote that this was fine because "the outbox lives under the user's own LOCALAPPDATA, so two Windows sessions have separate queues". They do not. `Local\` names are per LOGON SESSION; LOCALAPPDATA is per USER. So the same user in two sessions - fast user switching, or a second desktop over RDP - shared one queue while holding two different gates, and could drain it twice at once. Which is the very thing the gate was added to prevent. `Global\` would have fixed the scope and broken something else: creating a `Global\` object needs SeCreateGlobalPrivilege, which a standard user does not necessarily have, and the failure path here is "carry on ungated" - so it would have quietly reverted to no gate at all on exactly the machines we care about. So the gate is now an exclusively-opened lock file inside the outbox directory, which scopes it to precisely the thing it protects. Same outbox means the same file and therefore the same gate. A different outbox - another user, or a test with its own root - gets its own gate and no spurious contention, which also means tests no longer serialise against each other through a single machine-wide name. It needs no privileges, and Windows drops the lock when the handle closes, including when a process dies without closing it. Only directories are ever treated as bundles, so a lock file sitting in that directory cannot be mistaken for one. Verified by running the suite three times: 110 pass each time at normal speed, which is what rules out both a stalled acquire and a lock left held between runs. Greptile's other new point - that a 20-second gate timeout makes ReportNowAsync report failure for a report another process is about to file - is real and is NOT fixed here. Fixing it properly changes what DrainAsync returns, so it has gone to the preflight decision report rather than being decided unilaterally at the end of a long run. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Devin, on the commit I pushed twenty minutes ago: the cross-process gate never blocked anything. It was right. When I moved the gate from a named semaphore to a lock file I dropped the check that made it a gate. AcquireDrainGateAsync returns null when somebody else holds the lock, and DrainAsync fell straight through and drained anyway - so the mechanism was a no-op while its comment, its commit message and my reply on the PR all said it worked. The semaphore version had "if (!held) return 0" and the refactor lost it. The cause was conflating two different nulls, so that is now stated where the variable is declared: a null RETURN means somebody else holds the gate and we must not drain, while a THROW means the gating mechanism itself is unavailable and we drain ungated rather than never draining at all. TWO OTHER THINGS FOUND WHILE FIXING IT The acquire loop used the injectable _now clock for its timeout. That clock is deliberately frozen in tests, so the deadline could never be reached and the loop would have spun for ever the first time a test contended for the gate. It uses real elapsed time now, with a comment saying why it must not use _now. The gate wait is injectable, so the test below runs in 200ms instead of twenty seconds. AND A TEST, BECAUSE A COMMENT IS CLEARLY NOT ENOUGH This gate has now been wrong twice - in-process only, then a no-op - and both times the code claimed otherwise. So there is a test that holds the lock file the way another process would, and requires the drain to file nothing, to not even ATTEMPT a submission (attempting is what duplicates a card), and to leave the bundle pending for whoever holds the gate. It also checks the other direction, that the same outbox does drain once the gate is free, so it cannot pass by DrainAsync being broken outright. Verified by mutation: disabling the guard fails the test with the message it should, and the mutation was reverted. 111 tests pass. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Devin: Process.GetProcessesByName hands back Process objects that each hold an OS handle. Discover used only their Id and never disposed them, and it runs every five seconds for as long as the Doctor lives - which can be hours - so handles accumulated until finalization got round to them. Worth fixing rather than shrugging at, because of which process it is: the Doctor has to stay healthy enough to diagnose everything else, so it is the last program that should be quietly leaking handles while it waits. It now takes the ids and releases the Process objects immediately, and the exited-watcher check uses those ids rather than holding the array of live objects across the lock. 111 tests pass.
Decisions 7 and 9 from the preflight report. REPORT-NOW NO LONGER IMPLIES FAILURE (decision 7) DrainAsync returned a bare count, so 'nothing filed' and 'another process is already filing it' were the same answer: zero. ReportNowAsync drained, found no issue id, and returned null - and the window then said nothing at all, leaving 'Gathering a report on request...' on screen, which reads as a failure and invites the user to press the button again. The report was on disk the whole time. So the drain now returns a DrainOutcome saying whether it was gated out, and ReportNowAsync returns a ReportNowResult distinguishing filed, queued, and could not gather. The window says 'Report saved. It will be sent when the Freeze Doctor can reach the tracker.' Worth noting the bug was wider than the case Greptile raised. It reported the gated-out path, but the same wrong silence applied to being offline or over the daily cap - both perfectly normal, both previously indistinguishable from failure. The gated-out flag is RETURNED rather than stashed in a field, because several gathers can be in flight at once, one per watched Bloom, and a field would be read by the wrong caller. --drain says which happened too, so support does not read 'filed 0' and conclude something is broken when a Doctor is quietly doing the work. A TRACKER HICCUP NO LONGER DISCARDS A REPORT (decision 9) FindProjectIdAsync collapsed every non-success status to null, and the caller turned null into RejectedPermanently - so one 5xx or gateway timeout on the project-id lookup marked a gathered report failed for good and stopped all retries, defeating the one thing the outbox exists for. It now returns the failure to report rather than just null, classified by the same ClassifyFailure its neighbours use. That needed no new policy: 404 already maps to permanent, which is right for a project that genuinely does not exist, while 429 and 5xx map to retry. 111 tests pass.
…ption (BL-16719) Decision 3 from the preflight report: convert them all now, and fix the exemption rather than keep it. All 34 flagged call sites converted - File.Exists/ReadAllText/WriteAllText/ Copy/Move/Delete/AppendAllText to RobustFile, and Directory.Delete to RobustIO.DeleteDirectoryAndContents - and the Doctor's production tree is no longer exempt from build/check-csharp-robustfile.sh. Verified by running that gate for real with everything staged: it passes on its own merits. The tempting argument for exempting the Doctor was that its writes are only diagnostics, so a transient failure costs nothing much. That is wrong, and the outbox is the proof: the rename that publishes a gathered report into the queue was failing about one run in three with "access is denied", because Windows had not finished with files written milliseconds earlier, and each failure discarded a report at the exact moment a user had just sat through a freeze. A tool whose whole purpose is capturing evidence that is otherwise lost has LESS room to be careless with the disk than Bloom does, not more. That reasoning is now a comment on ReportOutbox, per the decision. WHAT THE EXEMPTION LIST KEEPS Only src/BloomFreezeDoctor.Tests, matching the existing src/BloomTests carve-out for the same reason. Production code has no exemption at all. THREE DOCUMENTED FileStream SITES These use the `robustfile-hook: allow FileStream` opt-out, which exists for exactly this: cases where the sharing flags ARE the requirement rather than an accident. Two read a log that the process being diagnosed still holds open and may delete underneath us (FileShare.ReadWrite | FileShare.Delete); the third is the drain gate, where FileShare.None IS the lock and a wrapper that retried past a sharing violation would defeat it rather than harden it. Each says so at the call. FOUR THINGS THE CONVERSION TURNED UP - RobustFile.Move has no overwrite overload. The two places that wrote a temp file and moved it over the target now use Replace when the target exists and Move when it does not. Replace is the better primitive anyway: it swaps the file in one step, where an unlink-then-rename leaves a window in which the file is simply absent. - RobustFile.AppendAllText has no encoding overload. Dropping the explicit UTF8 changes nothing that matters - .NET's default for these APIs is UTF-8 without a BOM, which is what was being asked for - and is marginally better, since appending with an explicit UTF8 encoding can write a BOM into the middle of an existing file. - RobustFile has no ReadAllBytesAsync, so the attachment read is synchronous now. It is a bounded read of a file we just wrote, on a background thread. - The gate is narrower than it looks: it bans File.*, Directory.Move/Delete and new FileStream, but NOT Directory.CreateDirectory or Directory.Exists, which is why those remain. THE PROTOCOL PROJECT NOW HAS A DEPENDENCY BloomBooks.FreezeDoctor.Protocol had none, and that was a genuine selling point while it was a published NuGet package. It is a plain project reference now and BloomExe already restores this exact version of SIL.Core.Desktop, so the cost is gone - and DoctorSession writes a file on a user's disk, so it belongs under the same rule as everything else. 111 tests pass, three runs. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Decision 8. Wait-chain reports were stating thread and process ids that were pure garbage. WAITCHAIN_NODE_INFO's second half is a UNION. The thread branch - ProcessId, ThreadId, WaitTime, ContextSwitches - starts at offset 8, overlapping the object name rather than following it. Our struct declared those four fields AFTER a 256-byte name, an 8-byte timeout and a BOOL, so Windows wrote them at offset 8 and we read them from around 276. The managed struct was also bigger than the native one, so the array stride was wrong too and every node after the first was misaligned as well. Nothing failed. The report simply carried numbers that meant nothing, which is the exact failure this tool exists to avoid, appearing inside the tool itself. Wait chains are among the more useful things a freeze report carries, so quietly wrong ones are worse than none at all. Only the thread branch is declared now, because only it is ever read - the lock branch's ObjectName is not used anywhere in the collector. So the union is expressed as its four DWORDs at offset 8 followed by an empty struct with an explicit Size of 256, which pads the whole thing to the native 280 bytes. That keeps it blittable, so a call made once per thread needs no marshalling, and it avoids the awkwardness of overlapping a marshalled string with integers, which explicit layout does not permit. AND A TEST, BECAUSE NOTHING COULD HAVE CAUGHT THIS WaitChainCollector now exposes the size and the two offsets that are actually read, and a test pins them at 280, 8 and 12. That needs no frozen process, which matters: the only other way to notice this was to read a report and recognise that a thread id was implausible. The size assertion is not redundant with the offsets - it is what catches a wrong stride, which was half of the original bug. Verified by mutation: restoring the old field order fails the test with "ProcessId is the first DWORD of the union", and the mutation was reverted. Note the size arithmetic is derived rather than measured against Windows: 256 for the name, 8 for the timeout at the next 8-boundary, 4 for the BOOL, padded to 272 by the timeout's alignment, plus the two leading enums. The runtime agreeing at 280 is corroboration, not proof, so end-to-end confirmation still wants a real frozen process - which is on the manual test list. 112 tests pass. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Decision 6, and the end of a long-standing gap: the Doctor could always wait five minutes instead of one when Bloom said it was deliberately busy, but nothing ever said so, so the flag was permanently false and every freeze was judged at one minute. MARKED, per the decision: making a BloomPUB, staging an ePUB, building an app with Reading App Builder, encoding a video, and uploading to or downloading from Bloom Library. MARKED AT THE WORKERS, NOT THE PUBLISH SCREENS. Every route to a BloomPUB goes through BloomPubMaker.CreateBloomPub, including the bulk publisher and app building - which are exactly the cases that run longest, and the ones a screen-level mark would have missed. A SCOPE, NOT PAIRED CALLS FreezeDoctorSupport.LongOperation(what) returns something to `use`. Paired Set(true)/Set(false) calls would be a poor bargain here: a call skipped by an early return or an exception leaves the Doctor permanently patient, which is freeze detection silently switched off for the rest of the session - the worst possible failure for this particular flag, and invisible. It also sets the activity line, so a card says "making a BloomPUB" rather than whichever API request happened to be in flight. NESTING IS REAL, SO THE COUNT IS TOO Building an app makes BloomPUBs on the way, so these scopes genuinely sit inside one another. The depth is counted: the inner one finishing does not take away the outer one's patience, and only the outermost clears the flag. A double Dispose is ignored rather than counted twice, because an unguarded decrement would drive the count negative and then the NEXT operation's exit would fail to clear the flag. Three tests pin that arithmetic - nesting, throwing, and double Dispose - because it is the part that fails silently. The flag actually reaching the shared page is a single line and is already covered by the protocol round-trip test. Video recording is deliberately NOT marked, only the encode afterwards: recording runs with a live window pumping messages, so the UI heartbeat keeps ticking and no freeze is detected anyway. The encode is CPU-bound and is the part that could be mistaken for one. WHAT IS NOT DONE John's further idea - that an operation should not be reported while DEFINITE PROGRESS is being made, files transmitted or pages processed - is not attempted here, and deliberately so: it needs a different signal, a progress heartbeat Bloom pokes as it goes, rather than a boolean. The natural shape is a second timestamp in the shared page that the Doctor treats much as it treats the UI heartbeat. Worth doing once field testing shows whether five minutes is enough. Full suite: 3188 passed, 13 skipped. Doctor: 112 passed. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The `BloomBooks.` prefix existed for exactly one reason: to namespace a public
NuGet package id. When the Doctor moved into this repository the package went
away, and the prefix stopped naming anything.
It was not merely redundant, it was costing something every day.
`BloomBooks.FreezeDoctor.Protocol` sorted ahead of `BloomBrowserUI` in `src`,
so `src/b` plus tab completion no longer landed on the front end - which is
where it lands dozens of times a day, and which cost an hour today chasing
"pnpm build and dev are both failing" that was really "wrong directory".
Dropping it also groups the project with its three siblings:
BloomFreezeDoctor
BloomFreezeDoctor.Core
BloomFreezeDoctor.Protocol
BloomFreezeDoctor.Tests
Mechanical throughout: folder, project file, assembly name, root namespace,
every `using`, the solution entry. No behaviour is touched, and the wire format
is untouched - the schema version is embedded in the shared-memory section name,
not in the assembly name, so nothing about compatibility depends on this.
The csproj comment that flagged the name as a loose end now records the decision
instead, and the README no longer describes itself as an unlisted package or
points at the abandoned separate repository - both were left stale by the move
into this repo.
BloomTests: 3188 passed, 13 skipped. Doctor: 112 passed.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…6719) Adding the four Doctor projects to the solution let Visual Studio also add solution configurations Bloom never had: `Debug|Any CPU`, `Debug|x86`, and their Release twins. That looks harmless and is not. WHAT IT BROKE `.vscode/launch.json` runs `output/Debug/x64/Bloom.exe` after a preLaunchTask of `dotnet build Bloom.sln`. With only x64 and ARM64 on offer, that build had to choose x64, so it rebuilt the very file F5 then launched. Once `Any CPU` existed it won, because it is MSBuild's default platform - so the build wrote `output\Debug\AnyCPU\` while F5 kept launching the x64 copy that nothing rebuilt any more. The result is the worst kind of failure: F5 silently ran a binary from the last day anyone happened to build x64 - here a week old - with no error, no failed build, and no "run the last successful build?" prompt. It was found only because the stale Bloom 404ed on an API endpoint that this branch had added, and the front end (served live by Vite) was current while the backend was not. It is not specific to this machine or to VS Code: any build of the solution that does not name a platform now lands somewhere nothing runs from. ALSO FIXED: THE DOCTOR WAS NOT LANDING BESIDE BLOOM BloomFreezeDoctor declares <Platforms>x64;ARM64</Platforms>, but every solution configuration - x64 included - was mapped to its `Any CPU` project configuration, so its exe built into `output\Debug\AnyCPU\` while Bloom.exe sat in `output\Debug\x64\`. DoctorLauncher looks for the Doctor next to Bloom.exe, so "Run Freeze Doctor" would have found nothing in any dev build, failing silently - exactly what the apphost note in Directory.Build.props warns about. Each solution platform now maps to the matching project platform. Verified by running the VS Code build task itself: BloomExe now copies its apphost to output\Debug\x64\Bloom.exe, and BloomFreezeDoctor copies into output\Debug\x64 beside it. (The run ends in MSB3026 file locks, because a Bloom was running out of that folder at the time - the ordinary "close Bloom before building" problem, and itself confirmation that x64 is the target again.) Bloom is an x64/ARM64 product; the solution offering `Any CPU` and `x86` at all was the mistake, so both are gone rather than merely deprioritised. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Everything here came out of running the Doctor against a real Bloom for the first
time. None of it was found by tests, and none of it produced an error: every
defect below was the Doctor working correctly and telling nobody.
THE SHAPE OF ALL OF IT
A developer build never files a report - it gathers to disk and stops, which is
right. But the window only ever revealed itself when a report was FILED, so the
whole developer path ended in silence. A freeze was detected, 24 KB of report and
a 17 MB dump were written, and the screen said nothing. It looked broken while
succeeding, on precisely the runs anyone testing it would use.
WHAT NOW HAPPENS
* A report gathered but not filed says so, names its folder, and reveals the
window - a separate event from "filed", because "we told the tracker" and
"nothing was sent, here is where to look" need different words.
* A "Show report" button, because the two routes that existed were both
ephemeral: a balloon that goes after ten seconds or the moment you click
elsewhere, and a line of text the next status update overwrites. A report
could be gathered perfectly and be unreachable a minute later.
* Ending a stuck Bloom says which of the four outcomes happened. ZombieEnded
had no listener at all, so the Doctor could end a process on the user's
behalf and never mention it.
* The log says WHICH reason stopped a filing - simulated, developer build, or
debugger - rather than listing all of them and leaving the reader to guess.
TWO RACES, BOTH THE SAME MISTAKE
Ending the old Bloom, or a Bloom crashing, is itself what leaves the Doctor with
nothing to watch. So the Doctor could exit in the middle of the very job it had
been given:
* "Restart Bloom" showed a confirmation, the automatic policy then ended the
zombie, ConsiderExiting found nothing left, and Application.Exit took the
dialog down unread. Bloom never restarted.
* A crash was gathered and the reveal was queued - then the guard was consulted
on the worker thread, before that reveal had run, and truthfully answered
"no window is showing". The exit was queued behind the reveal and destroyed
the window in the same message pump.
A restart now holds the exit open from the click until Bloom has actually started;
the guard is taken on the raising thread rather than inside the queued action; and
the exit asks again on the UI thread immediately before going. The Doctor also
declines to quit while its window is on screen - a program that vanishes
mid-sentence is indistinguishable from one that crashed.
RESTART BLOOM NO LONGER OFFERS WHAT IT CANNOT DELIVER
Bloom is single-instance, so a new one cannot start while an old one holds the
token; the button used to start a doomed process that died seconds later, which
reads as "Bloom will not start" - the very complaint that brought the user to the
Doctor. It now offers to end what is in the way first. Per John, that includes a
FROZEN Bloom: it cannot save anything anyway, so refusing mostly leaves the user
unable to start Bloom at all. The confirmation still names what is given up,
because a frozen Bloom does sometimes recover, as one did during this testing.
The AUTOMATIC policy is unchanged and still refuses, by itself, to end a frozen
Bloom or one under a debugger.
TELLING A REHEARSAL FROM THE REAL THING
Bloom now publishes which failure it was told to simulate, and the Doctor will not
file a card about a freeze we asked for. This is not only convenience: on ALPHA,
NeverFile is false, so an Alpha tester using the simulator - exactly who it was
opened up to - would have filed a real card. `--force` still overrides it, as it
overrides every other refusal.
The marker may affect whether a report is filed, and one line of the report.
Nothing else: detection, gathering and the zombie policy behave exactly as for a
real freeze, or a simulated run stops testing what it exists to test. A test pins
that, and mutation-testing confirms the test fails when the check is removed.
EVIDENCE THAT WAS BEING LOST
* Bloom's whole log was meant to be attached and never was. The log is written
by the process being diagnosed and held exclusively for the instant of each
write, so every open is a throw of the dice - and the code threw twice, tail
then copy, and the copy lost. It now copies first and reads the tail from its
own copy: one contended open, retried, and the good chance goes to the whole
log. (Measured on the way: File.Copy and a permissive stream fail in exactly
the same cases, so sharing flags were never the problem - the number of
attempts was.)
* The crash-dump path returned in silence both when no Doctor was watching and
when the request could not be signalled, so a crash that produced no dump left
nothing to say why. It now logs, except in the no-Doctor case, which is every
ordinary user's crash and where costing nothing matters.
WAIT CHAINS THAT CAN BE READ
`BLOOM_SIMULATE_FREEZE=mutexchain` is a new simulated failure - a UI thread
blocked on a kernel mutex another thread holds - and it exists because none of the
other kinds could produce a wait chain at all: the API is blind to Monitor,
SemaphoreSlim and async waits, which is all the others use. It made the first
end-to-end check of the wait-chain layout fix possible, and that check passed
against a live process: the chain named threads 52776 and 93728 in process 94304,
and 52776 was the first-started thread waiting on a kernel object while 93728 was
the mutex holder in Thread.Sleep.
Reading one, however, defeated somebody who knows Bloom well, so each chain now
explains itself: how to read it, how many of the process's threads appear and why
the others do not, and - crucially - whether Windows reported a CYCLE. A cycle is
a real deadlock; no cycle is a one-way block that says nothing about whether the
owner will finish. And since a cycle running through a managed lock is invisible
here, "no cycle" is not proof there is no deadlock.
Also: the first node of a chain IS the thread being asked about, so rendering it
as "waiting on thread N" had every chain claim a thread was blocked on itself.
AND THE TRAY ICON IS BLOOM'S
It was SystemIcons.Information - a placeholder never replaced. That icon is the
only visible sign the Doctor is running, and a generic blue "i" is invisible among
a dozen others; it was missed first time out. The exe now carries bloom.ico,
shared from BloomExe rather than copied, and the window reads it back off its own
exe so the tray, window and Explorer icons cannot drift apart.
STILL OPEN, AND NEEDING A DECISION: the crash-dump handshake does not fire.
Bloom's own FatalExceptionHandler hooks AppDomain.UnhandledException in
SetUpErrorHandling, a thousand lines before FreezeDoctorSupport.Start, and answers
a fatal exception with a modal dialog; ours is registered behind it. Moving our
hook earlier, or asking for the dump from Bloom's own fatal path, is a change to
Bloom's crash handling and has not been made. The logging added above is what will
say which of the two silent paths a crash actually takes.
Verified: BloomFreezeDoctor.Tests 113 passed; BloomTests FreezeDoctor 16 passed;
BloomExe builds clean. DoctorSupervisor and StatusForm still have no test harness,
so the window and supervisor changes here are verified by hand - which is how
every one of these defects was found.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…-16719)
Everything here came from two things: a code review of the whole branch, and
actually filing to the tracker for the first time. Between them they found one
defect that made the feature useless on the channels it was built for, and a
family of smaller ones that all shared a shape.
THE DOCTOR DID NOT WORK AT ALL ON ALPHA OR BETA
Bloom's installer renames the executable per channel, so an Alpha install runs as
`BloomAlpha`. Bloom launches the Doctor with only `--adopt <pid>`, so its target
name stayed at the default "Bloom", the first discovery tick found no such process,
concluded the Bloom it had just adopted was gone, and the Doctor exited - about a
second after starting, silently. It worked only on Release and on developer builds.
Alpha and Beta are where we most want it, and are the only channels where the
freeze simulator is allowed at all.
Discovery now searches a set of names it LEARNS: adopting a process adds that
process's own name, so there is no list to keep current. "Report now" had the same
literal name and so announced that Bloom was not running while watching it; it now
asks the supervisor which Blooms it is actually watching.
WIRES BUILT AND NOT CONNECTED
Three of these, all silent:
* The crash-dump handshake had never once run. Bloom's own fatal handler
registers for unhandled exceptions a thousand lines before the Doctor's hook,
and answers with a modal dialog that does not return. Bloom's fatal path now
asks for the dump itself, which is the right owner anyway - the Doctor is an
optimisation, not a dependency - and both fatal routes funnel through that one
place. The request is idempotent, since the Doctor's hook remains as a backstop
for the routes that never reach it.
* "Restart Bloom" relaunched whatever Bloom was INSTALLED rather than the one
that had just frozen - an installed 6.3.2 Release instead of the developer
build under test. The window was only ever told a path on the `--adopt` path,
so a Doctor started from the command line knew none at all. Every watcher now
reports its Bloom's path from the one place all routes pass through.
* ZombieEnded was raised and nothing listened, so the Doctor could end a process
on the user's behalf and never say so.
A MISSPELT SIMULATION KIND SILENCED REAL FREEZE REPORTS
`BLOOM_SIMULATE_FREEZE=slep` armed nothing but still marked the session a
rehearsal, so the Doctor declined to file for every genuine freeze for the rest of
that session, on a Bloom behaving perfectly normally. The kind is now validated
before anything is armed or recorded, with tests for a misspelling and for every
advertised kind.
A DEATH WE ASKED FOR IS NOT A BUG
One incident produced two cards: a frozen Bloom was reported, the Restart button
ended it to clear the way, and the Doctor reported that death as a fresh problem -
describing its own action as a fault, and spending a second of the three daily
filings. Dedup could not have caught it, because the fingerprint deliberately
includes the reason. The supervisor now records every Bloom it asks to stop, its
own zombie policy and the Restart button alike, and declines to report those
deaths.
THE LOG WAS NOT BEING ATTACHED, AND THE REASON WAS NOT WHAT I FIRST FOUND
A filed card went out with no log, saying both "the whole log" and that the log
could not be attached. RobustFile.Copy is refused outright by a file whose owner
holds it for writing, permanently, so its retrying cannot help - and Bloom holds
its log open for its whole run, which means attaching it could only ever have
worked for a Bloom that had already exited. Never for a freeze. (An earlier
investigation measured File.Copy instead, found it tolerant, and drew the opposite
conclusion; AttachingTheLogTests now pins both halves so that cannot recur.) The
two contradictory sentences are now one sentence that cannot disagree with itself.
A REPEAT NOW GETS A SHORT NOTE
Reports sharing a fingerprint share their reason, version, channel and top five
frames, so most of a second report is identical by construction. A recurrence posts
what varied - when, which process, what we saw, what Bloom thought it was doing -
plus the bundle folder, and no attachments.
ALSO: a queue that one undeliverable comment could block for thirty days (a
permanent refusal was classified as "no network"); a seqlock that gave up inside
one scheduling quantum and so reported a live channel as absent; a WMI leak on a
five-second loop; a torn read in the code that decides whether to exit; and a wait
chain that claimed a thread was blocked on itself, with each chain now explaining
how to read it and whether Windows found a real cycle.
One review finding was refuted by a test and left alone: seeding the heartbeats at
channel creation would make a Bloom that hangs before its first tick look healthy,
which is the dangerous direction. The constructor now says so.
Verified: BloomFreezeDoctor.Tests 117 passed; BloomTests 3250 passed, 13 skipped;
front-end typecheck and lint clean, vitest 733 passed. Filing was exercised against
the AUT project for the first time - a card, and then a comment on it.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
776a56e to
7269268
Compare
All three are in code written today, and two would otherwise have been found only by somebody using the Doctor. CLOSING THE WINDOW MADE IT UNREACHABLE FOR THE REST OF THE SESSION Making the X button hide instead of quit created a state that could not exist before: hidden, with the stay-hidden flag clear. RevealYourself is the only route to visibility in that class and it returns early unless the flag is set, so the tray's "Show" did nothing, and every later report revealed nothing - leaving "Restart Bloom" and "Show report" alive but invisible. The change meant to stop people accidentally switching off freeze detection would instead have hidden the window permanently, the first time anyone tidied their screen. Closing now restores the flag, which is what closing means anyway, and RestoreFromTray no longer leans on RevealYourself's early return: it clears the flag and shows the window itself, because "the window will not come back from the tray" is the one failure that method exists to prevent. THE "WE CAUSED THIS DEATH" GUARD MISSED THE PATH THAT MATTERS MOST It was applied where a report is WANTED, but the exit examination files its own report without passing through there. That path is reached precisely when we had to KILL rather than ask - and a killed process runs no ProcessExit handler, so it leaves no proof of a clean exit, which the examination then reports as "exited without shutting down properly". A second card about our own action, carrying a different reason from the first, so the outbox could not have merged them either. Exactly the defect the guard was added to remove, still present on the kill path. A RECYCLED PROCESS ID COULD HAVE SILENCED A REAL REPORT The set of Blooms we asked to stop was never pruned. Windows recycles process ids, and "Restart Bloom" is the case that kills one and starts another moments later, so a stale entry could suppress a genuine death report about a different Bloom that happened to be handed the dead one's id. Entries are now dropped once the process is seen to have gone. Doctor: 117 passed. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…BL-16719)
Found by the Fable review standing in for Devin, and it is the reason this
morning's crash-dump fix changed nothing.
Every accessor in DoctorSignals except TryCreate goes through TryOpenExisting.
TryCreate is called in exactly two places in the product: Bloom creates the
quit-request event and holds it while waiting, and the Doctor's watcher creates
the "I am watching" event and holds it while watching. Nothing anywhere created
either half of the DUMP handshake.
So at Bloom's end, TrySignal(DumpRequestName) found no event and returned false;
and at ours, DumpRequested() opened nothing and could only ever answer false,
making RespondToACrashingBloom dead code. The handshake could not fire from either
side. This morning's change - moving the request into Bloom's own fatal handler so
that it runs at all - corrected the ORDER of a call that was inert anyway. Two
silent failures stacked on the same feature, which is why the log line added
alongside it ("Could not signal the Bloom Freeze Doctor for a dump") is the thing
that would finally have shown this.
The watcher now creates and holds both events beside the watching one. It is the
right owner: its lifetime spans the crash and Bloom's does not, and Bloom already
checks whether anyone is watching before it pauses for anything. Both are released
with the watcher, so a Bloom whose Doctor has gone stops waiting on answers that
are not coming.
DumpRequested now reads the handle we hold rather than opening a fresh one, and
resets it once taken - manual-reset, so leaving it set would have every later tick
believe a new request had arrived. SignalDumpComplete cannot throw: Bloom's wait
gives up after about three seconds regardless, and our failure must not be what
holds a dying process open.
Still untested end to end. The next simulated crash with a Doctor watching is what
will show whether a dump actually lands; until then this is a fix to code that
demonstrably could not work rather than one demonstrated to work.
Doctor: 117 passed.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Devin has now timed out on this PR five times, so a Fable sub-agent reviewed the whole branch instead. It found the crash-dump handshake that was never created (fixed separately, in the commit before this one) and these. FOUR CARDS FOR TWO EVENTS, AND NOTHING RECOGNISED THE PAIRS One Bloom's collapse reaches the Doctor in instalments. The UI stops responding, so we report a freeze; then the process dies, and the exit examination finds no proof of an orderly shutdown and reports that too. Two reports, different reasons, therefore different fingerprints - so the dedup that exists for a recurring problem could not see they were about the same event, and filed two cards. That is exactly what the first live test produced: AUT-20929 and AUT-20930. Fixing the dump handshake would have added a third, since the crash path gathers once while Bloom is alive and once after. So the tie for this case is the process, not the fingerprint. The fingerprint's job is recognising a problem on other people's machines and is untouched; a process id means nothing anywhere else, which is exactly why it is the right key for "these two happened to the same Bloom, a minute apart". A follow-on report is kept rather than discarded as a recurrence would be: its body is attached and its own artifacts come with it, because "and then it died" is new information and for a crash it is the instalment carrying the minidump. The card gets a "what happened next to this same Bloom" section, without which the fold would be worse than the two cards it replaces - the death would be on disk and nowhere in the text. It does not touch Occurrences, which means "this same problem, again": one Bloom failing and then dying of it is not that, and counting it made the card say so. A HARD FAILURE WAS FILED AWAY AS A TIDY SHUTDOWN Bloom writes an exit record on the way out of a hard failure too - Environment .Exit before the orderly path begins, which is what a WebView2 startup failure does - and marks that record forced. The supervisor passed "a record exists" as "there is proof of a clean exit", so the classifier concluded Bloom had shut down properly and said nothing. The explanation it would have printed says how wrong that is: "Bloom shut down properly (shutdown phase 0)". The protocol layer already had this right, and its comment says why - "an exit that was forced is not an explanation, it is the evidence" - so the two now agree. The classifier also gained a branch for it, because Bloom's own account of forcing itself out is first-hand and beats guessing at a user kill. WINDOWS AGREEING THAT BLOOM CRASHED, ABOUT OTHER PROGRAMS The Event Log check accepted three things and two of them matched strangers: - the bare hex pid, anywhere in the message, undelimited. Every Application Error entry is full of hex - exception codes, fault offsets, module timestamps - so a short pid was near-certain to appear inside one of them. Pid 4096 is "1000", which sits in a fault offset of 0x00007ff81000a4c0. It now has to be a whole hex number AND labelled as a process id, which is how Windows writes it. - "msedgewebview2.exe", unqualified. Bloom is far from the only WebView2 host on a Windows machine: Teams, Outlook and the Widgets panel all lose renderers of their own, and any of them doing so within five minutes became evidence that Bloom had crashed. There is no narrower version either - the pid in such an entry is the renderer's, not Bloom's - so it is dropped. Little is lost: Bloom normally survives a renderer crash, and this code only runs when Bloom has gone. The third was too narrow rather than too broad. The installer renames the exe per channel, so matching the literal "Bloom.exe" found neither BloomAlpha.exe nor BloomBetaInternal.exe - quietly disabling the evidence on every channel except release. The name of the exe that actually died is now passed in. Ten tests, including the pid-inside-a-fault-offset case and somebody else's renderer crash. "THIS BLOOM DOES NOT PUBLISH A HEALTH CHANNEL" - OF ONE THAT HAD JUST BEEN The channel lives in Bloom's own memory and no reader holds it open, so it is gone the moment the process is. The report re-read it at gather time, so every report about a dead Bloom - the deaths, the crashes, the reports where what Bloom last thought it was doing matters most - stated that this Bloom published nothing and that this was "the normal case for a Bloom released before the Freeze Doctor existed". The probe had been keeping the last live reading for exactly this, with a comment saying so, and then throwing it away on the tick the read failed - which is the tick it became evidence. It keeps it now, the death path passes it to the gatherer, and the report dates it honestly instead of presenting it as the state at the moment of gathering. Where there is genuinely nothing, the two silences are now told apart rather than one being asserted as the other. THREE SMALLER ONES A long operation that finished put back the activity from before it started even when another thread's operation was still running, overwriting a live description with a stale one - and then being overwritten in turn by an account of work already finished. It now only restores the slot if the slot is still its own. The CDP client decoded each WebSocket fragment separately, so a multi-byte UTF-8 character split across a 16 KB boundary became two replacement characters. The JSON still parses, so nothing complains; the text inside it is simply corrupted, which for Bloom means the vernacular titles and console messages a report quotes. It now decodes once the message is whole. NoteBloomReportedAProblem claimed to be called for a Sentry event as well as a tracker card. Only the card path calls it, and that is right rather than missing: a Sentry event creates no card, so a Doctor report about the same trouble is not a duplicate of it - it is the only thing that would put the problem on the board. The comment now says that. The same-Bloom fold is bounded in time, at ten minutes measured from the last thing that happened to the bundle. The instalments it exists for arrive seconds apart, and a process id is only unique while its process lives: without a bound, a report still queued from a Bloom that died this morning - and on a bad connection reports sit for weeks - would swallow this afternoon's report about whatever new process inherited its number. Doctor: 128 passed (11 new). BloomTests: 3250 passed, 13 skipped. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…-16719) Found reviewing my own fix from the last commit. Making an exit record's ForcedByDoctor flag mean "this was not a clean exit" was too broad, because the flag covers two different things: `_endedAtDoctorsRequest || _shutdownPhase == 0`. A Doctor asking a healthy Bloom to quit gets that flag on a perfectly orderly shutdown, so the change would have filed a card about Bloom doing exactly what we asked - the mistake _weAskedItToStop exists to prevent, returning through a different door whenever the Doctor that asked and the Doctor that examined the exit are different processes, which is precisely what a command-line Doctor is. The phase is the thing that actually distinguishes them: 0 means the orderly path was never begun. So proof of a clean exit is now a record with a phase above 0, and the reportable case is a record with phase 0. Doctor: 129 passed. Front-end: 733 passed, typecheck and lint clean. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…er one name (BL-16719) Both found by reviewing this run's own diff, and the second by the test written for the first. A MERGE COULD UN-FILE A REPORT THAT HAD JUST BEEN FILED Folding a report into an existing bundle is a read-then-write, and a drain can finish between the two: the supervisor drains on a timer as well as after each gather, while an enqueue runs on whichever worker thread gathered. The gap is not small either, because a follow-on merge writes a report body and moves a minidump before it writes the metadata. Writing the stale copy back over a bundle that had just been filed would restore State=Pending and drop its IssueId, so the queue would file the same report a second time - the exact duplicate card that merging exists to prevent, arriving by way of the mechanism meant to stop it. Both merge paths now re-read the metadata at the moment of writing and refuse the merge if the bundle has left the queue, sending the caller off to make a bundle of its own. The follow-on path checks twice, before writing anything and again before the metadata write; if it loses the race at the second check the files it already wrote stay behind as harmless spare copies, so the report survives and only its attachments are lost. Filing the same card twice is the worse trade. Re-reading also fixes a lost update in its own right: the occurrence count and attempt count now build on what the disk says rather than on a stale snapshot. TWO REPORTS IN ONE SECOND COULD DESTROY ONE OF THEM A bundle's folder is named for the second it was gathered in plus the fingerprint, and the publish step renames staging onto that name. Two bundles that want the same name have always been possible - a developer run, where nothing merges at all - and refusing a merge above makes it reachable in ordinary use as well. The rename then threw IOException straight out of Enqueue, which discards the gathered report: the one failure mode this class is written to prevent, in the same method whose comment explains at length why the rename must be robust. The name is only a name, so it now takes a suffix until it is free. Doctor: 130 passed. BloomTests: 3250 passed, 13 skipped. Front-end: 733 passed, typecheck and lint clean. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…ight (BL-16719) Devin finally completed a review of this PR - the sixth attempt, and the first that produced findings. Most of what it raised was already fixed or already decided; these three were live. ROUGHLY ONE BLOOM IN TEN THAT VANISHED WAS NEVER EXAMINED The exit examination runs on the watcher's own one-second tick. The discovery sweep, every five seconds, disposed the watcher of any process that had gone - on the assumption, written into its comment, that "the watcher itself reports the exit first, so by the time we get here its story has been told." That was a hope, not a guarantee. Whichever of the two fires first after a death wins, and when the sweep won it stopped the timer before the tick could run, so the exit was never examined and no report was produced at all. For a death at a random moment that is something like one in ten - one in ten of a state this tool exists to notice, silently producing nothing. The sweep now examines each departed Bloom itself before letting go of its watcher, which needs no coordination with the tick because the examination already claims each process id once under the lock. That needs the probe, so probes are now kept beside their watchers. A SIMULATED CRASH FILED A REAL TRACKER CARD Whether a report may be filed was worked out in three places, and two of them used a shorter list of conditions than the third. The crash-dump path and the exit examination each checked the debugger and the channel but not the simulated-failure marker - so a deliberately simulated CRASH on a channel where the simulator is allowed (Alpha) filed a real card, while a simulated FREEZE on the same machine correctly did not. Rehearsals reaching the tracker is precisely what that marker exists to prevent, and the paths that run when Bloom actually dies were the ones missing it. There is now one definition, on the watcher, called by all three. A COMMENT SAYING THE PATIENCE DOES NOT EXIST, WHEN IT DOES `SetLongOperation`'s doc still said in bold that nothing called it and the five-minute patience therefore did not exist. This PR wires it in six places - BloomPUB, ePUB, video, Reading App Builder, and Bloom Library upload and download - so a reader was being told the opposite of the truth about the guard that stops a long publish being filed as a freeze. Doctor: 132 passed (2 new). BloomTests: 3250 passed, 13 skipped. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
|
[Claude Opus 5 during preflight] Consulted Devin up to Devin had timed out on this PR five times over two days — jobs reported Most of it was already dealt with. Devin itself marks 7 of the 10 bugs resolved by earlier commits on this branch. Of what was still live:
Every current Bug and Investigate flag has its own thread above with its outcome. The informational flags are not mirrored. Greptile has reviewed this branch 15 times and its threads are all resolved; its most recent review predates today's commits. CI is green. One thing Devin cannot tell us, and says so itself: the crash-dump path is still unexercised end to end. |
Four of the six needed code. "REPORT NOW" NOW SAYS WHAT IT IS OVERRIDING It keeps filing whatever the circumstances - a developer build, a rehearsal, a debugged process - because being able to force a real filing without stopping and restarting the Doctor with `--force` is useful twice over: it is how the filing path itself gets tested, and a developer build can have a real freeze genuinely worth reporting. But it now names the reasons filing would normally be prevented and asks first, defaulting to No. That needed the four conditions to be able to describe themselves, so the single definition added for the crash and exit paths now returns reasons rather than a bare bool, and MayFileAReport is "no reasons". THE WATCHED PROCESS'S HANDLE HAS AN OWNER The handle is what supplies the exit code of a process that has already died, so releasing it with the watcher would take it from an examination still reading it - which is why it had simply never been released at all. Ownership now passes to whichever examination claims the death: claiming removes the probe from the supervisor's table and the examination disposes it when it finishes, including on the path that claims a death it then declines to examine. What is left in that table is by definition unclaimed, so shutdown can release those. THE MERGE RACE IS CLOSED, THE DEVELOPER'S WAY Rather than making a gather wait on an upload, the drain now marks a bundle `Uploading` under a brief per-bundle metadata lock, releases the lock, does the network round trip with nothing held, and takes the lock again to record the answer. The lock is only ever held for a few file operations. A gather arriving mid-upload therefore sees a state that means "going out right now", which is different from "waiting to be sent" and needs the opposite treatment. It does not merge; it takes a bundle of its own, records whose card it belongs on, and waits. When drained it becomes a comment on that card. Waiting is bounded by the sibling: still queued means try again next pass, filed means send now, gone from the queue entirely means stop waiting and file on its own merits. The link has to be recorded, because nothing could reconstruct it later - a follow-on's fingerprint is by definition not the one its sibling's card was opened under, so no search would find it. Three tests, one of which reads the queue from inside the upload, since that is the only way to prove the mark goes on before the network call rather than after. THE TOKEN DECISION IS RECORDED WHERE THE TOKEN IS Left as it is, with the developer's reasoning in a comment next to it: what the Doctor does with the token is under our control exactly as what Bloom does with it is, so a second binary of ours carrying it adds no risk the first did not. The real risk is the pre-existing one - anyone who lifts it into a program of their own can do what it permits - which argues for narrowing the account or for the relay, not for treating the two executables differently. AND ONE THAT NEEDED NO CHANGE Asked to look for something simple that would make always-on health publishing cheaper: there is nothing, because the expensive-sounding part does not happen. The session file is compared every ten seconds and written only when it has actually changed, which in steady state is never - so the claim that it "rewrites a session file every 10s", in the review flag and in my own report, was wrong. What remains is a shared-memory page, a thread waking once a second, a UI timer at half that, and three property reads every ten seconds. Nothing worth trading detection resolution for. Doctor: 135 passed (3 new). Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Found by thinking through the change in the previous commit rather than by a test failing, which is why it gets its own test now. Marking a bundle `Uploading` before the network call is what lets a gather arriving mid-send know it must not merge. But the drain only ever looks at bundles that are `Pending`, so a mark left behind by a send that never finished - the Doctor killed mid-upload, or the machine going down - would make that report invisible to every future drain. Never retried, never filed, not even recorded as failed: it would sit there until age eviction quietly deleted it. Protecting a report from being filed twice must not become a way of losing it altogether. A drain now begins by putting back to Pending anything that has been marked as uploading for longer than a send could plausibly still be running. Fifteen minutes, deliberately generous: a dump of a dozen megabytes over the sort of connection that tends to accompany a freeze is genuinely slow, and reclaiming one that is still in flight would file it twice - the very thing this mechanism exists to prevent. Doctor: 136 passed (1 new). BloomTests: 3250 passed, 13 skipped. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…in silence (BL-16719) Devin's re-review of the previous commit, and the best single finding of the whole run: the attachment budget could not carry the one file it exists to carry. `MaxAttachmentBytes` was 12 MB. This project's own measurement, written down in ManagedStacksCollector, is that a `DumpType.Normal` dump of a real Bloom is **16-17 MB** against a 234 MB working set. An artifact bigger than the remaining budget is skipped, so on any real Bloom the dump was always over and always skipped - and the dump is the primary artifact, the point of decision D2, and the reason the whole crash-dump handshake exists. A cap meant to stop a card becoming a file server was instead stopping it carrying the only file worth having. It is now 30 MB: clear of the measured dump with room for the log beside it, and still nothing like a file server. The worse half was that the skip was silent. `continue`, and nothing anywhere said so - the card looked complete, and the missing dump would have been discovered by someone opening a card expecting one. Anything the budget cannot carry is now named in the card body, with its size and where the local copy is, using the same arithmetic the upload itself uses so the two cannot disagree. Guarded by a test that fails if the budget ever drops back below a measured dump. Doctor: 137 passed (1 new). Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
|
[Claude Opus 5 during preflight] Consulted Devin again, up to No live bugs at this commit — of the eleven it lists, none is against this HEAD unresolved. Eleven of its twelve Investigate flags are ones already carried through this run, each with its own resolved thread above. The twelfth is new, and is the best finding of the run: the attachment budget could not carry a minidump. 12 MB, against our own measurement of 16-17 MB for a That is the whole of this round. CI is green, every review thread on the PR is resolved, and the six decisions from the previous report are implemented. |
Problem
Users tell us Bloom froze, and we get almost nothing to work with. Their problem report is written after they killed Bloom, so it describes a healthy new process, and the log holds only what Bloom managed to write before it stopped responding. Three quite different failures arrive looking identical — the UI stops responding; Bloom exits without reporting anything; or Bloom's window is gone while the process lives on, so the user cannot start Bloom again. BL-16697 is the live example.
Cause
Nobody is watching at the moment it happens, and the worst case cannot be watched from outside at all.
The measurement the whole design rests on — check this first if you check one thing: a WinForms UI thread blocked in a managed wait on an STA thread still dispatches sent messages, so the window answers probes,
IsHungAppWindowreports it healthy andProcess.Respondingreturnstruewhile Bloom is completely stuck. Measured on a real Bloom: nine minutes frozen, reported responsive throughout. Since Bloom's UI thread awaits WebView2 constantly, that is likely the common shape of freeze rather than an exotic one.WM_TIMERis not dispatched, which is why detection rests on a UI-thread timer heartbeat published through shared memory, and not on either API that looks built for the job.What this PR does
Adds a companion Windows app — the Freeze Doctor, four projects in this repository — that is already running when the trouble starts, gathers what can only be gathered at that instant, and files a YouTrack card by itself.
ProcessExithandler — which runs for a normal return andEnvironment.Exit, and not forFailFast,TerminateProcessor an access violation, which is exactly the line worth drawing.Log.txteach run and falls back to a random name when another Bloom holds it, so guessing from the filesystem picks the wrong file in precisely the restart-after-a-freeze case.BLOOM_SIMULATE_FREEZE), so the Doctor never files a card about a rehearsal. This matters beyond convenience: on Alpha, where the simulator is deliberately allowed, it otherwise would have.How it ships. Inside Bloom's installer, signed alongside
Bloom.exe. Whether it runs is a setting, off by default, toggled by "Run Freeze Doctor" in the collections-tab debug menu; turning it on starts it at once. Until it has something to report it shows no window at all — only a tray icon.Reviewing this
75 files, ~15,800 insertions.Suggested order, since most of the volume is the Doctor's own code:src/BloomFreezeDoctor.Protocol/DoctorChannel.cs— the wire format, and the rules that let it grow without breaking older readers.src/BloomExe/FreezeDoctor/— Bloom's side; small, and the part that runs in everyone's Bloom.src/BloomFreezeDoctor.Core/FreezeDetector.cs— the detection rules. A false positive files a bogus card; a false negative is the tool not working.src/BloomFreezeDoctor.Core/Outbox/— the queue and the YouTrack submitter, which is what actually posts to the tracker.Two commits are worth reading on their own and then skipping: the protocol project rename (mechanical, ~20 files), and the solution-platform fix — adding the new projects had let Visual Studio add an
Any CPUsolution configuration, which silently redirected everydotnet build Bloom.slnaway fromoutput\Debug\x64, the folder.vscode/launch.jsonlaunches. F5 then ran whatever binary was last built there, with no error and no prompt.Verified
BloomTests3250 passed / 13 skipped;BloomFreezeDoctor.Tests130 passed; front-end typecheck and lint clean, vitest 733 passed.Now exercised by hand, which is where most of the recent work came from: freezes both visible and invisible to Windows, a window-less zombie ended and restarted, and a real crash — each against a live Bloom with
BLOOM_SIMULATE_FREEZE. That found a family of defects tests could not: the Doctor did its job and told nobody. A developer build never files, so the window only ever revealed itself on a filed report, and every developer run therefore ended in silence; ending a zombie or crashing is itself what leaves the Doctor with nothing left to watch, so it could exit in the middle of the very job it had been given; the only routes to a gathered report were a ten-second balloon and a line of text the next status update overwrote; and Bloom's whole log was meant to be attached and never was.The wait-chain layout fix is now confirmed end to end against a real freeze, which needed a new simulated failure (
mutexchain) because none of the others could produce a wait chain that Windows' API can see.The crash-dump handshake is wired but not yet proven. It could not fire at all until now, for a reason it took two attempts to find: nothing anywhere created either of the two named events it uses, so Bloom's request found no event and the Doctor's check for one could only ever answer false. Both ends are now in place — Bloom asks from its own fatal handler, and the watcher creates and holds both events for as long as it watches — but no crash has been run against it since, so a dump actually landing on a card is still unverified. A crash produces a report either way; it may simply have no dump attached.
Ref: https://issues.bloomlibrary.org/youtrack/issue/BL-16719 [Devin review](https://devinreview.com//pull/8229) - - - This change is [
](https://reviewable.io/reviews/BloomBooks/BloomDesktop/8229)