Hi all, In case anybody is interested. After some heavy debugging I was able to bisect the issue to the following pull request (which was backported to v247) https://github.com/systemd/systemd/pull/18802#issuecomment-827707662 . I left comments there on what broke.
Thanks for the help either way! On Sat, Apr 24, 2021 at 5:03 PM Arian van Putten <[email protected]> wrote: > Dear list, > > I've been working on trying to integrate systemd-gpt-auto and > systemd-cryptsetup into NixOS's stage-1 init. > > Everything was working great on 246; but when I updated from kernel 5.4 > to 5.10 and from systemd 246 to 247, the setup stopped working. > > After entering my LUKS password, the boot keeps hanging with: > > A start job is running for /dev/gpt-auto-root > > and eventually fails with: > > [ TIME ] Timed out waiting for device /dev/gpt-auto-root. > > Interestingly. Both /dev/gpt-auto-root and /dev/gpt-auto-root-luks > exist in the /dev tree so the udev rules are all fired correctly; but for > some reason they are not propagating to the device unit. > Also the btrfs kernel module didn't seem to get automatically loaded for > some reason. > > For the failed boot on 247; this seems to be the interesting bit of the > log: > Apr 24 12:18:46 localhost systemd-udevd[209]: dm-0: Adding watch on > '/dev/dm-0' > Apr 24 12:18:46 localhost systemd-udevd[209]: dm-0: sd-device: Created db > file '/run/udev/data/b254:0' for '/devices/virtual/block/dm-0' > Apr 24 12:18:46 localhost systemd-udevd[209]: dm-0: Device (SEQNUM=1720, > ACTION=change) processed > Apr 24 12:18:46 localhost systemd-udevd[209]: dm-0: sd-device-monitor: > Passed 947 byte to netlink monitor > Apr 24 12:18:46 localhost systemd[1]: systemd-journald.service: Received > EPOLLHUP on stored fd 46 (stored), closing. > Apr 24 12:18:46 localhost systemd[1]: Received SIGCHLD from PID 192 > (systemd-cryptse). > Apr 24 12:18:46 localhost systemd[1]: Child 192 (systemd-cryptse) died > (code=exited, status=0/SUCCESS) > Apr 24 12:18:46 localhost systemd[1]: [email protected]: > Child 192 belongs to [email protected]. > Apr 24 12:18:46 localhost systemd[1]: [email protected]: > Main process exited, code=exited, status=0/SUCCESS > Apr 24 12:18:46 localhost systemd[1]: [email protected]: > Changed start -> exited > Apr 24 12:18:46 localhost systemd[1]: [email protected]: > Job 59 [email protected]/start finished, result=done > Apr 24 12:18:46 localhost systemd[1]: Finished Cryptography Setup for root. > Apr 24 12:18:46 localhost audit[1]: SERVICE_START pid=1 uid=0 > auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-cryptsetup@root > comm="systemd" > exe="/nix/store/ixpwj1cxl4rp2qbyn0s2h4k5zj731q7c-systemd-247.6/lib/systemd/systemd" > hostname=? addr=? terminal=? res=success' > Apr 24 12:18:46 localhost systemd[1]: [email protected]: > Control group is empty. > Apr 24 12:18:46 localhost systemd[1]: [email protected] > changed dead -> active > Apr 24 12:18:46 localhost systemd[1]: [email protected]: > Job 72 [email protected]/start finished, result=done > Apr 24 12:18:46 localhost systemd[1]: Reached target Block Device > Preparation for /dev/mapper/root. > Apr 24 12:18:46 localhost kernel: kauditd_printk_skb: 4 callbacks > suppressed > Apr 24 12:18:46 localhost kernel: audit: type=1130 > audit(1619266726.241:15): pid=1 uid=0 auid=4294967295 ses=4294967295 > subj=kernel msg='unit=systemd-cryptsetup@root comm="systemd" > exe="/nix/store/ixpwj1cxl4rp2qbyn0s2h4k5zj731q7c-systemd-247.6/lib/systemd/systemd" > hostname=? addr=? terminal=? res=success' > Apr 24 12:18:50 localhost systemd-udevd[148]: Cleanup idle workers > Apr 24 12:18:50 localhost systemd-udevd[207]: Unload module index > Apr 24 12:18:50 localhost systemd-udevd[209]: Unload module index > Apr 24 12:18:50 localhost systemd-udevd[205]: Unload module index > Apr 24 12:18:50 localhost systemd-udevd[206]: Unload module index > Apr 24 12:18:50 localhost systemd-udevd[207]: Unloaded link configuration > context. > Apr 24 12:18:50 localhost systemd-udevd[209]: Unloaded link configuration > context. > Apr 24 12:18:50 localhost systemd-udevd[205]: Unloaded link configuration > context. > Apr 24 12:18:50 localhost systemd-udevd[206]: Unloaded link configuration > context. > Apr 24 12:18:50 localhost systemd-udevd[148]: Worker [205] exited > Apr 24 12:18:50 localhost systemd-udevd[148]: Worker [206] exited > Apr 24 12:18:50 localhost systemd-udevd[148]: Worker [207] exited > Apr 24 12:18:50 localhost systemd-udevd[148]: Worker [209] exited > Apr 24 12:19:48 localhost systemd[1]: dev-gpt\x2dauto\x2droot.device: Job > dev-gpt\x2dauto\x2droot.device/start timed out. > Apr 24 12:19:48 localhost systemd[1]: dev-gpt\x2dauto\x2droot.device: Job > 56 dev-gpt\x2dauto\x2droot.device/start finished, result=timeout > Apr 24 12:19:48 localhost systemd[1]: Timed out waiting for device > /dev/gpt-auto-root. > Apr 24 12:19:48 localhost systemd[1]: initrd-root-device.target: Job 57 > initrd-root-device.target/start finished, result=dependency > Apr 24 12:19:48 localhost systemd[1]: Dependency failed for Initrd Root > Device. > Apr 24 12:19:48 localhost systemd[1]: initrd-root-device.target: Job > initrd-root-device.target/start failed with result 'dependency'. > > Whilst the successful boot on 246 looks like this: > > r 24 12:44:32 localhost systemd-cryptsetup[176]: root: retaining kernel > read ahead of 256 (requested 256) > Apr 24 12:44:32 localhost systemd-cryptsetup[176]: Releasing crypt device > /dev/gpt-auto-root-luks context. > Apr 24 12:44:32 localhost systemd-cryptsetup[176]: Releasing device-mapper > backend. > Apr 24 12:44:32 localhost systemd-udevd[193]: dm-0: Adding watch on > '/dev/dm-0' > Apr 24 12:44:32 localhost systemd-cryptsetup[176]: Closing read only fd > for /dev/gpt-auto-root-luks. > Apr 24 12:44:32 localhost systemd-udevd[193]: dm-0: sd-device: Created db > file '/run/udev/data/b254:0' for '/devices/virtual/block/dm-0' > Apr 24 12:44:32 localhost systemd-udevd[193]: dm-0: Device (SEQNUM=2066, > ACTION=change) processed > Apr 24 12:44:32 localhost systemd-udevd[193]: dm-0: sd-device-monitor: > Passed 891 byte to netlink monitor > Apr 24 12:44:32 localhost systemd[1]: dev-gpt\x2dauto\x2droot.device: > Changed dead -> plugged > Apr 24 12:44:32 localhost systemd[1]: dev-gpt\x2dauto\x2droot.device: Job > 52 dev-gpt\x2dauto\x2droot.device/start finished, result=done > Apr 24 12:44:32 localhost systemd[1]: Found device /dev/gpt-auto-root. > Apr 24 12:44:32 localhost systemd[1]: > dev-disk-by\x2did-dm\x2dname\x2droot.device: Changed dead -> plugged > Apr 24 12:44:32 localhost systemd[1]: > dev-disk-by\x2did-dm\x2duuid\x2dCRYPT\x2dLUKS1\x2d0c642ebc2b7643dcb9ba34f1125d7f16\x2droot.device: > Changed dead -> plugged > Apr 24 12:44:32 localhost systemd[1]: dev-mapper-root.device: Changed dead > -> plugged > Apr 24 12:44:32 localhost systemd[1]: > dev-disk-by\x2duuid-5cb38441\x2d7012\x2d4aaf\x2da70c\x2db11aaaa212d3.device: > Changed dead -> plugged > Apr 24 12:44:32 localhost systemd[1]: dev-dm\x2d0.device: Changed dead -> > plugged > Apr 24 12:44:32 localhost systemd[1]: > sys-devices-virtual-block-dm\x2d0.device: Changed dead -> plugged > Apr 24 12:44:32 localhost systemd[1]: Received SIGCHLD from PID 176 > (systemd-cryptse). > Apr 24 12:44:32 localhost systemd[1]: Child 176 (systemd-cryptse) died > (code=exited, status=0/SUCCESS) > Apr 24 12:44:32 localhost systemd[1]: [email protected]: > Failed to read oom_kill field of memory.events cgroup attribute: No such > file or directory > Apr 24 12:44:32 localhost systemd[1]: [email protected]: > Child 176 belongs to [email protected]. > Apr 24 12:44:32 localhost systemd[1]: [email protected]: > Main process exited, code=exited, status=0/SUCCESS > Apr 24 12:44:32 localhost systemd[1]: [email protected]: > Changed start -> exited > Apr 24 12:44:32 localhost systemd[1]: [email protected]: > Job 56 [email protected]/start finished, result=done > Apr 24 12:44:32 localhost systemd[1]: Finished Cryptography Setup for root. > Apr 24 12:44:32 localhost audit[1]: SERVICE_START pid=1 uid=0 > auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-cryptsetup@root > comm="systemd" > exe="/nix/store/zpzn7c5g58srji21flwqmxzbnaa8w29j-systemd-246.6/lib/systemd/systemd" > hostname=? addr=? terminal=? res=success' > Apr 24 12:44:32 localhost systemd[1]: [email protected]: > Control group is empty. > Apr 24 12:44:32 localhost kernel: kauditd_printk_skb: 1 callbacks > suppressed > Apr 24 12:44:32 localhost kernel: audit: type=1130 > audit(1619268272.815:12): pid=1 uid=0 auid=4294967295 ses=4294967295 > subj=kernel msg='unit=systemd-cryptsetup@root comm="systemd" > exe="/nix/store/zpzn7c5g58srji21flwqmxzbnaa8w29j-systemd-246.6/lib/systemd/systemd" > hostname=? addr=? terminal=? res=success' > Apr 24 12:44:32 localhost systemd[1]: systemd-journald.service: Received > EPOLLHUP on stored fd 43 (stored), closing. > Apr 24 12:44:32 localhost systemd[1]: [email protected] > changed dead -> active > Apr 24 12:44:32 localhost systemd[1]: [email protected]: > Job 69 [email protected]/start finished, result=done > Apr 24 12:44:32 localhost systemd[1]: Reached target Block Device > Preparation for /dev/mapper/root. > Apr 24 12:44:32 localhost systemd[1]: initrd-root-device.target: > ConditionPathExists=/etc/initrd-release succeeded. > Apr 24 12:44:32 localhost systemd[1]: initrd-root-device.target changed > dead -> active > Apr 24 12:44:32 localhost systemd[1]: initrd-root-device.target: Job 55 > initrd-root-device.target/start finished, result=done > Apr 24 12:44:32 localhost systemd[1]: Reached target Initrd Root Device. > Apr 24 12:44:32 localhost systemd[1]: initrd.target: starting held back, > waiting for: initrd-root-fs.target > Apr 24 12:44:32 localhost systemd[1]: Failed to read pids.max attribute of > cgroup root, ignoring: No data available > Apr 24 12:44:32 localhost systemd[1]: sysroot.mount: About to execute: > /nix/store/wcbrp1x2xfmqdpg4vs759irmm1k74c0s-util-linux-2.36-bin/bin/mount > /dev/gpt-auto-root /sysroot -o ro > Apr 24 12:44:32 localhost systemd[1]: sysroot.mount: Forked > /nix/store/wcbrp1x2xfmqdpg4vs759irmm1k74c0s-util-linux-2.36-bin/bin/mount > as 202 > Apr 24 12:44:32 localhost systemd[1]: sysroot.mount: Changed dead -> > mounting > Apr 24 12:44:32 localhost systemd[1]: Mounting Root Partition... > Apr 24 12:44:32 localhost systemd[202]: sysroot.mount: Executing: > /nix/store/wcbrp1x2xfmqdpg4vs759irmm1k74c0s-util-linux-2.36-bin/bin/mount > /dev/gpt-auto-root /sysroot -o ro > > > I have attached the full boot log of the initrd as an attachment. > initrd-246.log succeeds; whilst initrd-247.log fails > > Would love to get some pointers on how to further debug this. I can't tell > from the logs what exactly is going wrong. > >
_______________________________________________ systemd-devel mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/systemd-devel
