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) <noreply@anthropic.com>
This commit is contained in:
parent
44173f74ae
commit
244148acef
GPG key ID:
80533536B0EB651C
6 changed files with 407 additions and 0 deletions
|
|
@ -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/<name>/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"
|
||||
}
|
||||
]
|
||||
}
|
||||
|
|
|
|||
55
.wolf/bugs/bug-1872.md
Normal file
55
.wolf/bugs/bug-1872.md
Normal file
|
|
@ -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/<name>/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
|
||||
54
.wolf/bugs/bug-1874.md
Normal file
54
.wolf/bugs/bug-1874.md
Normal file
|
|
@ -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' <scheduler log>`
|
||||
- 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
|
||||
54
.wolf/bugs/bug-1875.md
Normal file
54
.wolf/bugs/bug-1875.md
Normal file
|
|
@ -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
|
||||
56
.wolf/bugs/bug-1876.md
Normal file
56
.wolf/bugs/bug-1876.md
Normal file
|
|
@ -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' <standby logs>` 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
|
||||
54
.wolf/bugs/bug-1877.md
Normal file
54
.wolf/bugs/bug-1877.md
Normal file
|
|
@ -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
|
||||
Loading…
Add table
Add a link
Reference in a new issue