J110: diagnose service status query timeout under build load #312
Closed
opened 2026-11-02 15:45:25 +00:00 by kayg
·
15 comments
No Branch/Tag specified
main
j470b-server-mesh-rejoin
mesh-compat-382
j444b-d381-key-wins-flood
j461b-macos-utun-reader-thread
j475b-remove-host-motion
fix-reconnect-new-link
j481-d380
dev
j479-mesh-soak
fix/j476-host-facts
j475-motion-pill-split
j470-mac-node-join
root-upgrade-d376
j474-review-merge
latency-targets-120hz
nightly-suite-shards
gotatun-pin-j469
macos-utun-reader-thread
fix-flood-echo-stall
wip/j416
motion-fast-ease-out
mesh-addhost-j259
takeover-close-terminals-d368
kbd-instant-followups
fix-trust-key-double-click
nightly-suite-partial-report
appwin-icons-j207
rusqlite-slice1
swipe-content-first-d374
mesh-mtu-381
addhost-instant-open
glass-contrast-d365-mock
glass-contrast-d365
signout-followups-442
fix-startup-toast-red
research-gotatun-matrix-j317
themes-sync-j304
fix-load-flakes
fix-nix-zig-patch
fix-compute01-browser-baseline
ratchet-size-baseline-419
predict-auto-d130
revoke-coverage-d367
nightly-suite-queue-timeout
nightly-browser-suite
fix-rustsec-2026-0459
fonts-ioskeley-obel
log-retention-d375
fix-kbd-no-anim-427
fix-dev-red-specs-2
takeover-proof-305-j205
wip/j410-server-pump
ui-consistency-d372
fix-osc52-clipboard
libghostty-vt-1.0
forget-retired-host-d369
j404-merge-426
fix-setup-lock-race
fix-touch-select-426
revoke-access-report-ui
fix-predictive-echo-specs
fix-selinux-agent-exec
wip/j395-checkpoint2
wip/j395
j391-review-scratch
ui-consistency-j195-deferred-rebased
fix-rustc-paths-421
decisions-wording-341
fix-install-suite-red
fix-dev-rtt-specs
fix-pending-removal-align
fix-privileged-skip
fix-install-suite-404
review-j368
mesh-dns-j254
revoke-access-report-d356b
revoke-privilege-round5
fix-removal-confirm
review-j360
gotatun-rotation-367
deps-refresh-340
review-j354
review-J351
review-j350
addhost-takeover-d359
revoke-report-items-347
revoke-end-sessions-d362
review-j348
size-mesh-ssh-346
size-trim-337
revoke-access-diff-d356
j259-pre-rebase-b06c5a6
j305-ended-at-start-spec
addhost-sudo-consent
fix-layout-real-specs-411
fix-shell-open-411
fix-console-hosts-373
fix-shell-exit
fuzz-host-name-353
fix-host-details-410
macos-filter-j197
research-gotatun-tricks
revoke-p3-j216l
stale-state-pill
revoke-followups-j216k
revoke-progress-j216e
backup/macos01-20261106/lume/j197
backup/macos01-20261106/lume/appwin-icons-j207-stash0
backup/macos01-20261106/claude/stash-0
backup/macos01-20261106/claude/stash-1
backup/macos01-20261106/claude/J80-macos-s1
backup/macos01-20261106/claude/J80
backup/macos01-20261106/claude/J80-slice1-20261102
backup/macos01-20261106/claude/J16b-appwin-on-dev
backup/macos01-20261106/claude/appwin-launch-idle-146
backup/macos01-20261106/claude/J80-s1-run
wip/j259
trust-285-p3c
runtime-lock-j216f
mesh-ssh-p3-j175
tun-proof-p3b
trust-285-p3
terminal-polish-j271
tun-proof-p3
ssh-install-flakes-j216i
fuzz-fixes-j264
trust-285-a
trust-285-b
restart-oversized-fixture-j198
backup/macos01-20261106/lume/appwin-icons-j207
restart-bound-j216h
up-preflight-p3-j198
backup/macos01-20261106/lume/j251
up-preflight-j198
wip/up-preflight-j198-j245-p2
wip/up-preflight-j198-j245-p1
agent-fsync-offloop-j196
wip/up-preflight-j198-j245
settings-offscreen-j231
wip/up-preflight-j198-j226-inspection
wip/j103f
themes-j206
wip/up-preflight-j198-j226
flakes-j216c
backup/macos01-20261106/claude/j197
flakes-j216b
backup/macos01-20261106/claude/j197-red
wip/up-preflight-j198-review
flakes-j216
backup/macos01-20261106/claude/appwin-icons-j207
engineering-j208b
appwin-mock-j209
toast-stack-j165
engineering-j208
decisions-d351
decisions-d350
decisions-d349
appearance-presets-mock-j129
decisions-d348
docs-audit-spec
doc-coverage-baseline-raise
decisions-d347
decisions-d346b
decisions-d346
j88h-profile
ui-consistency-j195-deferred
ui-consistency-j195
engineering-practices-j194
preferred-login-ui-j166
signin-pools-263-j174
macos-node-265-s1
decisions-d345
decisions-d344
proxy-cgroup-j164
verify-quick-fuzz-329
proxy-start-io-j168
timing-flakes-j163
up-263-s1
mcp-events-j147
verify-quick-fuzz-j158
proxy-p3-j159
agent-resource-j157-detect
wip/j103d-final
remote-cancel-hang-j155
proxy-traefik-281-j62d
j149-verify-quick
proxy-traefik-281-j62b
j150-drop-unnamed
wip/j79d-red-r4
wip/j103d-d332
rootless-toast-j142
wip/j103d-head
wip/j103d
j125c-mcp
macos-build-j136
backup/macos01-20261106/claude/j136
wip/j79d-red-cli
wip/j79d-red-server
j121-link-liveness
j118c-tracer-failures
wip/j79c-head
release-desktop-j131
j124c-signed-macos
wip/j79c-red-p3
wip/j79c-red-p23
wip/j79c-red-p22
merge-j128-check
perf-deferred-j128
sidebar-toggle-260
j127-shortcut-changed-dot
j125-mcp
j118-tracer-failures
j126-account-summary
settings-sections-mock-j92
j120-pinch-lock
sidebar-292
backup/macos01-20261106/claude/j120
taste-2026-11-03
row-actions-242-215
backup/macos01-20261106/claude/stash-0-untracked
backup/macos01-20261106/claude/J80-265-s1-run
backup/macos01-20261106/claude/J80-macos-s1-20261102
j112-canvas-commands
ui-no-overshoot-scroll
fix-recovery-restart
backup/macos01-20261106/claude/stash-1-untracked
taste-2026-11-02
size-baseline-ratchet
machine-cards-structure-j108
j109-boot-copy-mockups
fix-dev-red
wip/up-263-s1
j95b-settings-rows
proxy-traefik-281
j95-option-rows
docs-human-j91
docs-keys-palette
fix-flood-1013-270-j38d
mesh-ssh-s1
mesh-ssh-s0
addhost-d291-tunnel
test-stability-load
mesh-relay-220
repro-296
shim-thp-off-24
mesh-pins-258-v2
mesh-dns
signin-d311-merged
docs-pages
ui-size-283
fix-ui-batch-specs
wip/j12b-edge-update
gate-on-arm
fix-rename-sync-293
trust-285-j60b
fix-focus-ring-clip
integ-ui-1101
edge-update-v2
signin-d311
taste-2026-11-01
layout-per-tab-250
ui-approved-splitopt-224
ui-approved-splitopt-224-on-dev
icon-text-centre-282
ui-approved-189-212-216
research-reverse-proxy
transfer-budget-320
review-mesh-pins-258-r2
sidebar-pill-259
review-mesh-relay-220
wip/j12-edge-update-v2
nix-package
status-crash-loop-237
fix-dev-test-failures
fix-fixture-socket-path
wip/mesh-relay-220-pre-dev-advance-rebase
fix-canvas-side-clip
research-head-to-head
frosted-real-256
review-mesh-pins-258
wip/mesh-relay-220-pre-final-rebase
review-layout-per-tab-250-r2
broad-suite-triage
nix-devshell
review-status-crash-loop-237-r3
wip/nix-devshell-pre-p3
taste-frosted-real
wip/code-serve-demo-2026-10-30
wip/code-serve-glass-2026-10-30
wip/code-serve-clusters-2026-10-30
wip/code-merge-release94-dev-2026-10-30
wip/rproxy-delta-scratch-2026-10-30
wip/stale-note-257-staged-2026-10-30
wip/d241-size-staged-2026-10-30
review-broad-suite-207
wip/mesh-pins-258-pre-split
wip/mesh-relay-220-pre-rebase
mesh-measure-220
plan-211-update
review-edge-autoupdate-r3
perf24-reconnect
review-stale-note-r2
release-prod-live
d241-shell-marker
review-mesh-pins-server-258
review-revocation-r3
review-setup-token-r2
review-sync-journal-r3
wip/review-mesh-pins-258-prune-review-1995fee46
frosted-scroll-256
sync-journal-r3
revocation-per-account-wip
review-tokio-asyncfd-0386
review-sync-p3s
wip/stash-8by64-stash0-2026-10-30
mesh-drag-r2
setup-token-data-wip
release-9-4
auth-busy-1013
mesh-view-overlap
sync-p3s
review-auth-busy-wake
review-readd-r8-wip
mesh-drag-bounds
audit-auth-93
app-windows-stream-start
review-authority-cap-r3
app-windows-r7-measure
readd-minimal-r6
readd-minimal-r5
app-windows-r7-soak
readd-minimal-r4
app-windows-r7
app-windows-r6
readd-minimal-r3
readd-minimal-r2
readd-minimal
merge-release8-dev
review-busy-page-liveness-r2
review-busy-page-liveness
mesh-view-trim
review-authority-read-retry-r2
review-remove-uninstall-r2
release-retry-reattach
release-retry
review-remove-uninstall
review-authority-read-retry
app-windows-ship
mesh-autoswitch-p2
mesh-ssh
mesh-relay
mesh-macos-node
screen-and-control
session-labels
review-real-logins-r5
review-real-logins-r4
review-real-logins-r3
shim-memory-r2
review-real-logins-r2
shim-memory
shadow-addhost-instant
shadow-real-logins
shadow-same-session-flood
shadow-prod-perf-fix
hosts-from-server
app-windows-real
app-windows-transport
release-prod-6w
mesh-policy-verify
quiet-close-toast
dev-merge-r4
review-mesh-agent-transport
review-app-windows-transport
settings-roundtrip
review-release-pipeline-r4
mesh-agent-transport
ended-strip-fix
review-audit-ca-update-d244
settings-rows
phone-width
signout-clear
fix-restart-tests
dev-merge-rp
signer-hardening
review-audit-ca-update
terminal-fidelity
review-audit-ca-update-wip
mesh-integrate
review-mesh-agent-transport-515d3712
review-mesh-dataplane-feec1988
mesh-dataplane
signout
research-canvas-node
wip/review-renderer-cost
wip/review-terminal-fidelity
padlock-glyph
review-release-pipeline-2e95b689
phone-polish
sidebar-polish
inbox-generic
review-mesh-dataplane-378d4055
prod-batch
ui-inbox
ui-ca-unlock
ui-machine-sections
review-mesh-dataplane-a5f744fb
tls-session-prod
session-bounds-prod
fix-dead-session
session-bounds
tls-session
palette-polish
shortcuts-d222
research-appmeta
phone-gutter
ui-centre-button
wip/ui-centre-button
wip/tls-session
review-addhost-breakit
ui-platform
renderer-cost
remote-agents
mesh-api
ssh-bootstrap
prod-hotfix2
prod-fixes
review-remote-agents
review-mesh-dataplane
session-life
research-browser
review-mesh-api
research-capture
review-mesh-api-round3
review-mesh-api-round1
gate-stability
review-gate-stability
review-relay-direct
review-mesh-api-findings
proto-sessions
font-picker
proto-addhost
proto-windows
mesh-core
latency-gate
research-bsd
research-discovery
keytray-mods
mock-core
ui-tweaks
fix-motion-sel
fix-motion
integrate2
fix-robust
t-web
t-server
vt-ghostty
fix-snap-echo
t-web-auth
review-vt2
t-agent
lane-protocol
lane-shim
lane-auth
s1-base
s1-contracts
s1-workspace
No results found.
No labels
launch-qa
Milestone
Clear milestone
No items
No milestone
Projects
Clear projects
No items
No project
Assignees
Clear assignees
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".
No due date set.
Dependencies
No dependencies set
Reference
kayg/infraternal#312
Loading…
Reference in a new issue
No description provided.
Delete branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Investigate status_restart::service_states_are_truthful_in_text_and_json failing under load with service manager query timed out. Reproduce 20 times before and after under synthetic CPU load; fix the root cause without weakening assertions; run scripts/verify fast, push the job branch and record evidence.
starting J110 on fix/j110-service-status-timeout, base
294042b56d. plan (90 minutes): inspect query/test deadlines and capture 20 baseline runs under synthetic CPU load on compute01; add a regression and fix the responsible bound; repeat identical 20-run load sweep; run scripts/verify fast on the emptier VM; commit, push and report raw gate and size evidence. both queues checked: compute01 has 2 free slots, dev-02 has queued work, so baseline goes to compute01.code tracing: the production query and worker-admission deadlines are both 40 ms (infraternal-status/src/lib.rs); the CLI matrix has no test timeout. original delayed fixture sleeps 25 ms inside that product budget. first exploratory build used --no-default-features, which omits component labels and fails for that unrelated reason; those 20 exploratory results are invalid as timeout evidence and are excluded. rebuilding with the normal production feature set before collecting the baseline. proposed regression retains every existing matrix row and adds 75 ms responsive restarting and fresh-active responses (including two observations).
independent evidence: compute01 ~/worktrees/j108-verify.log lines 1835-1848 show agent/host Unknown with service manager query timed out, and the CLI regression failing after 1.52 s. This is a production status query failure, not a test-side timer. The existing implementation already wakes on owned-child exit; raising its finite deadline need not add a wait to fast responses. Keep the two observations on one deadline and four workers with independent system/user capacity. Normal-feature baseline build is still compiling dependencies; evidence stays in ~/worktrees/j110-before-full.log.
valid baseline complete, normal default features at
294042b56, unchanged CLI matrix: 4/20 pass, 16/20 fail under 20 CPU-burn processes, 10 cores, nice 10, load 21.08 to 27.53. 15 failure logs explicitly contain service manager query timed out (checking the remaining diagnostic). A separate 100-sample launch of the same 25 ms shell response under the same load measured completion p50 40.009 ms, p95 69.588 ms, p99 78.521 ms, max 86.163 ms; 51/100 exceeded 40 ms. This measures scheduling robustness on the build VM, not a latency benchmark. Proposed product bound: 500 ms shared by both observations of a unit; admission also 500 ms, retaining four workers, independent scopes and child kill/reap. This gives >2x margin over two measured worst responses, with no sampling delay for fast queries. Original test executable preserved for the identical post-fix sweep. Raw logs: compute01 ~/worktrees/j110-evidence/before-full/, sweep driver ~/worktrees/j110-load.py, full build/sweep ~/worktrees/j110-before-full.log. Running the expanded test against the unchanged product next, then measuring baseline static images for an exact D243 delta.baseline failure breakdown: 15/20 query timeouts, 1/20 service query capacity exhausted (the separate 40 ms admission window), 4/20 pass. The new 75 ms regression fails against the unmodified product with Unknown/service manager query timed out, RED_EXIT=101 (compute01 ~/worktrees/j110-red.log). Both deadlines need the same loaded-host bound. Product change is now local: one shared 500 ms duration for admission and each unit, unchanged polling/observations/workers/cleanup. Baseline static images are building before syncing that change.
crash-safety checkpoint pushed:
eff6e948don fix/j110-service-status-timeout (WIP, not ready). Product bound and stronger matrix are committed; baseline static images still build on compute01 in ~/worktrees/j110/target (the only target for this job). Final regression now includes a 300 ms response above half the 500 ms budget, the retained 25 ms case, and two 75 ms fresh-active observations. Recent timestamps are refreshed per case to keep fixture semantics under slow scheduling. Next: finish baseline sizes, run red once more, sync the product change, green plus identical 20-run load sweep, final fast gate and paired perf-VM response measurements. Raw logs and baseline failure counts are in earlier comments. Estimate remains within the original 90-minute plan.baseline static builds completed successfully: x86_64 22,419,344 B, aarch64 20,454,176 B (exact
294042b56product sources). Final strengthened matrix red run still fails with service manager query timed out, RED_EXIT=101; ~/worktrees/j110-red-final.log. Both queues checked again: compute01 had a free slot; dev-02 was full with three queued runs. Fixed validation now owns that compute01 slot: fmt, CLI matrix, full infraternal-status suite, original unchanged matrix x20 under identical 20-process CPU load, then scripts/verify fast. Logs: ~/worktrees/j110-{green,after,fast,fixed}.log. Same target ~/worktrees/j110/target, no extra target dirs.fixed functional validation: strengthened CLI matrix passes; the full infraternal-status suite passes (GREEN_EXIT=0). Identical original CLI matrix under the same 20 CPU workers/nice 10: AFTER 20/20 pass, 0/20 fail; BEFORE 4/20 pass, 16/20 fail (15 manager timeouts, one admission expiry). After logs ~/worktrees/j110-after.log and ~/worktrees/j110-evidence/after/. Initial full gate stopped before tests because the rsynced source tree lacked git metadata required by scripts/verify.d/evidence-size.py. Establishing local git metadata pointing at the pushed job branch, then rerunning the full gate. This was a checkout setup failure, not a product/test failure.
second crash-safety checkpoint:
77c9af581(same product change, rustfmt layout included). Functional proof is green: original matrix AFTER 20/20 passed under 20 CPU workers, BEFORE 4/20 passed; full status crate 35 passed plus its existing opt-in ignored real-service test. Full scripts/verify fast is running on compute01; CLI plugin compile-out passed, now at clippy. Gate log ~/worktrees/j110-fast.log; target remains ~/worktrees/j110/target. Final static deltas and pinned-perf latency receipts follow the full gate. No additional scope or library changes.checkpoint (source unchanged at
77c9af581, pushed): full workspace tests, SSH inode-reuse and opt-in shim checks have completed; full gate is now rebuilding static images. Fixed x86_64 image is 22,419,344 B, exactly the294042b56baseline (delta 0 B). ARM image and frontend rows remain in progress. Pinned-perf paired measurement is running on perf-01 through perf-run using the saved baseline and rebuilt x86 static images. Gate ~/worktrees/j110-fast.log on compute01; perf ~/worktrees/j110-perf.log on perf-01. One target, compute01 ~/worktrees/j110/target, will be removed after the final receipt.full gate attempt 1 completed with VERIFY_EXIT=1: every Rust row passed EXCEPT workspace test, which had exactly one failure: infraternal-plugin-ssh --test install, earlier_control_socket_receipt_recovers_before_a_new_setup (install.rs:3180), synthetic remote exit 75. The target status regression passed within that gate. No SSH files or dependencies changed in J110 (diff is only status/src/lib.rs and CLI status_restart.rs). Both final static images match the exact
294042b56baselines: x86_64 22,419,344 B (delta 0), aarch64 20,454,176 B (delta 0). Raw failed gate ~/worktrees/j110-fast.log will be preserved before rerunning. Checking the isolated SSH failure against pinned-base sources next, then rerunning the full gate; no unrelated code fix is being added. Pinned-perf passed: healthy paired median delta -0.011632 ms, 95% CI [-0.054388, +0.043331]; restarting +0.0056105 ms [-0.0422245, +0.03229]. Stalled manager p50 42.994885 -> 503.605979 ms. perf-run exit 0, steal 0; ~/worktrees/j110-perf.log and ~/worktrees/j110-perf-run/ on perf-01.validation extension: the first full gate finished red only on the unchanged SSH receipt-recovery test (synthetic exit 75); both static builds were green with zero J110 byte growth. A pinned-base install-suite check plus full unchanged gate retry are queued on compute01, currently position 4; both VMs were full. Scope remains the original two status files. The initial 90-minute estimate now needs queue/retry time, roughly another 20 minutes if a slot opens soon; this is below the brief’s 2x stop threshold. All implementation and evidence are pushed at
77c9af581. No SSH fix is being added. Logs: ~/worktrees/j110-retry.log, ~/worktrees/j110-ssh-baseline.log, preserved first gate ~/worktrees/j110-fast-attempt1.log.pinned-base evidence: BASE_TREE_DIFF_EXIT=0 against
294042b56; standalone install-suite build succeeded. Base install run 1 passed; run 2 failed negotiated_retry_reuses_only_a_verified_cache_after_activation_refusal with SetupRunning/exit 73 at install.rs (93 passed, 1 failed, 2 ignored). This is a DIFFERENT SSH failure from the first J110 gate’s earlier_control_socket_receipt_recovers_before_a_new_setup/exit 75; that original test passed in both baseline runs. No claim that the exact first failure reproduced on base. Raw evidence ~/worktrees/j110-ssh-baseline.log and ~/worktrees/j110-ssh-baseline-run-{1,2}.log; empty ~/worktrees/j110-baseline-source.diff proves base source identity. Fixed status files and original mtimes restored; full gate retry is now running with the same default test parallelism. SSH source/dependency files remain unchanged.finished J110
branch:
fix/j110-service-status-timeoutbase:
294042b56daac3d4ab2289508b7f8a6ddb0b24a4head (pushed):
70dbd99057e275732b61ee081a9b863f413b0629root cause: production query AND worker-admission deadlines were 40 ms. the CLI test has no separate deadline. twenty runnable CPU workers on the 10-core compute VM delayed 25 ms manager fixtures to p99 78.521 ms / max 86.163 ms; 51/100 exceeded 40 ms. use a shared 500 ms duration for admission and each unit, including both observations. child-exit readiness, four workers, independent scopes and kill/reap are unchanged. admission plus the final admitted unit give a nominal one-second manager-work bound.
all original assertions and the 25 ms case remain. new cases exercise a 300 ms response above half the budget and two 75 ms fresh-active observations. recent fixture timestamps refresh per case so the matrix still tests recent starts under slow scheduling. the strengthened test failed before the fix and passes after it.
load proof, same ORIGINAL matrix executable and same 20-worker/nice-10 synthetic load on compute01:
~/worktrees/j110-{before-full,after}.log; per-run output:~/worktrees/j110-evidence/{before-full,after}/; reproducer:~/worktrees/j110-load.py.focused status suite: 35 passed, one existing opt-in real-service test ignored. strengthened CLI matrix passed too.
pinned perf VM, perf-run (cpus 1–3, 6 GB, steal 0, exit 0), 5 x 50 paired samples/image for responsive paths:
~/worktrees/j110-perf/samples.json, harness~/worktrees/j110-perf.py, receipt~/worktrees/j110-perf.log, state snapshots~/worktrees/j110-perf-run/.D243, exact baseline
294042b56versus final source:first full gate hit unchanged SSH test
earlier_control_socket_receipt_recovers_before_a_new_setup, synthetic exit 75. on unmodified294042b56sources (BASE_TREE_DIFF_EXIT=0), install suite run 1 passed and run 2 failed a DIFFERENT test,negotiated_retry_reuses_only_a_verified_cache_after_activation_refusal, SetupRunning/exit 73. the original control-socket test passed both base runs; no claim that its exact failure reproduced on base. SSH source/dependencies were not changed. the full gate retry used unchanged default test parallelism and passed, including 94/94 non-ignored SSH installation tests. earlier failure and base logs are preserved as~/worktrees/j110-fast-attempt1.log,~/worktrees/j110-ssh-baseline.log, and~/worktrees/j110-ssh-baseline-run-{1,2}.log.final
scripts/verify fastran on compute01 through build-slot, CARGO_BUILD_JOBS=4, default test parallelism. final source hashes match the local committed tree. no owned test processes remain; the job target directory was removed. logs and small artifacts remain. no blockers or owner decision needed. issue remains open for review.full gate output verbatim (including exit receipt):
J210 owner-authorized housekeeping: closing this completed scope because its work is merged on dev in 78c1d88a5. Verified the merge commit is an ancestor of current origin/dev. The implementation reports and evidence remain in this issue.