docs(buglog): bug-1905 fixed in 8ac637ad; log bug-1908 (kill lost before worker registers job)

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Rongsong Shen 2026-10-02 02:27:34 +00:00
parent 8ac637ad36
commit 7d6a6e6043
Signed by untrusted user: rshen
GPG key ID: 80533536B0EB651C
3 changed files with 103 additions and 15 deletions

View file

@ -16891,9 +16891,9 @@
},
{
"id": "bug-1905",
"status": "open",
"status_updated": "2026-10-01",
"status_note": "newly logged",
"status": "fixed",
"status_updated": "2026-10-02",
"status_note": "",
"component": "worker",
"severity": "wrong-result",
"timestamp": "2026-10-01T14:32:18Z",
@ -16901,15 +16901,17 @@
"occurrences": 1,
"error_message": "xcecd_virtual ignores kill of a running job: job keeps RUN until its sleep time elapses\n\n**Observed:**\n```\n14:17:47,625 controller_connector.c:1546 Received job control request to send SIGINFO for job ID: 1-0-1790864259-0\n14:17:47,625 controller_connector.c:1610 Job control task handled directly for job ID: 1-0-1790864259-0\n14:27:40,008 xcecd_worker_utils.c:847 Sleep time 600 >= 600 seconds elapsed for worker 1009 (job 1-0-1790864259-0)\nctrl-1: on_job_finish job finish jobid 1-0-1790864259-0 exit code 0\n```\n`xcecli jobs kill` of a RUN job (plain `sleep 600`, and array elements `arr3[2]`, `arr3[3]`) is accepted (apiserver: `overallStatus accepted`, SIGTERM) and reaches the virtual worker, but the job stays RUN and finishes DONE with exit 0 when its sleep time elapses. Killing a PEND job works (EXIT).\n\n**Expected:** the virtual worker ends a killed running job as EXITED with exit code 128+signal on its next poll (the `killed_signal` branch in `xcecd_dbus_manager.c:259-262`).\n**Impact:** kill of running jobs cannot be exercised on virtual-worker deployments (tests, soaks); the real worker path (`ipc_master_send_job_signal`) is not affected by this record.\n**Found by:** spec task (job-array-one-based-index task 10.2 live REST flow)",
"file": "src/worker/src/controller_connector.c, src/worker/src/xcecd_dbus_manager.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": "`dbus_workers_update()` (`src/worker/src/xcecd_dbus_manager.c`) decided a virtual job's end inside the branches of `get_systemd_job_exit_code()`: the `== 0` branch checked the sleep timer and then `killed_signal`, but the `< 0` branch checked only the timer. A virtual job has no systemd unit, and without a system bus (this container: `Failed to connect to system bus`) the call returns -1, so the kill recorded by the job-control handler (`controller_connector.c`, `worker->killed_signal`) was never acted on; the job stayed RUN and ended DONE with exit 0 when its sleep time elapsed. (Even on the `== 0` path the timer was checked before the kill.)",
"fix": "In `VIRTUAL_CLUSTER` builds the loop decides a running job's end before asking systemd: `killed_signal != 0` ends it as `WORKER_EXITED` with exit code 128 + signal; otherwise it is `WORKER_DONE` once its sleep time is up. The two partial virtual copies inside the exit-code branches were removed; real-worker behaviour is unchanged.\n\nVerification:\n- Test: `test_killed_running_job_exits_without_systemd` (and the guard `test_unkilled_running_job_keeps_running`) in `src/worker/testsuite/test_dbus_workers_update.c`; RED before the fix (no status update, `Expected 1 Was 0`), GREEN after\n- Suites: worker meson suite 14/14 OK (asan, src/build.jai)\n- Live: xce-deploy-ha + xcecli, kill sent after the worker logged the jobs running: `plain2` and `arr2[2]` went RUN -> EXIT within 6 s, `arr2[1]`/`arr2[3]` stayed RUN (/home/claude/tmp/bug-1905/fixed-run.log). A kill sent within ~a few seconds of dispatch, before the worker has registered the job, is still lost (\"Failed to find worker\") -- a separate defect shared with the real worker, see References (bug-1908)",
"tags": [
"virtual-cluster",
"job-control",
"kill"
],
"related_bugs": [],
"fix_commits": [],
"fix_commits": [
"8ac637ad"
],
"record": ".wolf/bugs/bug-1905.md"
},
{
@ -16964,6 +16966,32 @@
"47551fb2"
],
"record": ".wolf/bugs/bug-1907.md"
},
{
"id": "bug-1908",
"status": "investigating",
"status_updated": "2026-10-02",
"status_note": "worker drops a kill that arrives before the job is in its worker list; controller-side handling of the worker's error (retry or not) not yet traced",
"component": "worker",
"severity": "wrong-result",
"timestamp": "2026-10-02T02:27:01Z",
"last_seen": "2026-10-02T02:27:01Z",
"occurrences": 1,
"error_message": "a kill sent right after dispatch is lost: the worker drops it before registering the job\n\n**Observed:**\n```\n05,850 controller_connector.c:563 Job ID: 1-0-1790907905-32768[2], Command: sleep 600 ... (dispatch received)\n07,318 controller_connector.c:1546 Received job control request to send SIGINFO for job ID: 1-0-1790907905-32768[2]\n07,318 controller_connector.c:1586 Failed to find worker for job ID: 1-0-1790907905-32768[2]\n09,690 xcecd_worker_utils.c:352 Job ID 1-0-1790907905-32768[2] running - sending status to controller\n```\n`xcecli jobs list` already showed the job RUN, `xcecli jobs kill` answered `job <...> is being <kill>` (apiserver `overallStatus accepted`), but the worker had not yet added the job to its worker list, dropped the request, and the job then ran to completion. Same for a plain job (1-0-1790907905-0: dispatch 06,876, kill 07,313 dropped, running 09,724).\n\n**Expected:** a kill accepted for a job the controller shows as RUN takes effect: the worker applies it once the job is registered (or the controller retries / reports the kill as not delivered).\n**Impact:** wrong result: a kill issued in the first seconds after dispatch is reported as accepted but silently lost; the job keeps running. The lookup branch is shared by the real worker (`xcecd`), not only `xcecd_virtual` (real worker not tested).\n**Found by:** test (live verification of bug-1905, 2026-10-01)",
"file": "src/worker/src/controller_connector.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",
"tags": [
"job-control",
"kill",
"race",
"dispatch"
],
"related_bugs": [
"bug-1905"
],
"fix_commits": [],
"record": ".wolf/bugs/bug-1908.md"
}
]
}

View file

@ -1,8 +1,8 @@
---
id: "bug-1905"
status: "open"
status_updated: "2026-10-01"
status_note: "newly logged"
status: "fixed"
status_updated: "2026-10-02"
status_note: ""
component: "worker"
severity: "wrong-result"
timestamp: "2026-10-01T14:32:18Z"
@ -11,6 +11,7 @@ occurrences: 1
files: ["src/worker/src/controller_connector.c", "src/worker/src/xcecd_dbus_manager.c"]
tags: ["virtual-cluster", "job-control", "kill"]
related: []
fix_commits: ["8ac637ad"]
---
# bug-1905: xcecd_virtual ignores kill of a running job: job keeps RUN until its sleep time elapses
@ -45,15 +46,15 @@ ctrl-1: on_job_finish job finish jobid 1-0-1790864259-0 exit code 0
- Evidence: /home/claude/tmp/bug-1905/kill-trace.log
## Root cause
TODO: required for fixed/partial
`dbus_workers_update()` (`src/worker/src/xcecd_dbus_manager.c`) decided a virtual job's end inside the branches of `get_systemd_job_exit_code()`: the `== 0` branch checked the sleep timer and then `killed_signal`, but the `< 0` branch checked only the timer. A virtual job has no systemd unit, and without a system bus (this container: `Failed to connect to system bus`) the call returns -1, so the kill recorded by the job-control handler (`controller_connector.c`, `worker->killed_signal`) was never acted on; the job stayed RUN and ended DONE with exit 0 when its sleep time elapsed. (Even on the `== 0` path the timer was checked before the kill.)
## Fix
TODO: required for fixed/partial
In `VIRTUAL_CLUSTER` builds the loop decides a running job's end before asking systemd: `killed_signal != 0` ends it as `WORKER_EXITED` with exit code 128 + signal; otherwise it is `WORKER_DONE` once its sleep time is up. The two partial virtual copies inside the exit-code branches were removed; real-worker behaviour is unchanged.
## 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_killed_running_job_exits_without_systemd` (and the guard `test_unkilled_running_job_keeps_running`) in `src/worker/testsuite/test_dbus_workers_update.c`; RED before the fix (no status update, `Expected 1 Was 0`), GREEN after
- Suites: worker meson suite 14/14 OK (asan, src/build.jai)
- Live: xce-deploy-ha + xcecli, kill sent after the worker logged the jobs running: `plain2` and `arr2[2]` went RUN -> EXIT within 6 s, `arr2[1]`/`arr2[3]` stayed RUN (/home/claude/tmp/bug-1905/fixed-run.log). A kill sent within ~a few seconds of dispatch, before the worker has registered the job, is still lost ("Failed to find worker") -- a separate defect shared with the real worker, see References (bug-1908)
## References
- Related: none
- Related: bug-1908 (kill lost when sent before the worker registers the job)

59
.wolf/bugs/bug-1908.md Normal file
View file

@ -0,0 +1,59 @@
---
id: "bug-1908"
status: "investigating"
status_updated: "2026-10-02"
status_note: "worker drops a kill that arrives before the job is in its worker list; controller-side handling of the worker's error (retry or not) not yet traced"
component: "worker"
severity: "wrong-result"
timestamp: "2026-10-02T02:27:01Z"
last_seen: "2026-10-02T02:27:01Z"
occurrences: 1
files: ["src/worker/src/controller_connector.c"]
tags: ["job-control", "kill", "race", "dispatch"]
related: ["bug-1905"]
---
# bug-1908: a kill sent right after dispatch is lost: the worker drops it before registering the job
## Description
**Observed:**
```
05,850 controller_connector.c:563 Job ID: 1-0-1790907905-32768[2], Command: sleep 600 ... (dispatch received)
07,318 controller_connector.c:1546 Received job control request to send SIGINFO for job ID: 1-0-1790907905-32768[2]
07,318 controller_connector.c:1586 Failed to find worker for job ID: 1-0-1790907905-32768[2]
09,690 xcecd_worker_utils.c:352 Job ID 1-0-1790907905-32768[2] running - sending status to controller
```
`xcecli jobs list` already showed the job RUN, `xcecli jobs kill` answered `job <...> is being <kill>` (apiserver `overallStatus accepted`), but the worker had not yet added the job to its worker list, dropped the request, and the job then ran to completion. Same for a plain job (1-0-1790907905-0: dispatch 06,876, kill 07,313 dropped, running 09,724).
**Expected:** a kill accepted for a job the controller shows as RUN takes effect: the worker applies it once the job is registered (or the controller retries / reports the kill as not delivered).
**Impact:** wrong result: a kill issued in the first seconds after dispatch is reported as accepted but silently lost; the job keeps running. The lookup branch is shared by the real worker (`xcecd`), not only `xcecd_virtual` (real worker not tested).
**Found by:** test (live verification of bug-1905, 2026-10-01)
## Environment
- OS: no /etc/os-release; Docker container; NixOS kernel; kernel Linux 6.18.33 x86_64
- libc: glibc 2.42-47 (interpreter /nix/store/wb6rhpznjfczwlwx23zmdrrw74bayxw4-glibc-2.42-47/lib/ld-linux-x86-64.so.2)
- Toolchain: gcc (GCC) 15.2.0, meson 1.9.1
- Build: asan (src/build.jai)
- Code: scheduler-framework @ 8ac637ad-dirty
- Deployment: 3-node HA (xce-deploy-ha) + scheduler + apiserver + one xcecd_virtual worker, single host
## Reproduction
1. Deploy with xce-deploy-ha + `start-all.sh`; `xcecli login -u admin -p admin --url http://localhost:8080`.
2. `xcecli jobs submit -J plain sleep 600 </dev/null`; as soon as `xcecli jobs list` shows RUN (about 1 s), `xcecli jobs kill <id> </dev/null`.
3. The worker log shows `Failed to find worker for job ID`, and the job stays RUN.
- Frequency: 2/2 kills sent within ~1.5 s of dispatch, 2026-10-01
- Evidence: /home/claude/tmp/kill-race/worker.log
## Root cause
TODO: required for fixed/partial
## Fix
TODO: required for fixed/partial
## 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
## References
- Related: none