Pin the stress readiness probe to the native port and capture stacks when it gives up - #119891
Pin the stress readiness probe to the native port and capture stacks when it gives up#119891groeneai wants to merge 1 commit into
Conversation
…when it gives up stress_tests.lib::start_server decides whether a Stress test or Upgrade check job runs at all, and its probe passed neither --port nor --secure/--no-secure. That makes the client auto-detect its transport (programs/client/Client.cpp:651-663): it races the plain and the secure port concurrently and, when both answer, prefers TLS (src/Client/PortsProbe.cpp:196-200, "When both answered at the same time, TLS wins"). The CI config opens tcp_port_secure 9440 unconditionally, since tests/config/install.sh:209 links secure_ports.xml for every job family, so on loopback both ports answer in the same select() wake-up and the probe commits to 9440. A secure socket defers its handshake to the first send, so a server that accepts and then does not answer costs the whole handshake_timeout and surfaces as "Timeout exceeded while writing to socket", and SOCKET_TIMEOUT is deliberately not retried on the other port (Client.cpp:840-846). On the reported job 121 s of budget therefore bought exactly three probes, none of which touched the port the workload itself uses, and the failure named a port nothing else in the harness uses. The auto-detection is 08a76d4 (2026-07-12); the same author then pinned the transport in tests/clickhouse-test:7795-7805, tests/queries/shell_config.sh:42 (453e622) and ci/jobs/scripts/clickhouse_proc.py. tests/docker_scripts/ was the one server-facing harness that sweep missed: a grep for --port, --secure or --no-secure across that directory returns nothing. --port rather than --no-secure, deliberately: upgrade_runner.sh:91 installs the previous release and :138 then calls start_server, so the probe runs under the old client, and --no-secure exists only since the auto-detection commit, which is not an ancestor of the 26.6 or 26.5 branches. --port has always existed; the release the tag resolver currently selects, v26.8.3.105-lts, registers it at programs/client/Client.cpp:1211 and uses it in its own CI. 9000 is the right number: no config.d file overrides the top-level tcp_port, and wait_server_ports_free three lines up already hard-codes it. The "timeout -s KILL 15 ... --handshake_timeout_ms=10000 --receive_timeout=10" form is copied from stop_server in this same file, where that same previous-release client already runs it, and where the comment recording why the external timeout is what bounds an attempt already lives. check_server_start gets the transport pin but deliberately not the hard bound. The readiness loop waits on an unknown server state, where an unbounded attempt makes its own deadline meaningless; check_server_start runs once against a server start_server has just certified as answering SELECT 1 inside a 15 s bound (stress_runner.sh:356 then :358), so bounding it would change a currently passing path to guard a failure mode nothing has observed. The second half of the defect is that the give-up recorded a duration and nothing else. In both known occurrences the server had stopped emitting any log line at all, for 116 s and about 118 s, which the old message cannot distinguish from a slow start. The branch now samples how long ago the server last wrote to its log, dumps a listener snapshot and a bounded backtrace, and reports what it measured. Recency rather than a growth delta: in the reported job the log kept growing for about six seconds after the deadline was anchored and only then went silent, so "did it grow since the anchor?" answers yes for exactly the state the figure exists to name. The listener snapshot is a coarse observation only, because socketBindListen binds and listens inside the createServer lambda while createServers runs with start_servers false, so every client port enters LISTEN together, well before startServers reaches any of them; what it separates is a server that never got that far from one that did. Locating the stall is the backtrace's job. The backtrace is bounded at 10m rather than the 30m used by the other three sites in these scripts: the readiness give-up happens before any test has run, so the job is already a total loss and the remaining wall clock should not be spent, and a startup-time thread set is far smaller than the post-stress ones the 30m sites dump. Both figures in the message are sampled before the capture, which takes tens of seconds, so the reported duration still measures the wait rather than the diagnostics. The capture ends in ||: and the mtime sample uses a guarded form because it now runs before the failure is recorded: an unguarded version aborted the whole job under set -e and wrote no result row at all when the pipeline failed. The restart branch is untouched, so a daemon that keeps exiting reports exactly what it reported before, with no readiness claim attached. The product-side hang itself is not addressed here. In both occurrences the server stopped logging during startup and never recovered, with no core, no sanitizer report, and no shared code path between the two in their final 300 log lines, so there is nothing to root-cause from what CI captured. This change captures the stack instead of guessing at a fix. Related: ClickHouse#119868 Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Internal second-model review: adjudication log (click to expand)Pre-publication review by an independent model (engine: codex; 2 findings) plus my own cold
Severity: ❌ blocker / Session id: cron:clickhouse-review-slot-11:20260914-062800 |
|
Workflow [PR], commit [fbfd656] Summary: ❌
AI ReviewSummaryThis PR fixes the stress harness readiness check in Final VerdictStatus: ✅ Approve |
Pre-PR validation gate (click to expand)
Session id: cron:clickhouse-impl-slot-6:20260914-053700 |
CI finish ledger - fbfd656Every failure below has an owner: a fixing PR (mine or external), or a full-effort fix task
CI is finished on this head: 172 unique check-runs, 0 incomplete, This diff touches exactly one file, Session id: cron:our-pr-ci-monitor:20260914-090208 |
Related: #119868
Changelog category (leave one):
Changelog entry (a user-readable short description of the changes that goes into CHANGELOG.md):
...
Description
Stress test (amd_tsan)on #119868 produced no product signal:start_servergave up at itsreadiness deadline before the workload ran
(job);
arm_tsandid the same six days earlier(report).
No related open issue found; two harness defects, one file.
The probe measured an arbitrary transport. It passes neither
--portnor--no-secure, so theclient auto-detects: it races 9000 against 9440, prefers TLS when both answer
(
PortsProbe.cpp:196-200), and CI opens 9440 unconditionally (tests/config/install.sh:209). Allthree probes committed to
[::1]:9440and paid its full handshake timeout, which is deliberately notretried on the other port: 121 s bought 3 probes. With both ports open,
system.query_log.is_secureis 1 for 20/20 unpinned probes, 0 for 20/20 with--port; against afrozen server the unpinned probe takes 30.5 s and names
:9440, the pinned one 10.2 s and names:9000.--portrather than--no-securebecauseupgrade_runner.shcallsstart_serverunderthe previous-release client, and the auto-detection commit is not in the 26.6/26.5 line. I do not
claim this would have saved that job: the server was silent, so 9000's answer is unknowable.
The give-up recorded a duration, not a state. In both occurrences the server had stopped writing
to its log entirely (116 s and ~118 s), which the old message cannot tell from slow loading. It now
reports the probe count, how long ago the server last wrote to its log, a listener snapshot and a
bounded backtrace. Five sandboxed arms: healthy untouched; a wedged server reports
26-34 s of log silence; a listening-stopped but still-logging one 1 s; the daemon-exited branch
unchanged.
The product-side hang is not fixed here: no stack, no core, no shared code path between the two
freezes, so this captures the stack instead of guessing. The other transport-unspecified probes
(
stop_server,upgrade_runner.sh,run-fuzzer.sh,stress/stress.py) have zero measuredoccurrences.
Workflow [PR]
Sync PR [sync-upstream/pr/119891]