diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 17274854..5d7e169d 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -12400,18 +12400,18 @@ }, { "id": "bug-1765", - "status": "open", - "status_updated": "2026-09-24", - "status_note": "frontend tests/regression/run.sh jobid regex rejects dashed jobid format", - "component": "unknown", - "severity": "unknown", + "status": "fixed", + "status_updated": "2026-09-30", + "status_note": "", + "component": "xcecli", + "severity": "wrong-result", "timestamp": "2026-09-03T14:51:54Z", "last_seen": "2026-09-19T09:00:00Z", "occurrences": 1, - "error_message": "tests/regression/run.sh's 'jobs submit' test FAILs deterministically (28 passed / 1 failed / 1…\n\ntests/regression/run.sh's 'jobs submit' test FAILs deterministically (28 passed / 1 failed / 1 skipped instead of 29/0/0), with the cascading 'jobs kill' test SKIPped as a result -- reproduced identically regardless of which build system (Makefile vs Meson) produced the xcecli binary under test, confirming it predates and is unrelated to the eliminate-frontend-makefile migration.", - "file": "", + "error_message": "tests/regression/run.sh's 'jobs submit' test FAILs deterministically (28 passed / 1 failed / 1…\n\ntests/regression/run.sh's 'jobs submit' test FAILs deterministically (28 passed / 1 failed / 1 skipped instead of 29/0/0), with the cascading 'jobs kill' test SKIPped as a result -- reproduced identically regardless of which build system (Makefile vs Meson) produced the xcecli binary under test, confirming it predates and is unrelated to the eliminate-frontend-makefile migration.\n\nUPDATE (2026-09-29): also found while reproducing: run from a shell whose stdin is an open pipe (a background job, CI), the suite hangs forever at `jobs submit`, because xcecli's submit reads a job script from stdin whenever stdin is a pipe (src/frontend/xcecli/cmd/jobs/submit.go:96).", + "file": "src/frontend/tests/regression/run.sh", "root_cause": "CONFIRMED via source + git history. src/frontend/apiserver/controllers/jobs.go:1518 formats the submit-response message with a plain-digit '%d' placeholder ('Job <%d> is submitted...'), but src/frontend/xcecli/cmd/jobs/submit.go:500 post-processes that message client-side, replacing the '<%d>' substring via format.FormatJobID() (src/frontend/xcecli/common/format/jobid.go:40-57), which renders the packed 64-bit job ID as the dashed '{cluster}-{apiserver}-{timestamp}-{sequence}' form (e.g. '1-0-1788446837-0'). tests/regression/run.sh:143's assertion regex ('Job <[0-9]+> is submitted') was never updated for this dashed format. The CLI-side reformatting was introduced by commit d6008ead ('improve frontend jobid display', 2026-05-07) -- nearly four months before this discovery -- so the test has been silently broken (as a false FAIL, not a false PASS) since then, not a new regression.", - "fix": "NOT FIXED -- out of scope for the eliminate-frontend-makefile spec's task 3.5 (pure verification task, no file changes permitted). Fix would be updating run.sh:143's regex to accept the dashed job-ID format (e.g. 'Job <[0-9-]+> is submitted' or delegating to the same format.FormatJobID() pattern). A second, independent, lower-severity issue was found in the same file during this investigation: run.sh:155's assert_not_contains 'jobs list submit_time not dash' calls grep -qF \"- \" without a '--' separator, so GNU grep treats the leading-dash argument as an invalid option and errors out -- this coincidentally still yields the intended PASS (grep's error-exit is indistinguishable here from 'no match'), so it doesn't affect reported counts, but isn't actually testing what it appears to test.", + "fix": "src/frontend/tests/regression/run.sh: the submit check matches the dashed ID (`Job <[0-9]+(-[0-9]+){3}> is submitted`) and extracts the whole ID from between the angle brackets (the old `[0-9]{10,}` would have taken only the timestamp field), which `jobs kill` parses back (format.ParseJobID). The submit command reads `` (an immediate kill right after submit can briefly answer `not found` -- logged separately as bug-1894)", "tags": [ "regression-suite", "test-infra", @@ -12420,7 +12420,9 @@ "pre-existing" ], "related_bugs": [], - "fix_commits": [], + "fix_commits": [ + "0f4d23e3" + ], "record": ".wolf/bugs/bug-1765.md" }, { @@ -16519,6 +16521,85 @@ "record": ".wolf/bugs/bug-1891.md", "gitea_issue": 337, "gitea_synced_status": "fixed" + }, + { + "id": "bug-1892", + "status": "open", + "status_updated": "2026-09-30", + "status_note": "newly logged", + "component": "scheduler", + "severity": "wrong-result", + "timestamp": "2026-09-30T03:58:52Z", + "last_seen": "2026-09-30T03:58:52Z", + "occurrences": 1, + "error_message": "xce_scheduler admission check reads per-resource uncommitted amounts by list position, not index\n\n**Observed:** found by code reading, so there is no failing run yet. `unsatisfy_()` (`src/scheduler/src/resource.c:130-169`) compares\n```c\nif (total[i] < inuse[i] + uncomitted[i] + wanted[i])\n```\nwhere `total`, `inuse` and `wanted` are *positional* arrays (entry `i` is the\n`i`-th resource of the request, gathered by `get_resvals(..., wanted->idxs, ...)`),\nbut `uncomitted` is the context's *dense, resource-index-keyed* vector\n(`ctx->uncomitted.shared` / `ctx->uncomitted.hosts[w]`, 1024 floats,\n`schedobj.c:514/595`), filled by `xvec_idval(uncomit, &req, XVEC_ADD_FLOAT)`,\nwhich writes `d[idx] += val` (`lib/xvec.c`, `DEFINE_XVEC_IDVAL_OP`). Both\n`sched_check_shared_satisfy_()` (`resource.c:309`) and\n`sched_check_host_satisfy_()` (`resource.c:376`) pass `uncomitted->data`\nstraight through, so entry `i` reads the uncommitted amount of resource index\n`i`, not of resource `wanted->idxs[i]`.\n\n**Expected:** entry `i` uses `uncomitted[wanted->idxs[i]]` (gather it\npositionally like `total`/`inuse`, e.g. with the existing `get_resvals()`).\n\n**Impact:** wrong admission result. Uncommitted amounts are nonzero only\nwithin one allocation context that already committed something, i.e. from the\nsecond primary of a COMPOUND (or ALTER) job on, since those primaries share one\n`ctx` (`scheduler.c:348-354`); the first primary and ordinary PRIMARY jobs\nalways see all-zero uncommitted vectors, and parjob rolls back failed plans.\nFor a later primary, the check subtracts an unrelated resource's uncommitted\namount (or 0) instead of the earlier primaries' real claim on the same\nresource, so it can over-admit (earlier primary's claim ignored: the job is\ndispatched beyond host/shared capacity) or wrongly pend (another resource's\namount charged). Pend reasons printed for the same check carry the wrong\nshortfall.\n\n**Found by:** review of the `scheduler-allocator-runner` requirements\n(2026-09-29), while checking the shared-resource precheck the runner inherits.", + "file": "src/scheduler/src/resource.c, src/lib/xvec.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": [ + "scheduler", + "allocation", + "compound", + "code-review" + ], + "related_bugs": [ + "bug-1893" + ], + "fix_commits": [], + "record": ".wolf/bugs/bug-1892.md" + }, + { + "id": "bug-1893", + "status": "open", + "status_updated": "2026-09-30", + "status_note": "newly logged", + "component": "scheduler", + "severity": "wrong-result", + "timestamp": "2026-09-30T03:58:52Z", + "last_seen": "2026-09-30T03:58:52Z", + "occurrences": 1, + "error_message": "xce_scheduler allocators add spurious resource-0 shared pend reasons (loop reads past unmet list)\n\n**Observed:** found by code reading, so there is no failing run yet. When the shared-resource check\nfails, both allocators add the pend reasons with\n```c\nfor (i = 0; i < ctx->alloc_req.shared.count; i++) {\n rc = vget(core->resmgr, ((int*)ctx->unmeet.idxs.data)[i], (void**)&r);\n if (rc <= 0) continue;\n add_job_preason(reason->reasons, PREASON_NO_RESOURCE, NULL, r->name);\n}\n```\n(`seqjob_allocator.c` `my_alloc`, `parjob_allocator.c` `my_alloc`). The loop\nbound is the number of *requested* shared resources, but `ctx->unmeet` holds\nonly the *unmet* ones, packed at `[0, unmeet.count)` by `unsatisfy_()`\n(`resource.c:152-165`). Its arrays were `calloc`ed with capacity\n`shared.count` (`resource.c:280`), so entries `[unmeet.count, shared.count)`\nare 0.\n\n**Expected:** iterate `i < ctx->unmeet.count` (as the host path does,\n`resource.c:566`), giving one `NO_RESOURCE` reason per unmet shared resource.\n\n**Impact:** wrong pend reason, noise level. When a job requests N shared\nresources and only M < N are unmet, the loop adds N - M extra\n`PREASON_NO_RESOURCE` reasons naming whatever resource has index 0 (if one\nexists), which that job may never have requested. Main reason and allocation\ndecision are unaffected. No out-of-bounds memory access (the tail is inside the\nallocation).\n\n**Found by:** review of the `scheduler-allocator-runner` requirements\n(2026-09-29); the loop moves into the framework runner in that spec.", + "file": "src/scheduler/src/plugins/seqjob_allocator.c, src/scheduler/src/plugins/parjob_allocator.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": [ + "scheduler", + "allocation", + "preason", + "code-review" + ], + "related_bugs": [ + "bug-1892" + ], + "fix_commits": [], + "record": ".wolf/bugs/bug-1893.md" + }, + { + "id": "bug-1894", + "status": "open", + "status_updated": "2026-09-30", + "status_note": "newly logged", + "component": "apiserver", + "severity": "wrong-result", + "timestamp": "2026-09-30T04:14:02Z", + "last_seen": "2026-09-30T04:14:02Z", + "occurrences": 1, + "error_message": "xce_apiserver: jobs kill right after jobs submit can answer 'job not found' for the accepted job\n\n**Observed:** `xcecli jobs kill ` issued right after `jobs submit` returned that ID can answer that the job does not exist; retried moments later, the same kill succeeds:\n```\nJob <1-0-1790741567-0> is submitted to default queue .\njob <1-0-1790741567-0> not found\n... (seconds later)\njob <1-0-1790741567-0> is being \n```\n**Expected:** once submit has returned a job ID, operations on that ID see the job.\n**Impact:** minor -- a script that submits and immediately controls a job gets a spurious `not found`; the job itself is fine and appears in `jobs list` under the same ID.\n**Found by:** manual check while verifying bug-1765's regression-suite fix, 2026-09-29. Suspected (not verified): the apiserver learns of a new job through the controller's asynchronous job notification (OnJobCreated) rather than from the submit reply, so its job store lags the submit acknowledgement by up to a notification round-trip.", + "file": "src/frontend/apiserver/controllers/jobs.go (job kill lookup)", + "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": [ + "apiserver", + "jobs", + "kill", + "consistency", + "latency" + ], + "related_bugs": [ + "bug-1765" + ], + "fix_commits": [], + "record": ".wolf/bugs/bug-1894.md" } ] } diff --git a/.wolf/bugs/bug-1765.md b/.wolf/bugs/bug-1765.md index eba57dca..c45c0050 100644 --- a/.wolf/bugs/bug-1765.md +++ b/.wolf/bugs/bug-1765.md @@ -1,16 +1,17 @@ --- id: "bug-1765" -status: "open" -status_updated: "2026-09-24" -status_note: "frontend tests/regression/run.sh jobid regex rejects dashed jobid format" -component: "unknown" -severity: "unknown" +status: "fixed" +status_updated: "2026-09-30" +status_note: "" +component: "xcecli" +severity: "wrong-result" timestamp: "2026-09-03T14:51:54Z" last_seen: "2026-09-19T09:00:00Z" occurrences: 1 -files: [] +files: ["src/frontend/tests/regression/run.sh"] tags: ["regression-suite", "test-infra", "jobid-format", "false-fail", "pre-existing"] related: [] +fix_commits: ["0f4d23e3"] legacy: true --- @@ -19,20 +20,33 @@ legacy: true ## Description tests/regression/run.sh's 'jobs submit' test FAILs deterministically (28 passed / 1 failed / 1 skipped instead of 29/0/0), with the cascading 'jobs kill' test SKIPped as a result -- reproduced identically regardless of which build system (Makefile vs Meson) produced the xcecli binary under test, confirming it predates and is unrelated to the eliminate-frontend-makefile migration. +UPDATE (2026-09-29): also found while reproducing: run from a shell whose stdin is an open pipe (a background job, CI), the suite hangs forever at `jobs submit`, because xcecli's submit reads a job script from stdin whenever stdin is a pipe (src/frontend/xcecli/cmd/jobs/submit.go:96). + ## Environment -_Not recorded (migrated from buglog.json)._ +- OS: no /etc/os-release; Docker container; NixOS kernel; kernel Linux 6.18.33 x86_64 +- libc: glibc 2.42-47 for the controller (nix dev shell); xcecli/xce_apiserver are Go binaries built by meson (go_build) +- Toolchain: go (nix dev shell), gcc (GCC) 15.2.0, meson 1.9.1 +- Build: asan (src/xce.build.bug1871: controller, scheduler, worker, xceadmin, apiserver, xcecli) +- Code: reproduced 2026-09-29 at f5c887dc+ +- Deployment: local 3-node HA controller cluster + xcecd_virtual worker + scheduler + apiserver on :8080 (deploy-ha.sh + start-all.sh, /home/claude/tmp/xce-1765), config_file auth (admin/admin) ## Reproduction -_Not recorded (migrated from buglog.json)._ +1. Deploy a cluster with an apiserver: `bash src/tools/deploy-ha.sh /controller/xce_controller localhost:9991,localhost:9992,localhost:9993 && bash /scripts/start-all.sh` +2. `XCE=/frontend/xcecli/xcecli URL=http://localhost:8080 bash src/frontend/tests/regression/run.sh is submitted to default queue .`, `SKIP jobs kill`, `Results: 28 passed 1 failed 1 skipped`; without ` is submitted...'), but src/frontend/xcecli/cmd/jobs/submit.go:500 post-processes that message client-side, replacing the '<%d>' substring via format.FormatJobID() (src/frontend/xcecli/common/format/jobid.go:40-57), which renders the packed 64-bit job ID as the dashed '{cluster}-{apiserver}-{timestamp}-{sequence}' form (e.g. '1-0-1788446837-0'). tests/regression/run.sh:143's assertion regex ('Job <[0-9]+> is submitted') was never updated for this dashed format. The CLI-side reformatting was introduced by commit d6008ead ('improve frontend jobid display', 2026-05-07) -- nearly four months before this discovery -- so the test has been silently broken (as a false FAIL, not a false PASS) since then, not a new regression. ## Fix -NOT FIXED -- out of scope for the eliminate-frontend-makefile spec's task 3.5 (pure verification task, no file changes permitted). Fix would be updating run.sh:143's regex to accept the dashed job-ID format (e.g. 'Job <[0-9-]+> is submitted' or delegating to the same format.FormatJobID() pattern). A second, independent, lower-severity issue was found in the same file during this investigation: run.sh:155's assert_not_contains 'jobs list submit_time not dash' calls grep -qF "- " without a '--' separator, so GNU grep treats the leading-dash argument as an invalid option and errors out -- this coincidentally still yields the intended PASS (grep's error-exit is indistinguishable here from 'no match'), so it doesn't affect reported counts, but isn't actually testing what it appears to test. +src/frontend/tests/regression/run.sh: the submit check matches the dashed ID (`Job <[0-9]+(-[0-9]+){3}> is submitted`) and extracts the whole ID from between the angle brackets (the old `[0-9]{10,}` would have taken only the timestamp field), which `jobs kill` parses back (format.ParseJobID). The submit command reads `` (an immediate kill right after submit can briefly answer `not found` -- logged separately as bug-1894) ## References -_Not recorded (migrated from buglog.json)._ +- Fix commit: 0f4d23e3 +- Related: d6008ead (dashed job-ID display), bug-1894 (submit-to-visible lag) diff --git a/.wolf/bugs/bug-1894.md b/.wolf/bugs/bug-1894.md new file mode 100644 index 00000000..6846bbf7 --- /dev/null +++ b/.wolf/bugs/bug-1894.md @@ -0,0 +1,56 @@ +--- +id: "bug-1894" +status: "open" +status_updated: "2026-09-30" +status_note: "newly logged" +component: "apiserver" +severity: "wrong-result" +timestamp: "2026-09-30T04:14:02Z" +last_seen: "2026-09-30T04:14:02Z" +occurrences: 1 +files: ["src/frontend/apiserver/controllers/jobs.go (job kill lookup)"] +tags: ["apiserver", "jobs", "kill", "consistency", "latency"] +related: ["bug-1765"] +--- + +# bug-1894: xce_apiserver: jobs kill right after jobs submit can answer 'job not found' for the accepted job + +## Description +**Observed:** `xcecli jobs kill ` issued right after `jobs submit` returned that ID can answer that the job does not exist; retried moments later, the same kill succeeds: +``` +Job <1-0-1790741567-0> is submitted to default queue . +job <1-0-1790741567-0> not found +... (seconds later) +job <1-0-1790741567-0> is being +``` +**Expected:** once submit has returned a job ID, operations on that ID see the job. +**Impact:** minor -- a script that submits and immediately controls a job gets a spurious `not found`; the job itself is fine and appears in `jobs list` under the same ID. +**Found by:** manual check while verifying bug-1765's regression-suite fix, 2026-09-29. Suspected (not verified): the apiserver learns of a new job through the controller's asynchronous job notification (OnJobCreated) rather than from the submit reply, so its job store lags the submit acknowledgement by up to a notification round-trip. + +## 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 (xce.build) +- Code: scheduler-framework @ 0f4d23e3-dirty +- Deployment: local 3-node HA controller cluster + xcecd_virtual worker + scheduler + apiserver on :8080 (deploy-ha.sh + start-all.sh), config_file auth + +## Reproduction +1. Deploy a cluster with an apiserver (deploy-ha.sh + scripts/start-all.sh) and `xcecli login -u admin -p admin --url http://localhost:8080` +2. `id=$(xcecli jobs submit -q normal sleep 300 ]+)>.*/\1/p'); xcecli jobs kill "$id"` +- Frequency: 2/4 immediate kills answered `not found`, 2026-09-29 (the lag measured 0.01-0.22 s in three timed tries) +- Evidence: /home/claude/tmp/xce-1765/logs/apiserver.log (21:12:47 query for job_id 73935322667286528) + +## 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