From 8e66d463ea449d83de077d76a8801dcb7f2c04df Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Sun, 4 Oct 2026 23:59:29 +0000 Subject: [PATCH] docs(buglog): bug-1914, bug-1917, bug-1918 fixed; refresh STATUS.md Co-Authored-By: Claude Opus 5.5 (1M context) --- .wolf/STATUS.md | 22 ++++++++++++++-------- .wolf/buglog.json | 42 ++++++++++++++++++++++++------------------ .wolf/bugs/bug-1914.md | 19 +++++++++++-------- .wolf/bugs/bug-1917.md | 17 +++++++++-------- .wolf/bugs/bug-1918.md | 17 +++++++++-------- 5 files changed, 67 insertions(+), 50 deletions(-) diff --git a/.wolf/STATUS.md b/.wolf/STATUS.md index 2846c356..37b3090d 100644 --- a/.wolf/STATUS.md +++ b/.wolf/STATUS.md @@ -5,12 +5,18 @@ --- -## ✅ Done (2026-10-01/02, all pushed) +## ✅ Done (2026-10-03/04) -- **job-array-one-based-index** (spec, 30/30 tasks, validate-impl GO): job arrays numbered 1..N (LSF `name[1-N]`), `[k]` / `[a-b]` selections in REST, xcecli and the harness, `XCE_JOBINDEX`, `E_XCE_ARRAY_START0`; docs in `src/docs/xce.md` "Job arrays". Closed bug-1896. -- **Every open bug closed** (`buglog.py list --open` is empty): fixed bug-1736 (LSF CPU peak/efficiency fields, `6df644e6`), 1880 (pre-bug-1888 capture), 1892, 1897, 1898 (restart path `c73708b8`), 1899–1908, 1437 (librtti re-pin `8c7d26a9`, record updated); bug-1856 wontfix (upstream OpenWolf hook; `auto_detect=false` survives `openwolf update`). -- Spec metadata and roadmap synced (`84a93a01`); Gitea #89, #331, #335 closed. -- Group-3 follow-ups (`3615c7c0`..`c15580a7`): gofmt on 29 frontend files; unused job-ID regex macros removed from `config.h`; `TestLoadJobs` runs only with `XCE_LOAD_TEST_URL`; peek resolves `[k]` on the server and restart takes written job IDs (`c-a-ts-seq[k]`) in xcecli and REST. +- **HA fixes, committed + pushed** (`88a8bf8a`..`e27bc2ed`, Gitea #338-#340 closed): + - bug-1915: a PreVote round is decided once; a leader promotes only with its own election's votes; `raft_on_leader_lost` keeps `voted_for`. + - bug-1919: the promotion fence releases once a node that booted RECOVER_TRUNCATED has caught up (runtime `recovery_truncation_healed` latch; the re-check re-arms). + - bug-1920: replicated WAL writes are refused before this boot's `persist_recover` (they truncated and misfiled `seg-...0001`, stalling catch-up); catch-up streams from min(join position, standby report). + - Soaks on that code: sequential 4x20 + 50, chaotic 50, loaded 30 (40 spinners on 32 cores) -- all PASS, WAL segment layout clean on every node. +- **bug-1914, bug-1917, bug-1918 fixed, committed + pushed:** + - bug-1918: `INVOKE_MSG_HANDLER` no longer drops a refused packet (leak). + - bug-1917: `xce_ctx_reconnect` quiesces the old endpoint (unmonitor, clear owner, drain refs, 2 s bound) before re-init. + - bug-1914: config-push barrier 500 -> 2000 ms under the commit-wait admission reservation; honest timeout reply. + - Verification: 127/127 suites; 80/80 live HA config pushes under 40 spinners; loaded seq-30 soak PASS, no ASAN. --- @@ -20,8 +26,8 @@ ### Open items (not yet actioned) - **Checks needing a host with systemd/dbus** (this container has none): a running array element prints the right `XCE_JOBINDEX`; bug-1908's kept signal reaches a real (non-virtual) worker over IPC at RUNNING. -- **Exposing bug-1736's peak/efficiency fields in the apiserver/xcecli** (decision pending): the computed `run_usage` never reaches the apiserver -- the capnp `Job` pushed on job updates has no `run_usage`, and the only usage notify (`schedJobRusages`) is the raw worker report, which the apiserver ignores. Needs a wire change (add `run_usage` to `Job`, or a new notify event) plus a cgo handler, store update and xcecli display: spec-sized (`/kiro-spec-quick`), or drop it -- nothing consumes the fields yet. -- **Specs awaiting the next phase:** design review -- `controller-peers-env-fallback`, `xce-node-manager`; requirements written -- `job-status-detail-display`, `scheduler-preemption`, `scheduler-sim-decision-trace`; initialized -- `commit-batch-window`, `resource-distribution-mapping`; brief -- `component-rejoin-resync`. +- **Exposing bug-1736's peak/efficiency fields in the apiserver/xcecli** (decision pending): needs a wire change (`run_usage` on `Job`, or a new notify event) plus cgo handler, store update and xcecli display -- spec-sized (`/kiro-spec-quick`), or drop it; nothing consumes the fields yet. +- **Specs awaiting the next phase:** design review -- `xce-node-manager`; requirements written -- `job-status-detail-display`, `scheduler-preemption`, `scheduler-sim-decision-trace`; initialized -- `commit-batch-window`, `resource-distribution-mapping`; brief -- `component-rejoin-resync`. - **Roadmap backlog (briefs only):** application-profile → job-sandbox-execution → job-sandbox-multinode; job-time-window → job-dependency → job-dependency-insight; rbac-persistence; scheduler-alter-pend-reasons; controller-job-cleanup. ### Files to create / edit @@ -29,7 +35,7 @@ ### Open decisions - **REST job output for jobs with a custom `out_file`/`err_file`**: the worker never writes those paths (always `/tmp/job__task.out`), so since bug-1508 `GET /jobs/:id/output` for such a job returns a permission error from the worker. Either the apiserver's `resolveOutputPath()` (controllers/output.go) always targets the worker's own output file, or the worker starts honouring `out_file`. Waiting on the user. -- **Bug records not mirrored to Gitea:** ~400 older records plus bug-1885–bug-1908. A sync without `--since`/`--ids` would create an issue for each. Default: leave them off Gitea. +- **Bug records not mirrored to Gitea:** ~400 older records plus bug-1885–bug-1908 (bug-1914/1915/1917-1920 are mirrored). A sync without `--since`/`--ids` would create an issue for each. Default: leave them off Gitea. --- diff --git a/.wolf/buglog.json b/.wolf/buglog.json index d501ef6b..2a350f26 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -17154,9 +17154,9 @@ }, { "id": "bug-1914", - "status": "open", - "status_updated": "2026-10-03", - "status_note": "newly logged", + "status": "fixed", + "status_updated": "2026-10-04", + "status_note": "", "component": "controller", "severity": "wrong-result", "timestamp": "2026-10-03T15:07:26Z", @@ -17164,8 +17164,8 @@ "occurrences": 1, "error_message": "config push fails -110 under heavy CPU load: commit lands just after the 500 ms barrier\n\n**Observed:**\n```\nError: controller returned status -110\n```\n`xceadmin config push` to a healthy, normally elected HA primary (standbys promoted from the vote connections, own-term no-op already committed) was rejected with -ETIMEDOUT: the config marker's majority commit landed ~75 ms after the `repl_wait_majority_ack(..., CONF_PUSH_TIMEOUT_MS)` barrier (`config_repl.c` ~1658; `CONF_PUSH_TIMEOUT_MS` = 500, `config_repl.h:33`) expired. Seen only with the CPU heavily oversubscribed (40 busy loops on 32 cores).\n\n**Expected:** a push to a healthy primary with a reachable majority succeeds under load, or the barrier is sized/structured so normal scheduling delay cannot turn a soon-to-commit marker into a rejection. (A commit that lands after the client was told -110 also leaves the outcome ambiguous to the client: rejected per the reply, yet committed later.)\n**Impact:** spurious push failures under heavy load (fail-loud, no data loss). If the marker then commits after the -110 reply, the client believes the push failed while the cluster activated it -- a retry is idempotent per tag, but the reply is misleading. Check before changing: whether the late commit is actually applied after the -110 reply, and the async-I/O rules for the commit-wait barrier (`COMMIT_WAIT_RESERVED`, `.kiro/steering/ha-async-io.md`).\n**Found by:** test (bug-1485 investigation, 2026-10-03)", "file": "src/controller/config_repl.c, src/controller/config_repl.h", - "root_cause": "TODO: required for fixed/partial", - "fix": "TODO: required for fixed/partial\n\nVerification:\n- Test: TODO: name + file; RED before the fix, GREEN after\n- Suites: TODO: suite results and build profile\n- Live: TODO: soak/deploy run, or n/a and why", + "root_cause": "`config_commit_change` appends the `WAL_CONFIG_MARKER` first and then waits for the out-of-band byte-delivery quorum (`repl_wait_majority_ack(..., CONF_PUSH_TIMEOUT_MS)`, configAck branch). `CONF_PUSH_TIMEOUT_MS` was 500 ms, which is below ordinary scheduling delay on an oversubscribed host: with 40 busy loops on 32 cores a standby's ACK arrived ~575 ms in, so the push was rejected with -ETIMEDOUT although the majority was healthy. The marker, already in the log, still committed and activated, so the client was told the push failed for a change the cluster applied (the reply text even said \"upgrade not committed\"). The configAck wait was also a raw condition wait on a vtask outside the commit-wait admission reservation that ha-async-io.md requires for bounded blocking there.", + "fix": "- `CONF_PUSH_TIMEOUT_MS` 500 -> 2000 ms (src/controller/config_repl.h).\n- The configAck wait in `repl_wait_majority_ack` now holds a commit-wait admission slot for its duration (new `commit_blocking_admit`/`commit_blocking_release` in commit.c, the same budget `commit_submit` WAIT uses); a full budget rejects fast with -XCE_ERR_NOT_READY, so the longer bound can never take workers reserved for liveness traffic.\n- The timeout reply no longer claims \"upgrade not committed\": it says the change was not confirmed on a majority, may still activate if it was already ordered in the log, and should be re-pushed to confirm.\n\nVerification:\n- Test: `test_configack_late_ack_under_load_meets_barrier` (src/controller/testsuite/test_commit_barrier_rollout.c): a config ACK arriving 700 ms in must meet the production bound, and the wait must hold one admission slot (released afterwards). RED before the fix (-110 at 500 ms), GREEN after.\n- Suites: `xce-build.sh all` asan, 127/127 meson suites OK, Go tests ok (2026-10-04).\n- Live: `test_live_config_push_against_primary_reaches_success_path` looped 80 times under 40 busy loops on 32 cores, 2026-10-04: 80/80 passed, no -110 (before the fix: 1/70 failed with -110 under the same load).", "tags": [ "ha", "config-push", @@ -17176,7 +17176,9 @@ "bug-1485", "bug-1913" ], - "fix_commits": [], + "fix_commits": [ + "06e99b90" + ], "record": ".wolf/bugs/bug-1914.md" }, { @@ -17241,9 +17243,9 @@ }, { "id": "bug-1917", - "status": "investigating", - "status_updated": "2026-10-03", - "status_note": "code-review finding from bug-1916; watch loaded soaks for reconnect stacks without free_packet", + "status": "fixed", + "status_updated": "2026-10-04", + "status_note": "", "component": "lib", "severity": "crash", "timestamp": "2026-10-03T22:55:30Z", @@ -17251,8 +17253,8 @@ "occurrences": 1, "error_message": "xce_ctx_reconnect re-inits the endpoint on the caller thread while the io_worker may still use it\n\n**Observed:**\nNot yet observed as a crash -- found by code review while fixing bug-1916. `xce_ctx_reconnect` (src/lib/xcectx.c ~366) calls `endpoint_fini` / `endpoint_init` on the client's caller thread for an endpoint embedded in the context, while the io_worker may still be dispatching the same endpoint (still monitored). Exposed operations: the io_worker's post-handler store into `ep->fsm_in.pkt` and `endpoint_unref` (harmless after the bug-1916 fix), a concurrent `SSL_read` / `handle_error` on the old fd/SSL against `SSL_free` / `close`, and `fsm_out.pkt` freed while `handle_output` is writing it. `vtask_entry` also reads `ep->owner` without a lock while reconnect rewrites it.\n\n**Expected:** reconnect first unmonitors the old endpoint and waits for the io_worker to finish any in-flight dispatch on it (quiesce), then tears it down, as the controller side does with deferred per-endpoint teardown (bug-1839).\n**Impact:** potential use-after-free / crash in OpenSSL or `handle_output` stacks under `xce_ctx_reconnect` during client failover (worker, scheduler, xce_test, apiserver backend), most likely under heavy CPU load, like bug-1916.\n**Found by:** review (bug-1916 fix, 2026-10-03)\n\nUPDATE (2026-10-03): Review of the bug-1916 fix (2026-10-03) adds a second hazard: a reply task from the OLD connection still queued when xce_ctx_reconnect re-arms ep->owner can run against the NEW session (ep->owner read unsynchronised in xcectx.c vtask_entry ~134-135).", "file": "src/lib/xcectx.c, src/lib/netio.c", - "root_cause": "TODO: required for fixed/partial", - "fix": "TODO: required for fixed/partial\n\nVerification:\n- Test: TODO: name + file; RED before the fix, GREEN after\n- Suites: TODO: suite results and build profile\n- Live: TODO: soak/deploy run, or n/a and why", + "root_cause": "`xce_ctx_reconnect` (src/lib/xcectx.c) ran `endpoint_fini`/`endpoint_init` on `ctx->ep` straight away, while work dispatched for the old connection could still be running: the io_worker inside its epoll batch (it holds an endpoint reference for the whole batch: `SSL_read`/`handle_output` on the fd and SSL being freed), and VTASK_IO reply tasks still queued on the context's pool (each holds a reference and reads `ep->owner` without a lock). A queued reply task of the old connection that ran after the reconnect found `ep->owner` re-armed to the context and was delivered to the new session.", + "fix": "`xce_ctx_reconnect` first calls `xce_ctx_quiesce_ep`: unmonitor the old fd (no further io_worker events), clear `ep->owner` under `ep->lock` (stale reply tasks are dropped; `vtask_entry` frees their packet), then wait until the endpoint's reference count is back at its base value (0 for the embedded client endpoint, 1 for a heap one), polling every 1 ms. The wait is bounded at 2000 ms: if the caller is itself a task of this endpoint its own reference never drains, and the reconnect then proceeds as before with a WARN (\"reconnecting anyway\") rather than deadlocking. `vtask_entry` now reads `ep->owner` under `ep->lock`.\n\nVerification:\n- Test: `test_reconnect_drains_old_connection_tasks` (new src/lib/testsuite/test_ctx_reconnect_quiesce.c): reconnect to a local listener, queue an old-connection packet via INVOKE_MSG_HANDLER -> handle_msg with the pool stopped, reconnect again while a helper starts the pool 100 ms in. RED before the fix (the stale task reached the context's request handler: expected 0 calls, was 1), GREEN and LSan-clean after.\n- Suites: `xce-build.sh all` asan, 127/127 meson suites OK, Go tests ok (2026-10-04).\n- Live: loaded `/xce-test-ha` sequential 30 rounds (40 busy loops on 32 cores), 2026-10-04: PASS, zero job loss, all 3 nodes led, no ASAN report in any controller/worker/scheduler log; client failover reconnects in worker/scheduler/xce_test throughout, and the quiesce never needed its timeout (no \"reconnecting anyway\" WARN).", "tags": [ "race", "failover", @@ -17262,14 +17264,16 @@ "related_bugs": [ "bug-1916" ], - "fix_commits": [], + "fix_commits": [ + "431a6d70" + ], "record": ".wolf/bugs/bug-1917.md" }, { "id": "bug-1918", - "status": "open", - "status_updated": "2026-10-03", - "status_note": "newly logged", + "status": "fixed", + "status_updated": "2026-10-04", + "status_note": "", "component": "lib", "severity": "leak", "timestamp": "2026-10-03T23:04:08Z", @@ -17277,8 +17281,8 @@ "occurrences": 1, "error_message": "handle_msg / vtask_handle_msg early -EINVAL/-ENOMEM exits leak the received packet\n\n**Observed:**\nNot yet observed at runtime -- found reviewing the bug-1916 fix. When `handle_msg` (src/lib/xcectx.c ~196-198, src/controller/cluster.c ~1371-1373) or `vtask_handle_msg` (src/lib/vtaskmgr.c ~617-629) returns early with -EINVAL/-ENOMEM, the received packet is still in `ep->fsm_in.pkt`; `INVOKE_MSG_HANDLER` (src/include/netio.h:148-158) then stores NULL into the slot without freeing it, so the packet leaks.\n\n**Expected:** on every early exit the packet is freed exactly once (either the handler frees it, or the slot keeps it and the endpoint teardown frees it).\n**Impact:** small per-message leak on rare error paths (allocation failure, missing context); pre-existing, not a crash.\n**Found by:** review (bug-1916 fix, 2026-10-03)", "file": "src/lib/xcectx.c, src/lib/vtaskmgr.c, src/controller/cluster.c", - "root_cause": "TODO: required for fixed/partial", - "fix": "TODO: required for fixed/partial\n\nVerification:\n- Test: TODO: name + file; RED before the fix, GREEN after\n- Suites: TODO: suite results and build profile\n- Live: TODO: soak/deploy run, or n/a and why", + "root_cause": "`INVOKE_MSG_HANDLER` (src/include/netio.h) stored NULL into `ep->fsm_in.pkt` after every `msg_handler` call, on the old assumption that the handler always takes the packet. Since bug-1916 and raft-drive-async 3.1, a handler that takes the packet clears the slot itself (`vtask_handle_msg`, `peer_ctrl_msg_handler`). A handler that refuses it (`handle_msg` with no owner -> -EINVAL; `vtask_handle_msg` on an incomplete fsm -> -EINVAL or a failed task allocation -> -ENOMEM) leaves the packet in the slot, by the contract `test_handoff_rejects_incomplete_fsm` already pins. The macro's NULL store then dropped the only reference: the packet leaked.", + "fix": "Drop the post-handler `ep->fsm_in.pkt = NULL` from `INVOKE_MSG_HANDLER`. A refused packet stays endpoint-owned: `handle_input` reuses it for the next message and `endpoint_fini` frees it. All three production msg handlers already clear the slot when they take the packet, so no path frees it twice. The ref/unref bracket (bug-1298) is kept.\n\nVerification:\n- Test: `test_refused_packet_stays_endpoint_owned` (src/lib/testsuite/test_vtask_pkt_handoff.c) drives the macro with a refusing handler, then with a taking handler, then endpoint_fini. RED before the fix (slot NULL after a refusal; LeakSanitizer: 88 bytes leaked from encode_nop), GREEN and LSan-clean after.\n- Suites: `xce-build.sh all` asan, 127/127 meson suites OK, Go tests ok (2026-10-04).\n- Live: loaded `/xce-test-ha` sequential 30 rounds (40 busy loops on 32 cores), 2026-10-04: PASS, zero job loss, all 3 nodes led, no ASAN report in any controller/worker/scheduler log.", "tags": [ "leak", "vtask", @@ -17287,7 +17291,9 @@ "related_bugs": [ "bug-1916" ], - "fix_commits": [], + "fix_commits": [ + "a74b684c" + ], "record": ".wolf/bugs/bug-1918.md" }, { diff --git a/.wolf/bugs/bug-1914.md b/.wolf/bugs/bug-1914.md index 6e81d679..ad8ae34b 100644 --- a/.wolf/bugs/bug-1914.md +++ b/.wolf/bugs/bug-1914.md @@ -1,8 +1,8 @@ --- id: "bug-1914" -status: "open" -status_updated: "2026-10-03" -status_note: "newly logged" +status: "fixed" +status_updated: "2026-10-04" +status_note: "" component: "controller" severity: "wrong-result" timestamp: "2026-10-03T15:07:26Z" @@ -11,6 +11,7 @@ occurrences: 1 files: ["src/controller/config_repl.c", "src/controller/config_repl.h"] tags: ["ha", "config-push", "timeout", "load"] related: ["bug-1485", "bug-1913"] +fix_commits: ["06e99b90"] --- # bug-1914: config push fails -110 under heavy CPU load: commit lands just after the 500 ms barrier @@ -42,15 +43,17 @@ Error: controller returned status -110 - Evidence: not kept (scratchpad loop logs from the bug-1485 investigation) ## Root cause -TODO: required for fixed/partial +`config_commit_change` appends the `WAL_CONFIG_MARKER` first and then waits for the out-of-band byte-delivery quorum (`repl_wait_majority_ack(..., CONF_PUSH_TIMEOUT_MS)`, configAck branch). `CONF_PUSH_TIMEOUT_MS` was 500 ms, which is below ordinary scheduling delay on an oversubscribed host: with 40 busy loops on 32 cores a standby's ACK arrived ~575 ms in, so the push was rejected with -ETIMEDOUT although the majority was healthy. The marker, already in the log, still committed and activated, so the client was told the push failed for a change the cluster applied (the reply text even said "upgrade not committed"). The configAck wait was also a raw condition wait on a vtask outside the commit-wait admission reservation that ha-async-io.md requires for bounded blocking there. ## Fix -TODO: required for fixed/partial +- `CONF_PUSH_TIMEOUT_MS` 500 -> 2000 ms (src/controller/config_repl.h). +- The configAck wait in `repl_wait_majority_ack` now holds a commit-wait admission slot for its duration (new `commit_blocking_admit`/`commit_blocking_release` in commit.c, the same budget `commit_submit` WAIT uses); a full budget rejects fast with -XCE_ERR_NOT_READY, so the longer bound can never take workers reserved for liveness traffic. +- The timeout reply no longer claims "upgrade not committed": it says the change was not confirmed on a majority, may still activate if it was already ordered in the log, and should be re-pushed to confirm. ## Verification -- Test: TODO: name + file; RED before the fix, GREEN after -- Suites: TODO: suite results and build profile -- Live: TODO: soak/deploy run, or n/a and why +- Test: `test_configack_late_ack_under_load_meets_barrier` (src/controller/testsuite/test_commit_barrier_rollout.c): a config ACK arriving 700 ms in must meet the production bound, and the wait must hold one admission slot (released afterwards). RED before the fix (-110 at 500 ms), GREEN after. +- Suites: `xce-build.sh all` asan, 127/127 meson suites OK, Go tests ok (2026-10-04). +- Live: `test_live_config_push_against_primary_reaches_success_path` looped 80 times under 40 busy loops on 32 cores, 2026-10-04: 80/80 passed, no -110 (before the fix: 1/70 failed with -110 under the same load). ## References - Related: none diff --git a/.wolf/bugs/bug-1917.md b/.wolf/bugs/bug-1917.md index 5554d51a..c4df9fc9 100644 --- a/.wolf/bugs/bug-1917.md +++ b/.wolf/bugs/bug-1917.md @@ -1,8 +1,8 @@ --- id: "bug-1917" -status: "investigating" -status_updated: "2026-10-03" -status_note: "code-review finding from bug-1916; watch loaded soaks for reconnect stacks without free_packet" +status: "fixed" +status_updated: "2026-10-04" +status_note: "" component: "lib" severity: "crash" timestamp: "2026-10-03T22:55:30Z" @@ -11,6 +11,7 @@ occurrences: 1 files: ["src/lib/xcectx.c", "src/lib/netio.c"] tags: ["race", "failover", "client", "ssl"] related: ["bug-1916"] +fix_commits: ["431a6d70"] --- # bug-1917: xce_ctx_reconnect re-inits the endpoint on the caller thread while the io_worker may still use it @@ -39,15 +40,15 @@ UPDATE (2026-10-03): Review of the bug-1916 fix (2026-10-03) adds a second hazar - Evidence: code reading of src/lib/xcectx.c xce_ctx_reconnect and src/lib/netio.c endpoint_fini / handle_input / handle_output ## Root cause -TODO: required for fixed/partial +`xce_ctx_reconnect` (src/lib/xcectx.c) ran `endpoint_fini`/`endpoint_init` on `ctx->ep` straight away, while work dispatched for the old connection could still be running: the io_worker inside its epoll batch (it holds an endpoint reference for the whole batch: `SSL_read`/`handle_output` on the fd and SSL being freed), and VTASK_IO reply tasks still queued on the context's pool (each holds a reference and reads `ep->owner` without a lock). A queued reply task of the old connection that ran after the reconnect found `ep->owner` re-armed to the context and was delivered to the new session. ## Fix -TODO: required for fixed/partial +`xce_ctx_reconnect` first calls `xce_ctx_quiesce_ep`: unmonitor the old fd (no further io_worker events), clear `ep->owner` under `ep->lock` (stale reply tasks are dropped; `vtask_entry` frees their packet), then wait until the endpoint's reference count is back at its base value (0 for the embedded client endpoint, 1 for a heap one), polling every 1 ms. The wait is bounded at 2000 ms: if the caller is itself a task of this endpoint its own reference never drains, and the reconnect then proceeds as before with a WARN ("reconnecting anyway") rather than deadlocking. `vtask_entry` now reads `ep->owner` under `ep->lock`. ## Verification -- Test: TODO: name + file; RED before the fix, GREEN after -- Suites: TODO: suite results and build profile -- Live: TODO: soak/deploy run, or n/a and why +- Test: `test_reconnect_drains_old_connection_tasks` (new src/lib/testsuite/test_ctx_reconnect_quiesce.c): reconnect to a local listener, queue an old-connection packet via INVOKE_MSG_HANDLER -> handle_msg with the pool stopped, reconnect again while a helper starts the pool 100 ms in. RED before the fix (the stale task reached the context's request handler: expected 0 calls, was 1), GREEN and LSan-clean after. +- Suites: `xce-build.sh all` asan, 127/127 meson suites OK, Go tests ok (2026-10-04). +- Live: loaded `/xce-test-ha` sequential 30 rounds (40 busy loops on 32 cores), 2026-10-04: PASS, zero job loss, all 3 nodes led, no ASAN report in any controller/worker/scheduler log; client failover reconnects in worker/scheduler/xce_test throughout, and the quiesce never needed its timeout (no "reconnecting anyway" WARN). ## References - Related: none diff --git a/.wolf/bugs/bug-1918.md b/.wolf/bugs/bug-1918.md index 05be229b..971f5818 100644 --- a/.wolf/bugs/bug-1918.md +++ b/.wolf/bugs/bug-1918.md @@ -1,8 +1,8 @@ --- id: "bug-1918" -status: "open" -status_updated: "2026-10-03" -status_note: "newly logged" +status: "fixed" +status_updated: "2026-10-04" +status_note: "" component: "lib" severity: "leak" timestamp: "2026-10-03T23:04:08Z" @@ -11,6 +11,7 @@ occurrences: 1 files: ["src/lib/xcectx.c", "src/lib/vtaskmgr.c", "src/controller/cluster.c"] tags: ["leak", "vtask", "netio"] related: ["bug-1916"] +fix_commits: ["a74b684c"] --- # bug-1918: handle_msg / vtask_handle_msg early -EINVAL/-ENOMEM exits leak the received packet @@ -37,15 +38,15 @@ Not yet observed at runtime -- found reviewing the bug-1916 fix. When `handle_ms - Evidence: code reading of the cited lines ## Root cause -TODO: required for fixed/partial +`INVOKE_MSG_HANDLER` (src/include/netio.h) stored NULL into `ep->fsm_in.pkt` after every `msg_handler` call, on the old assumption that the handler always takes the packet. Since bug-1916 and raft-drive-async 3.1, a handler that takes the packet clears the slot itself (`vtask_handle_msg`, `peer_ctrl_msg_handler`). A handler that refuses it (`handle_msg` with no owner -> -EINVAL; `vtask_handle_msg` on an incomplete fsm -> -EINVAL or a failed task allocation -> -ENOMEM) leaves the packet in the slot, by the contract `test_handoff_rejects_incomplete_fsm` already pins. The macro's NULL store then dropped the only reference: the packet leaked. ## Fix -TODO: required for fixed/partial +Drop the post-handler `ep->fsm_in.pkt = NULL` from `INVOKE_MSG_HANDLER`. A refused packet stays endpoint-owned: `handle_input` reuses it for the next message and `endpoint_fini` frees it. All three production msg handlers already clear the slot when they take the packet, so no path frees it twice. The ref/unref bracket (bug-1298) is kept. ## Verification -- Test: TODO: name + file; RED before the fix, GREEN after -- Suites: TODO: suite results and build profile -- Live: TODO: soak/deploy run, or n/a and why +- Test: `test_refused_packet_stays_endpoint_owned` (src/lib/testsuite/test_vtask_pkt_handoff.c) drives the macro with a refusing handler, then with a taking handler, then endpoint_fini. RED before the fix (slot NULL after a refusal; LeakSanitizer: 88 bytes leaked from encode_nop), GREEN and LSan-clean after. +- Suites: `xce-build.sh all` asan, 127/127 meson suites OK, Go tests ok (2026-10-04). +- Live: loaded `/xce-test-ha` sequential 30 rounds (40 busy loops on 32 cores), 2026-10-04: PASS, zero job loss, all 3 nodes led, no ASAN report in any controller/worker/scheduler log. ## References - Related: none