chore(buglog): bug-1873 fixed (44173f74); pc13v retest recorded for bug-1872..1877

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

.wolf/bugs/bug-1873.md

@@ -0,0 +1,55 @@
+---
+id: "bug-1873"
+status: "fixed"
+status_updated: "2026-09-28"
+status_note: ""
+component: "worker"
+severity: "noise"
+timestamp: "2026-09-28T03:55:19Z"
+last_seen: "2026-09-28T03:58:45Z"
+occurrences: 1
+files: ["src/worker/src/xcecd_dbus_manager.c", "src/worker/src/xcecd.c"]
+tags: ["worker", "systemd", "dbus", "logging"]
+related: []
+fix_commits: ["44173f74"]
+---
+
+# bug-1873: xcecd warns 'Failed to get worker pid' on every job start while systemd forks the unit
+
+## Description
+**Observed:**
+```
+[2026-09-28 11:55:19,212][ WARN][xcecd_dbus_manager.c:139 ] Failed to get worker pid
+(13 such lines in 3 bursts, 11:55:19, 11:57:00, 11:58:44 -- one burst per batch of job starts; no ERROR followed, so every job did start)
+```
+**Expected:** no warning when the pid is simply not known yet and the retry finds it.
+**Impact:** WARN lines on every job start that look like failures; noise only.
+**Found by:** user report from a pc13v HA deploy, 2026-09-28
+
+## Environment
+- OS: NixOS 26.05 (Yarara); 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: debug (build.dbg)
+- Code: scheduler-framework, a build before 44173f74 (exact commit of the 11:52 run not recorded; environment read at 4c134127 with `buglog.py env src/build.dbg/worker/xcecd`)
+- Deployment: pc13v: 3-node HA (ctrl-1..3) + scheduler + apiserver, real root xcecd running jobs as systemd transient units, deploy dir /tmp/xce-ha-deploy
+
+## Reproduction
+1. Deploy on a systemd host with a real (root) xcecd
+2. Submit jobs; watch xcecd.log for 'Failed to get worker pid' at each start
+- Frequency: deterministic on pc13v (every burst of job starts, 13/13 in the 2026-09-28 run)
+- Evidence: the xcecd.log lines pasted in the user's report, quoted above
+
+## Root cause
+After xcecd asks systemd to start the job's transient unit (xcecd-worker-<jobid>.service), it reads the unit's MainPID over D-Bus (get_systemd_job_pid(), xcecd_cgroups.c). systemd forks the unit asynchronously, so MainPID is still 0 on the first read. dbus_get_worker_pid() (xcecd_dbus_manager.c) logged every 0 as a WARN, although its caller (xcecd.c) already retries 5 times, 100 ms apart, and only gives up -- with its own ERROR -- after that.
+
+## Fix
+dbus_get_worker_pid() logs the expected miss at DEBUG, with the unit name; the caller's final ERROR now names the unit and the retry count.
+
+## Verification
+- Test: none automated -- the path needs a real systemd and D-Bus (the sandbox runs xcecd_virtual, which fakes the pid); the change is a log-level change only
+- Suites: full ASAN build (xce-build all): 113/113 suites, worker included
+- Live: pc13v retest at 4c134127 (debug build, 2026-09-28 14:47 +0800): `ag -i error logs/` finds nothing; `ag -i warn logs/` shows only the WAL-unencrypted advisory; no 'Failed to get worker pid'
+
+## References
+- Related: none