docs(buglog): bug-1914, bug-1917, bug-1918 fixed; refresh STATUS.md
Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This commit is contained in:
parent
06e99b9081
commit
8e66d463ea
GPG key ID:
80533536B0EB651C
5 changed files with 67 additions and 50 deletions
|
|
@ -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]`), `<array-id>[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 `<array-id>[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_<id>_task<N>.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.
|
||||
|
||||
---
|
||||
|
||||
|
|
|
|||
|
|
@ -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"
|
||||
},
|
||||
{
|
||||
|
|
|
|||
|
|
@ -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
|
||||
|
|
|
|||
|
|
@ -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
|
||||
|
|
|
|||
|
|
@ -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
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue