fix(controller,xceadmin): fix zero-slot scheduling block, misleading resval logs, byte-unit display
Three bugs found while diagnosing a live controller log, all in the worker resource-value path: 1. Every host relying on the documented hosts.yaml auto-detect default (no max_slot, meaning "use CPU count") got 0 scheduling slots, permanently blocking the scheduler from placing jobs on it. mxj is UInt32 on the wire and can't carry the schema's -1 sentinel; mapping.py worked around this by leaving it unset, which defaults to 0 -- and 0 is never < 0, so apply_join_state()'s auto-detect fallback never fired. Fixed by encoding the sentinel as 0xFFFFFFFF, which the controller's `int mxj` field reinterprets back to -1 via its existing implicit uint32_t->int conversion. No C-side or wire schema change needed for this part; the fallback itself was already correct but had zero test coverage for a negative mxj, now added. 2. update_resvals()/update_resval_list() logged the failure reason via PERROR, which reads process-global errno -- but update_resval()'s failure paths return raw negative codes directly and never touch errno, so the controller log filled with misleading "update_resval: Success" / "update_resval: Resource temporarily unavailable" lines instead of the real reason. Fixed to decode the actual rc via xce_strerror_r and name the failing resource. 3. maxmem is canonically stored/wired as raw bytes but had no unit metadata, so resval/workerlist printed it as a bare number that read as garbage (e.g. workerlist's fixed-width columns visually smeared a multi-GB byte count across the MaxCPU/MaxMem headers). Added an optional `unit` field to the Resource/ResourceVal capnp structs (and xce_resource_t/xce_resval_t/resources.yaml) so resval and workerlist can render a human-readable value (e.g. "30.90 GB") while the stored value stays raw bytes -- display-only, every other resource unaffected. Regenerated the xceadmin golden fixture (fixtures/full/expected.bin) twice: once for the mxj sentinel encoding change, once for the new Resource.unit field growing every resource's wire size by one pointer slot. Both diffs verified byte-for-byte isolated to exactly the expected change before regenerating. Verified: 1095/1095 controller_unit_test (stable across repeated runs), 229/229 xceadmin pytest, clean rebuild of lib/controller/xceadmin/xce_test. Two related findings logged to .wolf/buglog.json but deliberately not fixed here (out of scope per discussion): a pre-existing flaky segfault in the combined controller_unit_test binary, and maxswap/maxtmp being hardcoded stub values on the worker side. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This commit is contained in:
parent
9e15161228
commit
e3b3ffaa97
SSH key fingerprint:
SHA256:8Vf2pZ3h6rJa7EhGK+WaAQ9Mta/apZvteW6g9U/WKKk
12 changed files with 354 additions and 20 deletions
|
|
@ -62,9 +62,20 @@ static int do_reply_resvals(cluster_t* c, endpoint_t* ep,
|
|||
rc = get_resval(c, condition->condition.reskey->resname,
|
||||
condition->condition.reskey->hostname, &val);
|
||||
if (rc >= 0) {
|
||||
xce_resource_t* r = NULL;
|
||||
|
||||
resval.val = &val;
|
||||
resval.name = condition->condition.reskey->resname;
|
||||
resval.host = condition->condition.reskey->hostname;
|
||||
resval.unit = NULL;
|
||||
|
||||
lock(c->resmgr, RTTI_LOCK_READ);
|
||||
key_find(c->resmgr, (void*)resval.name, (void**)&r);
|
||||
unlock(c->resmgr);
|
||||
if (r != NULL) {
|
||||
resval.unit = r->unit;
|
||||
}
|
||||
|
||||
resvaldata.n_total = 1;
|
||||
resvaldata.vals = vals;
|
||||
}
|
||||
|
|
|
|||
|
|
@ -1050,6 +1050,9 @@ static char* worker_status_str(uint32_t status)
|
|||
return "UNKOWN";
|
||||
}
|
||||
|
||||
/* forward decl: defined near cmd_resval, below, which also uses it */
|
||||
static void format_bytes_human(double bytes, char* buf, size_t bufsize);
|
||||
|
||||
int cmd_workerlist(int argc, char* argv[])
|
||||
{
|
||||
int rc, i;
|
||||
|
|
@ -1068,11 +1071,19 @@ int cmd_workerlist(int argc, char* argv[])
|
|||
"MaxSwap", "MaxTmp", "NDisks");
|
||||
|
||||
for (i = 0; i < rc; i++) {
|
||||
printf("%-20s%-8s%-25s%-25s%12f%12d%12f%12f%12f%12d\n",
|
||||
/* MaxMem is stored/wired as raw bytes (xce_resource_t.unit="bytes"
|
||||
* for the maxmem resource definition) -- humanize for display only,
|
||||
* every other column stays as-is. */
|
||||
char maxmem_buf[64];
|
||||
|
||||
format_bytes_human(workers[i]->attrs->maxmem, maxmem_buf,
|
||||
sizeof(maxmem_buf));
|
||||
|
||||
printf("%-20s%-8s%-25s%-25s%12f%12d%12s%12f%12f%12d\n",
|
||||
workers[i]->name, worker_status_str(workers[i]->status),
|
||||
workers[i]->attrs->hosttype, workers[i]->attrs->hostmodel,
|
||||
workers[i]->attrs->cpufactor, workers[i]->attrs->maxcpus,
|
||||
workers[i]->attrs->maxmem, workers[i]->attrs->maxswap,
|
||||
maxmem_buf, workers[i]->attrs->maxswap,
|
||||
workers[i]->attrs->maxtmp, workers[i]->attrs->ndisks);
|
||||
}
|
||||
|
||||
|
|
@ -2024,6 +2035,28 @@ cleanup:
|
|||
return 0;
|
||||
}
|
||||
|
||||
/*
|
||||
* Render a raw byte count as a human-readable string (e.g. "30.90 GB").
|
||||
* Only used for display -- the stored/wire value stays raw bytes always,
|
||||
* this never feeds back into anything that's compared or persisted. A
|
||||
* pure function so it's directly unit-testable without a live client
|
||||
* connection.
|
||||
*/
|
||||
static void format_bytes_human(double bytes, char* buf, size_t bufsize)
|
||||
{
|
||||
static const char* const UNITS[] = { "B", "KB", "MB", "GB", "TB", "PB" };
|
||||
const int nunits = (int)(sizeof(UNITS) / sizeof(UNITS[0]));
|
||||
double val = bytes;
|
||||
int i = 0;
|
||||
|
||||
while (val >= 1024.0 && i < nunits - 1) {
|
||||
val /= 1024.0;
|
||||
i++;
|
||||
}
|
||||
|
||||
snprintf(buf, bufsize, "%.2f %s", val, UNITS[i]);
|
||||
}
|
||||
|
||||
int cmd_resval(int argc, char* argv[])
|
||||
{
|
||||
char* host = NULL;
|
||||
|
|
@ -2065,7 +2098,15 @@ int cmd_resval(int argc, char* argv[])
|
|||
printf("%s\n", val->val->u.svalue);
|
||||
break;
|
||||
case Value_u_fvalue:
|
||||
printf("%f\n", val->val->u.fvalue);
|
||||
if ((val->unit != NULL) && (strcmp(val->unit, "bytes") == 0)) {
|
||||
char hbuf[64];
|
||||
|
||||
format_bytes_human(val->val->u.fvalue, hbuf,
|
||||
sizeof(hbuf));
|
||||
printf("%f (%s)\n", val->val->u.fvalue, hbuf);
|
||||
} else {
|
||||
printf("%f\n", val->val->u.fvalue);
|
||||
}
|
||||
break;
|
||||
case Value_u_bvalue:
|
||||
printf("%s\n", (val->val->u.bvalue == 0) ? "false" : "true");
|
||||
|
|
|
|||
|
|
@ -17,6 +17,7 @@
|
|||
#include <stdio.h>
|
||||
#include <stdlib.h>
|
||||
#include <string.h>
|
||||
#include <unistd.h>
|
||||
|
||||
#include <unity/unity.h>
|
||||
|
||||
|
|
@ -152,6 +153,132 @@ static float get_worker_res_fval(worker_t* w, const char* name)
|
|||
return (v != NULL) ? v->u.fvalue : -1.0f;
|
||||
}
|
||||
|
||||
/*
|
||||
* Capture whatever update_resvals()/update_resval_list() print during a
|
||||
* failing update_resval() call, as raw runtime output rather than a
|
||||
* source-text scan. This test binary never calls mylog_init()/tlog_init()
|
||||
* (only the real daemon main()s do -- see test_apply_correctness_
|
||||
* verification.c's own header comment, and the identical established
|
||||
* precedent in scheduler/testsuite/test_scheduler_connect.c's
|
||||
* capture_stdout_during_sched_init()), so tlog's internal root log handle
|
||||
* stays NULL and every ERROR()/WARN() call falls through tlog's early-
|
||||
* print path, which writes the fully formatted line directly to
|
||||
* STDOUT_FILENO via a raw write() -- genuine runtime log capture, not a
|
||||
* guess about which stream PERROR/ERROR happens to use.
|
||||
*/
|
||||
static char* capture_stdout_during(void (*fn)(void* ctx), void* ctx)
|
||||
{
|
||||
char tmp[] = "/tmp/xce_worker_join_logcap_XXXXXX";
|
||||
int fd = mkstemp(tmp);
|
||||
TEST_ASSERT_TRUE_MESSAGE(fd >= 0,
|
||||
"fixture: mkstemp for stdout capture must succeed");
|
||||
|
||||
fflush(stdout);
|
||||
int saved_stdout = dup(STDOUT_FILENO);
|
||||
TEST_ASSERT_TRUE_MESSAGE(saved_stdout >= 0,
|
||||
"fixture: dup(STDOUT_FILENO) must succeed");
|
||||
TEST_ASSERT_TRUE_MESSAGE(dup2(fd, STDOUT_FILENO) >= 0,
|
||||
"fixture: dup2 redirect of STDOUT_FILENO must "
|
||||
"succeed");
|
||||
|
||||
fn(ctx);
|
||||
|
||||
fflush(stdout);
|
||||
dup2(saved_stdout, STDOUT_FILENO);
|
||||
close(saved_stdout);
|
||||
|
||||
off_t len = lseek(fd, 0, SEEK_CUR);
|
||||
TEST_ASSERT_TRUE_MESSAGE(len >= 0,
|
||||
"fixture: lseek on capture file must succeed");
|
||||
|
||||
char* buf = (char*)calloc(1, (size_t)len + 1);
|
||||
TEST_ASSERT_NOT_NULL(buf);
|
||||
if (len > 0) {
|
||||
TEST_ASSERT_TRUE_MESSAGE(lseek(fd, 0, SEEK_SET) == 0,
|
||||
"fixture: rewind of capture file must "
|
||||
"succeed");
|
||||
ssize_t nread = read(fd, buf, (size_t)len);
|
||||
TEST_ASSERT_TRUE_MESSAGE(nread == len,
|
||||
"fixture: reading back captured buffer "
|
||||
"must succeed");
|
||||
}
|
||||
close(fd);
|
||||
unlink(tmp);
|
||||
|
||||
return buf;
|
||||
}
|
||||
|
||||
typedef struct {
|
||||
cluster_t* c;
|
||||
worker_t* w;
|
||||
xce_resval_t* val;
|
||||
} update_resvals_call_ctx_t;
|
||||
|
||||
static void call_update_resvals_1(void* ctx_)
|
||||
{
|
||||
update_resvals_call_ctx_t* ctx = (update_resvals_call_ctx_t*)ctx_;
|
||||
update_resvals(ctx->c, ctx->w, 1, ctx->val);
|
||||
}
|
||||
|
||||
/*
|
||||
* update_resval() returns its failure reason as a raw negative code
|
||||
* directly (key_find/zarray_put convention -- never via errno), so
|
||||
* update_resvals()/update_resval_list() logging it via PERROR (which reads
|
||||
* the process-global errno) reported whatever errno happened to be left
|
||||
* over from an unrelated earlier call: "Success" if nothing had touched
|
||||
* it, or a stray EAGAIN/etc from some other syscall in the same event-loop
|
||||
* iteration -- never the real reason a resource update failed. This test
|
||||
* reproduces that exact symptom (ambient errno=EAGAIN, unrelated to the
|
||||
* genuine failure) and proves the fix decodes the actual rc instead.
|
||||
*/
|
||||
static void test_update_resvals_logs_actual_rc_not_stale_errno(void)
|
||||
{
|
||||
setup_test_cluster();
|
||||
|
||||
hostattrs_t attrs;
|
||||
memset(&attrs, 0, sizeof(attrs));
|
||||
attrs.hosttype = makeString("LINUX");
|
||||
attrs.hostmodel = makeString("x86");
|
||||
worker_t* w = make_test_worker("host-resval-log", &attrs);
|
||||
TEST_ASSERT_NOT_NULL(w);
|
||||
|
||||
xce_val_t fval;
|
||||
memset(&fval, 0, sizeof(fval));
|
||||
fval.which = Value_u_fvalue;
|
||||
fval.u.fvalue = 1.0f;
|
||||
|
||||
xce_resval_t val;
|
||||
val.name = "does-not-exist-in-resmgr";
|
||||
val.val = &fval;
|
||||
|
||||
/* Simulate the exact reported symptom: ambient errno unrelated to the
|
||||
* real failure, left over from some other unrelated call. */
|
||||
errno = EAGAIN;
|
||||
|
||||
update_resvals_call_ctx_t ctx = { .c = &g_tc.c, .w = w, .val = &val };
|
||||
char* captured = capture_stdout_during(call_update_resvals_1, &ctx);
|
||||
|
||||
TEST_ASSERT_NOT_NULL(captured);
|
||||
TEST_ASSERT_NULL_MESSAGE(
|
||||
strstr(captured, "Resource temporarily unavailable"),
|
||||
"must not log the ambient errno's string (EAGAIN) -- that is not "
|
||||
"why update_resval failed");
|
||||
TEST_ASSERT_NULL_MESSAGE(
|
||||
strstr(captured, "Success"),
|
||||
"must not log \"Success\" for a call that returned rc<0");
|
||||
TEST_ASSERT_NOT_NULL_MESSAGE(
|
||||
strstr(captured, "does-not-exist-in-resmgr"),
|
||||
"must name which resource failed");
|
||||
TEST_ASSERT_NOT_NULL_MESSAGE(
|
||||
strstr(captured, "No such file or directory"),
|
||||
"must log the real reason (-ENOENT, from key_find on an "
|
||||
"unregistered resource name)");
|
||||
|
||||
free(captured);
|
||||
teardown_test_cluster();
|
||||
printf("test_update_resvals_logs_actual_rc_not_stale_errno: PASS\n");
|
||||
}
|
||||
|
||||
/* ── Task 1.1: Tests for apply_join_state ──────────────────────────── */
|
||||
|
||||
/*
|
||||
|
|
@ -295,6 +422,60 @@ static void test_apply_join_state_updates_resource_values(void)
|
|||
printf("test_apply_join_state_updates_resource_values: PASS\n");
|
||||
}
|
||||
|
||||
/*
|
||||
* hconfig.mxj == -1 is the schema's documented "auto-detect" sentinel
|
||||
* (hosts.schema.json: "max_slot": {"minimum": -1, "description": "-1 means
|
||||
* auto-detect"}) -- apply_join_state must fall back to the worker's own
|
||||
* reported maxcpus, NOT persist -1 (or, before the xceadmin mapping fix,
|
||||
* silently ship 0 and permanently disable scheduling on that host: mxj is
|
||||
* UInt32 on the wire, so an unset/absent max_slot used to decode as 0,
|
||||
* which is not < 0 and so never reached this fallback -- see
|
||||
* xcecommon.mapping.HOSTCONFIG_MXJ_AUTO_DETECT). This is the ONLY test in
|
||||
* this file that exercises the nslots<0 branch; every sibling test above
|
||||
* uses a positive hconfig.mxj and so cannot catch a regression here.
|
||||
*/
|
||||
static void test_apply_join_state_mxj_negative_one_falls_back_to_maxcpus(void)
|
||||
{
|
||||
setup_test_cluster();
|
||||
|
||||
hostattrs_t attrs;
|
||||
memset(&attrs, 0, sizeof(attrs));
|
||||
attrs.hosttype = makeString("LINUX");
|
||||
attrs.hostmodel = makeString("x86");
|
||||
attrs.cpufactor = 1.0f;
|
||||
attrs.maxcpus = 12;
|
||||
attrs.maxmem = 64;
|
||||
attrs.maxswap = 128;
|
||||
attrs.maxtmp = 256;
|
||||
attrs.ndisks = 2;
|
||||
|
||||
worker_t* w = make_test_worker("host-ajs-autodetect", &attrs);
|
||||
TEST_ASSERT_NOT_NULL(w);
|
||||
|
||||
xce_hostconfig_t hconfig;
|
||||
memset(&hconfig, 0, sizeof(hconfig));
|
||||
hconfig.hosttype = (char*)"!";
|
||||
hconfig.hostmodel = (char*)"!";
|
||||
hconfig.mxj = -1;
|
||||
|
||||
endpoint_t ep;
|
||||
memset(&ep, 0, sizeof(ep));
|
||||
|
||||
lock(w, RTTI_LOCK_WRITE);
|
||||
int rc = apply_join_state(&g_tc.c, w, &ep, &hconfig);
|
||||
unlock(w);
|
||||
|
||||
TEST_ASSERT_EQUAL_INT(0, rc);
|
||||
TEST_ASSERT_EQUAL_FLOAT_MESSAGE(
|
||||
12.0f, get_worker_res_fval(w, "slots"),
|
||||
"mxj=-1 must auto-detect slots from the worker's reported maxcpus, "
|
||||
"not persist -1 or silently leave slots at 0");
|
||||
|
||||
teardown_test_cluster();
|
||||
printf("test_apply_join_state_mxj_negative_one_falls_back_to_maxcpus: "
|
||||
"PASS\n");
|
||||
}
|
||||
|
||||
/* ── Task 1.2: Tests for init_worker ────────────────────────────────── */
|
||||
|
||||
/*
|
||||
|
|
@ -520,10 +701,13 @@ void test_worker_join(void)
|
|||
/* xstring_table_init must be called once before any makeString usage */
|
||||
xstring_table_init(139);
|
||||
|
||||
RUN_TEST(test_update_resvals_logs_actual_rc_not_stale_errno);
|
||||
|
||||
/* Task 1.1: apply_join_state (shared status/resource update) */
|
||||
RUN_TEST(test_apply_join_state_clears_unavail);
|
||||
RUN_TEST(test_apply_join_state_applies_hosttype_override);
|
||||
RUN_TEST(test_apply_join_state_updates_resource_values);
|
||||
RUN_TEST(test_apply_join_state_mxj_negative_one_falls_back_to_maxcpus);
|
||||
|
||||
/* Task 1.2: init_worker (first-time join) */
|
||||
RUN_TEST(test_init_worker_creates_new_entry);
|
||||
|
|
|
|||
|
|
@ -115,7 +115,7 @@ static int update_resval(cluster_t* c, worker_t* w, xce_resval_t* val)
|
|||
}
|
||||
if (r == NULL) {
|
||||
ERROR("resource `%s' can not be found", val->name);
|
||||
return -errno;
|
||||
return -ENOENT;
|
||||
}
|
||||
|
||||
if (r->idx < 0) {
|
||||
|
|
@ -130,6 +130,24 @@ static int update_resval(cluster_t* c, worker_t* w, xce_resval_t* val)
|
|||
return rc;
|
||||
}
|
||||
|
||||
/*
|
||||
* update_resval() returns its failure reason as a raw negative code
|
||||
* directly (key_find/zarray_put convention throughout this codebase --
|
||||
* never via errno), so logging it with PERROR (which reads the process-
|
||||
* global errno) reported whatever errno happened to be left over from an
|
||||
* unrelated earlier call -- "Success" if nothing had touched it, or a
|
||||
* stray EAGAIN/etc from some other syscall in the same event-loop
|
||||
* iteration, never the real reason. Decode the actual rc instead.
|
||||
*/
|
||||
static void log_update_resval_failure(const char* name, int rc)
|
||||
{
|
||||
char ebuf[128];
|
||||
|
||||
ebuf[0] = '\0';
|
||||
xce_strerror_r(-rc, ebuf, sizeof(ebuf));
|
||||
ERROR("update_resval `%s': %s", name, ebuf);
|
||||
}
|
||||
|
||||
int update_resvals(cluster_t* c, worker_t* w, int nres, xce_resval_t* vals)
|
||||
{
|
||||
int rc = 0;
|
||||
|
|
@ -138,7 +156,7 @@ int update_resvals(cluster_t* c, worker_t* w, int nres, xce_resval_t* vals)
|
|||
for (i = 0; i < nres; i++) {
|
||||
rc = update_resval(c, w, &(vals[i]));
|
||||
if (rc < 0) {
|
||||
PERROR("update_resval");
|
||||
log_update_resval_failure(vals[i].name, rc);
|
||||
}
|
||||
}
|
||||
|
||||
|
|
@ -153,7 +171,7 @@ int update_resval_list(cluster_t* c, worker_t* w, xce_resval_list_t* l)
|
|||
for (i = 0; i < l->count; i++) {
|
||||
rc = update_resval(c, w, l->vals[i]);
|
||||
if (rc < 0) {
|
||||
PERROR("update_resval");
|
||||
log_update_resval_failure(l->vals[i]->name, rc);
|
||||
}
|
||||
}
|
||||
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue