Repository navigation
Plain sockets: a send cut short by the send timeout ends the write; TestClientStalledReader measures the session's end - #377
Merged
Conversation
Old: client A asked for OVER/XOVER 1-40000 (served from the fake upstream, which runs in the race-instrumented test process) and stopped reading; after 2 s client B's GROUP and ARTICLE 39999 had to be answered within 20 s. Nothing checked when A's session ended. Since #274 writes the records with the group's lock released, B is served even when A's session stays blocked in send() for good, so the test no longer saw what 3cefac9 (ClientTimeout for each write) and 763126c (drop the buffer after a failed send) fixed. New, as #369 did for the TLS test: a first client fills the cache, so A's reply comes from the spool and its socket fills at once; A's session pid is the daemon's only child, and a goroutine records when it is gone, measured from just before A's request (it reads /proc/<pid>/task/<pid>/children itself, no t.Fatal from the goroutine, and stops with the test). The session must be gone within 1.5 ClientTimeouts (4.5 s); in a file-log build "can't be written to, session ended" must be logged. B's part is unchanged. Needs /proc or the log file, like the TLS test. Measured (12 cores, ClientTimeout 3): the session ended 3.04-3.10 s after the request (5 runs x OVER/XOVER), 3.27-3.37 s with -race; all pass. Mutants (scratch only): 1. 763126c reverted (sockstream.cc: the buffer kept after a failed send): the new test fails, OVER and XOVER: stalled reader's session 2064767 ended 6.035s after the request, want within 4.5s 2. no SO_SNDTIMEO on the client's output (set_socket_timeouts, the core of 3cefac9): the new test fails: stalled reader's session 2065805 still running 14.501s after the request, want it gone within 4.5s The test from origin/main passes against both mutants. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Without /proc the test fell back to the log line "can't be written to, session ended", which is logged at the first failed write, not when the session ends: with 763126c reverted it comes 3 s before the end, so the bound wasn't checked there (Terra's finding). The session end now always comes from the daemon's children, through daemonChildren (/proc, or pgrep -P, from #369); the log line stays as a check of why the session ended. The test skips only where neither /proc nor pgrep exists. With /proc hidden (scratch change): main 3.10-3.14 s, pass; 763126c reverted 6.14-6.16 s, fails. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
When SO_SNDTIMEO runs out after send() has taken part of the data, FreeBSD returns that part instead of EAGAIN (kern_sendit turns EWOULDBLOCK into a short count). sync() took the short count for progress and sent the rest, which waited for a second timeout: the session of a client that stopped reading ended after two ClientTimeouts. FreeBSD CI showed it with the new TestClientStalledReader: 6.088 s (OVER) and 6.044 s (XOVER) with ClientTimeout 3, bound 4.5 s. A blocking send returns short only when it was cut off, by a signal or by the timeout. When it has waited for the socket's whole send timeout (read with getsockopt, since a client's is set on its socket, not through set_io_timeout), the rest is dropped and the write fails, as after a failed send. A short count after a shorter wait (a signal) still goes on. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…eout Terra's review of 21e5d48: the 90 % check guessed from the elapsed time whether the timeout or a signal cut the send short, and t0 was taken before the EINTR retries. Now a short send waits until the socket can take more for what is left of the send timeout (poll), from the start of the send call that returned short: nothing left or still full ends the write, so a signal never ends it early and the timeout never runs twice. Not during a reply deadline (non-blocking socket, short counts at once): that path is unchanged. Linux returns short counts at the timeout too (1774 of 4096 bytes after 1 s, then EAGAIN after another second), so cReplyBudget gets a check: loopback TCP with a small window, SO_SNDTIMEO 1 s, a peer that reads nothing; the write must fail within 1.5 s. main's sockstream: 2.06-2.07 s, fails 3/3; with this: 1.00-1.06 s. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
On a failed socket() or connect() it went on to accept(), which waits for good with no peer coming (Terra's review). Now it reports the failure and returns; a failed accept() too. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Bug found by the new test, fixed here (21e5d48, reworked in fa0d23f):
with the session's end now measured without /proc too, FreeBSD CI failed:
OVER 6.088 s, XOVER 6.044 s after the request, bound 4.5 s (ClientTimeout
3): two send timeouts. When SO_SNDTIMEO runs out after send() has taken
part of the data, the kernel returns that part instead of EAGAIN (FreeBSD
and Linux alike: on Linux 1774 of 4096 bytes after 1 s, then EAGAIN after
another second), and
sockstreambuf::sync()sent the rest with a secondwait. Now, after a short send, the rest goes out only if the socket
becomes writable (poll) within what is left of the socket's send timeout,
counted from the start of the send call that returned short (read with
getsockopt: a client's is set on its socket, not through set_io_timeout);
otherwise the write fails like a failed send. A short count from a signal
therefore never ends the write early, and the timeout never runs twice.
Not during a reply deadline (non-blocking socket): unchanged. (21e5d48
used a 90 %-of-the-timeout guess instead; Terra pointed out that it
could cut a write short after a late signal and counted EINTR retries.)
New check in cReplyBudget: loopback TCP with a small window, SO_SNDTIMEO
1 s, a peer that reads nothing; the write must fail within 1.5 s.
main's sockstream: 2.06-2.07 s, FAIL 3/3; with the fix 1.00-1.06 s, pass.
Linux: the stall/timeout e2e tests pass; full suite passed on 21e5d48,
running again on fa0d23f. FreeBSD CI must now pass.
Old: client A asked for OVER/XOVER 1-40000 (served from the fake
upstream, which runs in the race-instrumented test process) and stopped
reading; after 2 s client B's GROUP and ARTICLE 39999 had to be
answered within 20 s. Nothing checked when A's session ended. Since
#274 writes the records with the group's lock released, B is served
even when A's session stays blocked in send() for good, so the test no
longer saw what 3cefac9 (ClientTimeout for each write) and 763126c
(drop the buffer after a failed send) fixed.
New, as #369 did for the TLS test: a first client fills the cache, so
A's reply comes from the spool and its socket fills at once; A's
session pid is the daemon's only child, and a goroutine records when
it is gone, measured from just before A's request (through
daemonChildren from #369: /proc, or pgrep -P without /proc; no t.Fatal
from the goroutine, and it stops with the test). The session must be
gone within 1.5 ClientTimeouts (4.5 s); in a file-log build "can't be
written to, session ended" must be logged too, as a check of why it
ended (not of when: that line comes at the first failed write, 3 s
before the end with 763126c reverted). B's part is unchanged. Skips only
where neither /proc nor pgrep exists.
Measured (12 cores, ClientTimeout 3): the session ended 3.04-3.10 s
after the request (5 runs x OVER/XOVER), 3.27-3.37 s with -race; all
pass.
Mutants (scratch only):
send): the new test fails, OVER and XOVER:
stalled reader's session 2064767 ended 6.035s after the request,
want within 4.5s
core of 3cefac9): the new test fails:
stalled reader's session 2065805 still running 14.501s after the
request, want it gone within 4.5s
The test from origin/main passes against both mutants.
Without /proc (scratch change hiding it, pgrep path): main 3.10-3.14 s,
pass; 763126c reverted 6.14-6.16 s, fails. (An earlier head used the
log line as the end without /proc, which didn't check the bound there:
Terra's finding.)
Part of the review of weakened tests that go-while asked for. Shown to fail with the guarded defect (scratch mutant; not committed).
NEWS:
changes/fix-stalled-reader-test-from-spool.md.🤖 Generated with Claude Code