From 244148acef4d78e6178b25486b150b133ce28510 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Mon, 28 Sep 2026 04:37:51 +0000 Subject: [PATCH] chore(buglog): log bug-1872, bug-1874..1877 fixed (44173f74) bug-1873 (systemd pid race) is held back until pc13v's environment is recorded. Co-Authored-By: Claude Opus 5.5 (1M context) --- .wolf/buglog.json | 134 +++++++++++++++++++++++++++++++++++++++++ .wolf/bugs/bug-1872.md | 55 +++++++++++++++++ .wolf/bugs/bug-1874.md | 54 +++++++++++++++++ .wolf/bugs/bug-1875.md | 54 +++++++++++++++++ .wolf/bugs/bug-1876.md | 56 +++++++++++++++++ .wolf/bugs/bug-1877.md | 54 +++++++++++++++++ 6 files changed, 407 insertions(+) create mode 100644 .wolf/bugs/bug-1872.md create mode 100644 .wolf/bugs/bug-1874.md create mode 100644 .wolf/bugs/bug-1875.md create mode 100644 .wolf/bugs/bug-1876.md create mode 100644 .wolf/bugs/bug-1877.md diff --git a/.wolf/buglog.json b/.wolf/buglog.json index c68ffac1..328270f7 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -15887,6 +15887,140 @@ "record": ".wolf/bugs/bug-1871.md", "gitea_issue": 297, "gitea_synced_status": "investigating" + }, + { + "id": "bug-1872", + "status": "fixed", + "status_updated": "2026-09-28", + "status_note": "", + "component": "worker", + "severity": "wrong-result", + "timestamp": "2026-09-28T03:52:37Z", + "last_seen": "2026-09-28T03:58:49Z", + "occurrences": 1, + "error_message": "xcecd logs 'Failed to find any disk statistics' every 15 s on NVMe-only hosts; io never reported\n\n**Observed:**\n```\n[2026-09-28 11:53:03,567][ERROR][node_information.c:951 ] Failed to find any disk statistics in /proc/diskstats\n(repeated every 15 s; pc13v's /proc/diskstats lists nvme0n1, nvme0n1p1, nvme0n1p2, loop0..loop7)\n```\n**Expected:** the io metric computed from nvme0n1's sector counters, no error.\n**Impact:** the `io` resource is never reported on a host whose disks are all NVMe or mmc (also any `sd*` name containing 'p', e.g. sdp), and xcecd logs an ERROR every 15 s. Likely the real cause of the io=0 readings in bug-1586.\n**Found by:** user report from a pc13v HA deploy, 2026-09-28", + "file": "src/worker/src/node_information.c, src/worker/include/diskstats.h", + "root_cause": "read_disk_io_rate() (src/worker/src/node_information.c) decided whole disks by name: it skipped names starting loop/ram/dm-, names containing 'p', and names longer than 3 characters ending in a digit. Every NVMe disk (nvme0n1) ends in a digit and contains 'p' in its partitions only, so the disk itself was skipped for the digit; mmcblk0 likewise; sdp for its 'p'. With no disk counted it returned -1 and logged ERROR each sample. Pre-existing, origin unknown.", + "fix": "src/worker/include/diskstats.h: diskstats_sum_physical() counts a device only when /sys/block//device exists -- the kernel's own mark of a real disk; partitions are not in /sys/block and loop, ram, zram, dm- and md devices have no `device` (counting dm/md would double-count I/O already seen on their member disks). node_information.c uses it and warns once, not every 15 s, when a host really has no physical disk.\n\nVerification:\n- Test: test_nvme_disk_is_counted_and_its_partitions_are_not (pc13v's /proc/diskstats) and test_sd_mmc_and_names_with_p_are_disks_virtual_ones_are_not in src/worker/testsuite/test_diskstats.c: both RED against the old name filter (0 disks; sdp/mmcblk0 missed), GREEN after; plus two more cases\n- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS\n- Live: pending: user retest on pc13v (real root xcecd); the sandbox only runs xcecd_virtual", + "tags": [ + "worker", + "io", + "diskstats", + "nvme" + ], + "related_bugs": [ + "bug-1586" + ], + "fix_commits": [ + "44173f74" + ], + "record": ".wolf/bugs/bug-1872.md" + }, + { + "id": "bug-1874", + "status": "fixed", + "status_updated": "2026-09-28", + "status_note": "", + "component": "scheduler", + "severity": "noise", + "timestamp": "2026-09-28T03:52:37Z", + "last_seen": "2026-09-28T03:58:49Z", + "occurrences": 1, + "error_message": "scheduler warns about deprecated job_elect_fn for xce_sched_fcfs on every start\n\n**Observed:**\n```\n[2026-09-28 11:52:49,740] [51152] [ WARN] [ plugin_register] plugin 'xce_sched_fcfs' selects jobs via the deprecated job_elect_fn hook; migrate to xce_job_picker_iface_t (scheduler-core spec, Req 5 'Migration from old job_elect_fn')\n```\n**Expected:** no warning: the normal-mode job picker is builtin_fcfs, not the legacy plugin.\n**Impact:** a WARN on every scheduler start that asks the operator to migrate something they do not use; noise only.\n**Found by:** user report from a pc13v HA deploy, 2026-09-28", + "file": "src/scheduler/src/plugin.c, src/scheduler/src/schedobj.c", + "root_cause": "sched_register_plugins() (scheduler.c) registers the legacy xce_sched_fcfs plugin on every start alongside builtin_fcfs, and plugin_register() (plugin.c) warned for every job_elect_fn-only plugin it adapted to the picker interface, whether or not that plugin would ever be selected. In normal mode the picker is always builtin_fcfs (sched_set_default_job_pick_plugin()); only --sim can name another.", + "fix": "plugin_register() still adapts a job_elect_fn plugin but only marks it (plugin->legacy_picker); sched_resolve_job_picker() (schedobj.c) logs the deprecation once (legacy_picker_warned) when such a plugin is actually selected as the picker.\n\nVerification:\n- Test: test_legacy_picker_deprecation_flagged_on_selection_not_registration in src/scheduler/testsuite/test_picker_wiring.c (new: registration leaves legacy_picker_warned unset, selection sets it) and test_register_legacy_job_elect_fn_only_plugin_uses_wrapper_without_warning in test_plugin_picker_registration.c, which captures the log: 0 warnings at registration (it asserted 1 before the change)\n- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS\n- Live: pending: user retest on pc13v (scheduler log)", + "tags": [ + "scheduler", + "plugin", + "picker", + "logging" + ], + "related_bugs": [], + "fix_commits": [ + "44173f74" + ], + "record": ".wolf/bugs/bug-1874.md" + }, + { + "id": "bug-1875", + "status": "fixed", + "status_updated": "2026-09-28", + "status_note": "", + "component": "apiserver", + "severity": "noise", + "timestamp": "2026-09-28T03:52:37Z", + "last_seen": "2026-09-28T03:58:49Z", + "occurrences": 1, + "error_message": "apiserver warns PAM needs root when the auth provider is not pam\n\n**Observed:**\n```\n2026-09-28T11:52:50.031+0800 WARN Not running as root — PAM authentication will not work. OK for dev/testing.\n```\n**Expected:** no warning when the configured auth provider is not pam (the default config/auth.yaml has `provider: config_file`).\n**Impact:** a misleading WARN on every non-root apiserver start; noise only.\n**Found by:** user report from a pc13v HA deploy, 2026-09-28", + "file": "src/frontend/apiserver/middleware/startserver.go", + "root_cause": "StartServer() (src/frontend/apiserver/middleware/startserver.go) warned whenever the uid was not 0, without looking at which auth provider cmd/main.go had initialized (auth.GlobalProvider) -- only the PAM provider needs root.", + "fix": "rootWarning(uid, provider) returns the warning only for provider \"pam\" and a non-root uid; StartServer() passes auth.GlobalProvider.Name().\n\nVerification:\n- Test: TestRootWarning in src/frontend/apiserver/middleware/startserver_test.go (5 uid/provider cases): RED before the fix (rootWarning did not exist), GREEN after; run with `CGO_ENABLED=0 go test ./middleware/ -run TestRootWarning` (the package's TestLoadJobs needs a live apiserver and is not part of the normal Go test set)\n- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS\n- Live: pending: user retest on pc13v (apiserver log)", + "tags": [ + "apiserver", + "auth", + "pam", + "logging" + ], + "related_bugs": [], + "fix_commits": [ + "44173f74" + ], + "record": ".wolf/bugs/bug-1875.md" + }, + { + "id": "bug-1876", + "status": "fixed", + "status_updated": "2026-09-28", + "status_note": "", + "component": "controller", + "severity": "noise", + "timestamp": "2026-09-28T03:52:37Z", + "last_seen": "2026-09-28T03:58:49Z", + "occurrences": 1, + "error_message": "standby logs cluster_init_phase2 failed (rc=-22) WARN every 3 s while awaiting the primary's config\n\n**Observed:**\n```\n[2026-09-28 11:52:38,939] [51034] [ WARN] [ myapp_run] myapp_run: cluster_init_phase2 on standby rejoin failed (rc=-22) — WAL not recovered; member stays alive and will retry (bug-1477: ...)\n[2026-09-28 11:52:41,941] [51034] [ WARN] [ ha_phase2_retry_fn] HA: cluster_init_phase2 retry rc=-22 — member stays alive and will retry again (bug-1477, never self-terminate)\n(ctrl-2 and ctrl-3, every 3 s until 11:52:47)\n```\n**Expected:** the standby waits for the primary's config push quietly (INFO), as cluster_init_phase2() itself describes that state.\n**Impact:** WARN lines on every cold start of every standby that read like a failed WAL recovery; noise, but alarming.\n**Found by:** user report from a pc13v HA deploy, 2026-09-28", + "file": "src/controller/cluster.c, src/controller/myapp.c, src/controller/ha.c", + "root_cause": "cluster_init_phase2() (controller/cluster.c) returns early when c->myconf->cluster_config is still NULL -- a standby that has not received the primary's config push yet -- and logs that at INFO as normal, but returned -EINVAL. Both callers, myapp_run()'s standby-rejoin path (myapp.c) and ha_phase2_retry_fn() (ha.c), treat any nonzero result as a failure and log WARN with rc=-22.", + "fix": "cluster_init_phase2() returns -EAGAIN for that wait; ha_phase2_rc_is_waiting() (ha.h) names it, and myapp_run() and ha_phase2_retry_fn() log it at INFO while other failures still WARN. The promotion-refused path in ha.c keeps its WARN.\n\nVerification:\n- Test: test_phase2_without_config_is_a_wait_not_an_error in src/controller/testsuite/test_phase2_cold_boot.c: cluster_init_phase2() with no cluster_config returns -EAGAIN (it returned -EINVAL before), and ha_phase2_rc_is_waiting() accepts only -EAGAIN\n- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS\n- Live: pending: user retest on pc13v (standby logs on a fresh deploy)", + "tags": [ + "controller", + "ha", + "cold-boot", + "logging" + ], + "related_bugs": [ + "bug-1477" + ], + "fix_commits": [ + "44173f74" + ], + "record": ".wolf/bugs/bug-1876.md" + }, + { + "id": "bug-1877", + "status": "fixed", + "status_updated": "2026-09-28", + "status_note": "", + "component": "controller", + "severity": "noise", + "timestamp": "2026-09-28T03:52:37Z", + "last_seen": "2026-09-28T03:58:49Z", + "occurrences": 1, + "error_message": "controller warns 'WAL/snapshot stored unencrypted' without checking the storage\n\n**Observed:**\n```\n[2026-09-28 11:52:37,938] [51034] [ WARN] [ persist_init] WAL/snapshot stored unencrypted in /tmp/xce-ha-deploy/controller/ctrl-3/data/wal — ensure filesystem is encrypted if job payloads contain sensitive data\n```\n**Expected:** the warning only when the WAL's storage is not encrypted.\n**Impact:** the advisory fired on encrypted storage too, so it carried no information. On pc13v (/tmp, not shown to be encrypted) it still correctly appears after the fix.\n**Found by:** user report from a pc13v HA deploy, 2026-09-28", + "file": "src/controller/persist.c", + "root_cause": "persist_init() (controller/persist.c) logged the warning unconditionally.", + "fix": "persist_path_encrypted() checks the WAL directory for fscrypt (statx STATX_ATTR_ENCRYPTED) and its block device for a dm-crypt layer via sysfs (dm/uuid starting CRYPT-), following `slaves` so LVM on LUKS counts (persist_dev_is_dmcrypt()). Encrypted storage is logged at INFO; anything not shown to be encrypted keeps the WARN.\n\nVerification:\n- Test: test_luks_device_is_encrypted, test_lvm_on_luks_is_encrypted, test_plain_partition_and_plain_lvm_are_not and test_unknown_device_is_not_claimed_encrypted in src/controller/testsuite/test_persist_encryption.c, against a fake sysfs tree (new functions; there was no check before)\n- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS\n- Live: n/a here (no encrypted volume on this host); on pc13v the warning is expected to remain for /tmp", + "tags": [ + "controller", + "persistence", + "encryption", + "logging" + ], + "related_bugs": [], + "fix_commits": [ + "44173f74" + ], + "record": ".wolf/bugs/bug-1877.md" } ] } diff --git a/.wolf/bugs/bug-1872.md b/.wolf/bugs/bug-1872.md new file mode 100644 index 00000000..f8a1aeed --- /dev/null +++ b/.wolf/bugs/bug-1872.md @@ -0,0 +1,55 @@ +--- +id: "bug-1872" +status: "fixed" +status_updated: "2026-09-28" +status_note: "" +component: "worker" +severity: "wrong-result" +timestamp: "2026-09-28T03:52:37Z" +last_seen: "2026-09-28T03:58:49Z" +occurrences: 1 +files: ["src/worker/src/node_information.c", "src/worker/include/diskstats.h"] +tags: ["worker", "io", "diskstats", "nvme"] +related: ["bug-1586"] +fix_commits: ["44173f74"] +--- + +# bug-1872: xcecd logs 'Failed to find any disk statistics' every 15 s on NVMe-only hosts; io never reported + +## Description +**Observed:** +``` +[2026-09-28 11:53:03,567][ERROR][node_information.c:951 ] Failed to find any disk statistics in /proc/diskstats +(repeated every 15 s; pc13v's /proc/diskstats lists nvme0n1, nvme0n1p1, nvme0n1p2, loop0..loop7) +``` +**Expected:** the io metric computed from nvme0n1's sector counters, no error. +**Impact:** the `io` resource is never reported on a host whose disks are all NVMe or mmc (also any `sd*` name containing 'p', e.g. sdp), and xcecd logs an ERROR every 15 s. Likely the real cause of the io=0 readings in bug-1586. +**Found by:** user report from a pc13v HA deploy, 2026-09-28 + +## 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 @ 8cadeeb2 (last commit without the fix) +- Deployment: first seen on pc13v: 3-node HA (ctrl-1..3) + scheduler + apiserver + real root xcecd under systemd, deploy dir /tmp/xce-ha-deploy, 2026-09-28 11:52 +0800 (pc13v's OS, libc and exact commit were not recorded; the values above are from the reproduction on this dev host, same nix toolchain) + +## Reproduction +1. `/xce-build worker` +2. At 8cadeeb2 put the old filter in `src/worker/include/diskstats.h` (the name test from node_information.c) and run `ASAN_OPTIONS=detect_leaks=0 src/xce.build/worker/testsuite/diskstats_test`, which feeds pc13v's /proc/diskstats +- Frequency: deterministic +- Evidence: the xcecd/scheduler/controller/apiserver logs pasted in the user's report, 2026-09-28 (quoted above) + +## Root cause +read_disk_io_rate() (src/worker/src/node_information.c) decided whole disks by name: it skipped names starting loop/ram/dm-, names containing 'p', and names longer than 3 characters ending in a digit. Every NVMe disk (nvme0n1) ends in a digit and contains 'p' in its partitions only, so the disk itself was skipped for the digit; mmcblk0 likewise; sdp for its 'p'. With no disk counted it returned -1 and logged ERROR each sample. Pre-existing, origin unknown. + +## Fix +src/worker/include/diskstats.h: diskstats_sum_physical() counts a device only when /sys/block//device exists -- the kernel's own mark of a real disk; partitions are not in /sys/block and loop, ram, zram, dm- and md devices have no `device` (counting dm/md would double-count I/O already seen on their member disks). node_information.c uses it and warns once, not every 15 s, when a host really has no physical disk. + +## Verification +- Test: test_nvme_disk_is_counted_and_its_partitions_are_not (pc13v's /proc/diskstats) and test_sd_mmc_and_names_with_p_are_disks_virtual_ones_are_not in src/worker/testsuite/test_diskstats.c: both RED against the old name filter (0 disks; sdp/mmcblk0 missed), GREEN after; plus two more cases +- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS +- Live: pending: user retest on pc13v (real root xcecd); the sandbox only runs xcecd_virtual + +## References +- Related: bug-1586 diff --git a/.wolf/bugs/bug-1874.md b/.wolf/bugs/bug-1874.md new file mode 100644 index 00000000..7198eac9 --- /dev/null +++ b/.wolf/bugs/bug-1874.md @@ -0,0 +1,54 @@ +--- +id: "bug-1874" +status: "fixed" +status_updated: "2026-09-28" +status_note: "" +component: "scheduler" +severity: "noise" +timestamp: "2026-09-28T03:52:37Z" +last_seen: "2026-09-28T03:58:49Z" +occurrences: 1 +files: ["src/scheduler/src/plugin.c", "src/scheduler/src/schedobj.c"] +tags: ["scheduler", "plugin", "picker", "logging"] +related: [] +fix_commits: ["44173f74"] +--- + +# bug-1874: scheduler warns about deprecated job_elect_fn for xce_sched_fcfs on every start + +## Description +**Observed:** +``` +[2026-09-28 11:52:49,740] [51152] [ WARN] [ plugin_register] plugin 'xce_sched_fcfs' selects jobs via the deprecated job_elect_fn hook; migrate to xce_job_picker_iface_t (scheduler-core spec, Req 5 'Migration from old job_elect_fn') +``` +**Expected:** no warning: the normal-mode job picker is builtin_fcfs, not the legacy plugin. +**Impact:** a WARN on every scheduler start that asks the operator to migrate something they do not use; noise only. +**Found by:** user report from a pc13v HA deploy, 2026-09-28 + +## 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 @ 8cadeeb2 (last commit without the fix) +- Deployment: first seen on pc13v: 3-node HA (ctrl-1..3) + scheduler + apiserver + real root xcecd under systemd, deploy dir /tmp/xce-ha-deploy, 2026-09-28 11:52 +0800 (pc13v's OS, libc and exact commit were not recorded; the values above are from the reproduction on this dev host, same nix toolchain) + +## Reproduction +1. Start xce_scheduler at 8cadeeb2 (any deployment, e.g. `/xce-deploy-ha`) +2. `grep 'deprecated job_elect_fn' ` +- Frequency: deterministic (every start) +- Evidence: the xcecd/scheduler/controller/apiserver logs pasted in the user's report, 2026-09-28 (quoted above) + +## Root cause +sched_register_plugins() (scheduler.c) registers the legacy xce_sched_fcfs plugin on every start alongside builtin_fcfs, and plugin_register() (plugin.c) warned for every job_elect_fn-only plugin it adapted to the picker interface, whether or not that plugin would ever be selected. In normal mode the picker is always builtin_fcfs (sched_set_default_job_pick_plugin()); only --sim can name another. + +## Fix +plugin_register() still adapts a job_elect_fn plugin but only marks it (plugin->legacy_picker); sched_resolve_job_picker() (schedobj.c) logs the deprecation once (legacy_picker_warned) when such a plugin is actually selected as the picker. + +## Verification +- Test: test_legacy_picker_deprecation_flagged_on_selection_not_registration in src/scheduler/testsuite/test_picker_wiring.c (new: registration leaves legacy_picker_warned unset, selection sets it) and test_register_legacy_job_elect_fn_only_plugin_uses_wrapper_without_warning in test_plugin_picker_registration.c, which captures the log: 0 warnings at registration (it asserted 1 before the change) +- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS +- Live: pending: user retest on pc13v (scheduler log) + +## References +- Related: none diff --git a/.wolf/bugs/bug-1875.md b/.wolf/bugs/bug-1875.md new file mode 100644 index 00000000..98201765 --- /dev/null +++ b/.wolf/bugs/bug-1875.md @@ -0,0 +1,54 @@ +--- +id: "bug-1875" +status: "fixed" +status_updated: "2026-09-28" +status_note: "" +component: "apiserver" +severity: "noise" +timestamp: "2026-09-28T03:52:37Z" +last_seen: "2026-09-28T03:58:49Z" +occurrences: 1 +files: ["src/frontend/apiserver/middleware/startserver.go"] +tags: ["apiserver", "auth", "pam", "logging"] +related: [] +fix_commits: ["44173f74"] +--- + +# bug-1875: apiserver warns PAM needs root when the auth provider is not pam + +## Description +**Observed:** +``` +2026-09-28T11:52:50.031+0800 WARN Not running as root — PAM authentication will not work. OK for dev/testing. +``` +**Expected:** no warning when the configured auth provider is not pam (the default config/auth.yaml has `provider: config_file`). +**Impact:** a misleading WARN on every non-root apiserver start; noise only. +**Found by:** user report from a pc13v HA deploy, 2026-09-28 + +## 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, from src/xce.build/frontend/apiserver/xce_apiserver) +- Toolchain: gcc (GCC) 15.2.0, meson 1.9.1 +- Build: release-style Go build via meson (xce.build/frontend/apiserver/xce_apiserver) +- Code: scheduler-framework @ 8cadeeb2 (last commit without the fix) +- Deployment: first seen on pc13v: 3-node HA (ctrl-1..3) + scheduler + apiserver + real root xcecd under systemd, deploy dir /tmp/xce-ha-deploy, 2026-09-28 11:52 +0800 (pc13v's OS, libc and exact commit were not recorded; the values above are from the reproduction on this dev host, same nix toolchain) + +## Reproduction +1. Start the apiserver as a non-root user with the default src/frontend/apiserver/config/auth.yaml (provider: config_file) +2. The warning is logged at start +- Frequency: deterministic (every non-root start) +- Evidence: the xcecd/scheduler/controller/apiserver logs pasted in the user's report, 2026-09-28 (quoted above) + +## Root cause +StartServer() (src/frontend/apiserver/middleware/startserver.go) warned whenever the uid was not 0, without looking at which auth provider cmd/main.go had initialized (auth.GlobalProvider) -- only the PAM provider needs root. + +## Fix +rootWarning(uid, provider) returns the warning only for provider "pam" and a non-root uid; StartServer() passes auth.GlobalProvider.Name(). + +## Verification +- Test: TestRootWarning in src/frontend/apiserver/middleware/startserver_test.go (5 uid/provider cases): RED before the fix (rootWarning did not exist), GREEN after; run with `CGO_ENABLED=0 go test ./middleware/ -run TestRootWarning` (the package's TestLoadJobs needs a live apiserver and is not part of the normal Go test set) +- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS +- Live: pending: user retest on pc13v (apiserver log) + +## References +- Related: none diff --git a/.wolf/bugs/bug-1876.md b/.wolf/bugs/bug-1876.md new file mode 100644 index 00000000..54b43e09 --- /dev/null +++ b/.wolf/bugs/bug-1876.md @@ -0,0 +1,56 @@ +--- +id: "bug-1876" +status: "fixed" +status_updated: "2026-09-28" +status_note: "" +component: "controller" +severity: "noise" +timestamp: "2026-09-28T03:52:37Z" +last_seen: "2026-09-28T03:58:49Z" +occurrences: 1 +files: ["src/controller/cluster.c", "src/controller/myapp.c", "src/controller/ha.c"] +tags: ["controller", "ha", "cold-boot", "logging"] +related: ["bug-1477"] +fix_commits: ["44173f74"] +--- + +# bug-1876: standby logs cluster_init_phase2 failed (rc=-22) WARN every 3 s while awaiting the primary's config + +## Description +**Observed:** +``` +[2026-09-28 11:52:38,939] [51034] [ WARN] [ myapp_run] myapp_run: cluster_init_phase2 on standby rejoin failed (rc=-22) — WAL not recovered; member stays alive and will retry (bug-1477: ...) +[2026-09-28 11:52:41,941] [51034] [ WARN] [ ha_phase2_retry_fn] HA: cluster_init_phase2 retry rc=-22 — member stays alive and will retry again (bug-1477, never self-terminate) +(ctrl-2 and ctrl-3, every 3 s until 11:52:47) +``` +**Expected:** the standby waits for the primary's config push quietly (INFO), as cluster_init_phase2() itself describes that state. +**Impact:** WARN lines on every cold start of every standby that read like a failed WAL recovery; noise, but alarming. +**Found by:** user report from a pc13v HA deploy, 2026-09-28 + +## 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 @ 8cadeeb2 (last commit without the fix) +- Deployment: first seen on pc13v: 3-node HA (ctrl-1..3) + scheduler + apiserver + real root xcecd under systemd, deploy dir /tmp/xce-ha-deploy, 2026-09-28 11:52 +0800 (pc13v's OS, libc and exact commit were not recorded; the values above are from the reproduction on this dev host, same nix toolchain) + +## Reproduction +1. Deploy a fresh 3-node HA cluster at 8cadeeb2 (`/xce-deploy-ha`) +2. `grep 'cluster_init_phase2' ` during the first seconds +- Frequency: deterministic on a cold start (until the primary's config push arrives) +- Evidence: the xcecd/scheduler/controller/apiserver logs pasted in the user's report, 2026-09-28 (quoted above) + +## Root cause +cluster_init_phase2() (controller/cluster.c) returns early when c->myconf->cluster_config is still NULL -- a standby that has not received the primary's config push yet -- and logs that at INFO as normal, but returned -EINVAL. Both callers, myapp_run()'s standby-rejoin path (myapp.c) and ha_phase2_retry_fn() (ha.c), treat any nonzero result as a failure and log WARN with rc=-22. + +## Fix +cluster_init_phase2() returns -EAGAIN for that wait; ha_phase2_rc_is_waiting() (ha.h) names it, and myapp_run() and ha_phase2_retry_fn() log it at INFO while other failures still WARN. The promotion-refused path in ha.c keeps its WARN. + +## Verification +- Test: test_phase2_without_config_is_a_wait_not_an_error in src/controller/testsuite/test_phase2_cold_boot.c: cluster_init_phase2() with no cluster_config returns -EAGAIN (it returned -EINVAL before), and ha_phase2_rc_is_waiting() accepts only -EAGAIN +- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS +- Live: pending: user retest on pc13v (standby logs on a fresh deploy) + +## References +- Related: bug-1477 diff --git a/.wolf/bugs/bug-1877.md b/.wolf/bugs/bug-1877.md new file mode 100644 index 00000000..8673c4a5 --- /dev/null +++ b/.wolf/bugs/bug-1877.md @@ -0,0 +1,54 @@ +--- +id: "bug-1877" +status: "fixed" +status_updated: "2026-09-28" +status_note: "" +component: "controller" +severity: "noise" +timestamp: "2026-09-28T03:52:37Z" +last_seen: "2026-09-28T03:58:49Z" +occurrences: 1 +files: ["src/controller/persist.c"] +tags: ["controller", "persistence", "encryption", "logging"] +related: [] +fix_commits: ["44173f74"] +--- + +# bug-1877: controller warns 'WAL/snapshot stored unencrypted' without checking the storage + +## Description +**Observed:** +``` +[2026-09-28 11:52:37,938] [51034] [ WARN] [ persist_init] WAL/snapshot stored unencrypted in /tmp/xce-ha-deploy/controller/ctrl-3/data/wal — ensure filesystem is encrypted if job payloads contain sensitive data +``` +**Expected:** the warning only when the WAL's storage is not encrypted. +**Impact:** the advisory fired on encrypted storage too, so it carried no information. On pc13v (/tmp, not shown to be encrypted) it still correctly appears after the fix. +**Found by:** user report from a pc13v HA deploy, 2026-09-28 + +## 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 @ 8cadeeb2 (last commit without the fix) +- Deployment: first seen on pc13v: 3-node HA (ctrl-1..3) + scheduler + apiserver + real root xcecd under systemd, deploy dir /tmp/xce-ha-deploy, 2026-09-28 11:52 +0800 (pc13v's OS, libc and exact commit were not recorded; the values above are from the reproduction on this dev host, same nix toolchain) + +## Reproduction +1. Put a controller's workdir on a LUKS/dm-crypt or fscrypt filesystem at 8cadeeb2 +2. Start it: the warning is logged anyway (persist_init never checked) +- Frequency: deterministic (every controller start) +- Evidence: the xcecd/scheduler/controller/apiserver logs pasted in the user's report, 2026-09-28 (quoted above) + +## Root cause +persist_init() (controller/persist.c) logged the warning unconditionally. + +## Fix +persist_path_encrypted() checks the WAL directory for fscrypt (statx STATX_ATTR_ENCRYPTED) and its block device for a dm-crypt layer via sysfs (dm/uuid starting CRYPT-), following `slaves` so LVM on LUKS counts (persist_dev_is_dmcrypt()). Encrypted storage is logged at INFO; anything not shown to be encrypted keeps the WARN. + +## Verification +- Test: test_luks_device_is_encrypted, test_lvm_on_luks_is_encrypted, test_plain_partition_and_plain_lvm_are_not and test_unknown_device_is_not_claimed_encrypted in src/controller/testsuite/test_persist_encryption.c, against a fake sysfs tree (new functions; there was no check before) +- Suites: full ASAN build (xce-build all): 113/113 suites after the updated scheduler picker-registration test; controller 1250/0, harness 141/0, worker diskstats 4/0, scheduler picker wiring 11/0 + picker registration 4/0, apiserver TestRootWarning PASS +- Live: n/a here (no encrypted volume on this host); on pc13v the warning is expected to remain for /tmp + +## References +- Related: none