Skip to content

Make compat binary console logging non-blocking - #732

Draft
todthomson wants to merge 2 commits into
mainfrom
todthomson/lev-2253-non-blocking-compat-console
Draft

todthomson wants to merge 2 commits into
mainfrom
todthomson/lev-2253-non-blocking-compat-console

Conversation

@todthomson

Copy link
Copy Markdown
Member

Background

The nightly Halibut chain has been blocked every few days by a single net48 test timing out against the out-of-process 5.0.236 compat binary (Linear LEV-2253). The trace logs from two of those failures (7Nq4O5056D and 3rIE6fZPSs, build 10.0.2247) show the same sequence:

  1. The test process stops receiving the compat binary's stdout.
  2. About 4 KB of further traffic still flows, with no matching compat-side log lines. That's roughly a Windows anonymous-pipe buffer.
  3. The compat binary freezes completely. In-flight requests stop, and reconnects get TCP but are never served.

The compat binary logs every Halibut event and every service call with a synchronous Console.WriteLine on the request path. So once the test-side stdout reader stops draining the pipe, the next write blocks, and the Halibut protocol in the compat binary blocks with it.

This PR doesn't explain why the reader stops. That's being investigated separately; the CliWrap 3.8.2 → 3.10.5 bump in #724 is a suspect. What it does is stop a stalled reader from freezing the binary under test.

Results

  • Adds NonBlockingLineWriter and a NonBlockingConsole wrapper to Halibut.TestUtils.CompatBinary.Base. Lines are queued (bounded at 10,000) and written to stdout by a dedicated background thread.
  • If the queue is full, lines are dropped and counted instead of blocking. A [NonBlockingLineWriter] N log line(s) were dropped… line is written once output resumes.
  • All compat binary console output now goes through NonBlockingConsole.
    • The startup lines the harness waits for (Listening on port, RunningAndReady) are flushed before the binary continues.
    • Queued output is flushed (briefly) before the process exits.
  • FixHungWebSocketsHack keeps its direct Console.WriteLine, since the write itself is what that hack relies on. It runs on its own background thread, so it can't block the protocol.
  • NonBlockingLineWriterFixture covers the writer:
    • lines keep their order;
    • callers don't block when the target is blocked;
    • dropped lines are reported once output resumes;
    • flushes time out when the target stays blocked;
    • a throwing target doesn't stop the writer.
      The source file is linked into Halibut.Tests, so the test project doesn't reference a compat binary and its old Halibut package.

Relates to Linear LEV-2253.

Before

A stalled stdout reader on the test side freezes the compat binary. The test then fails with a read timeout, or with a polling request that is never collected.

After

A stalled stdout reader only delays (or eventually drops) compat binary log lines. The compat binary keeps serving requests.

How to review this PR

Quality ✔️

  • Built Halibut.TestUtils.CompatBinary.Base for both net48 and net10.0 locally.
  • On Linux (net10.0) I ran NonBlockingLineWriterFixture three times, plus the 42 UsageFixture.OctopusCanSendMessagesToTentacle_WithEchoService / _WithSupportedServices cases, which include the 5.0.236 variants. All passed.
  • net48 on Windows hasn't been run yet; that needs CI.
  • Worth a close look: the startup flush in BackwardsCompatProgramBase and ProxyServiceForwardingRequestToClient, and keeping FixHungWebSocketsHack on the direct console write.

Pre-requisites

  • I have read How we use GitHub Issues for help deciding when and where it's appropriate to make an issue.
  • I have considered informing or consulting the right people, according to the ownership map.
  • I have considered appropriate testing for my change.

Generated by Claude Code

The compat binaries log every Halibut event and service call with a synchronous Console.WriteLine on the request path. When the test process stops reading the compat binary's stdout, the pipe buffer fills and the next write blocks, freezing the whole binary (LEV-2253). Route compat binary console output through NonBlockingConsole, which queues lines (bounded) for a background thread and drops and counts lines rather than blocking. Startup lines are flushed before continuing, and output is flushed before exit. FixHungWebSocketsHack keeps its direct console write.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_012CQ12H5eAC2buLoec1L71V
Links the compat binary's NonBlockingLineWriter into Halibut.Tests and checks it keeps order, never blocks callers when the target is blocked, reports dropped lines once output resumes, times out flushes on a blocked target, and survives a throwing target.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_012CQ12H5eAC2buLoec1L71V
@CLAassistant

Copy link
Copy Markdown

CLA assistant check
Thank you for your submission! We really appreciate it. Like many open source projects, we ask that you sign our Contributor License Agreement before we can accept your contribution.
You have signed the CLA already but the status is still pending? Let us recheck it.

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.

3 participants