Current ALPHA no boot with PXE Job dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device/start timed out

[micahel71]

Issue Report

Bug

Container Linux Version

Container Linux 1855.1.0

$ cat /etc/os-release
NAME="Container Linux by CoreOS"
...
BUG_REPORT_URL="https://issues.coreos.com"

Environment

Mini PC Intel® NUC Kit NUC6i7KYK
What hardware/cloud provider/hypervisor is being used to run Container Linux?

Expected Behavior

Boot

Actual Behavior

Stops at dracut-pre-mount and starts Setup Virtual Console

Reproduction Steps

1. Download https://alpha.release.core-os.net/amd64-usr/current/coreos_production_pxe.vmlinuz
2. Download https://alpha.release.core-os.net/amd64-usr/current/coreos_production_pxe_image.cpio.gz
3. Have an empty /dev/sda in place
4. Try to mount empty /dev/sda1 as ROOT

Other Information

This bug was not seen with BETA and STABLE channel with the exact same settings on PXE Boot server. All fine there.

[micahel71]

[   61.927229] localhost systemd[1]: Reached target Local File Systems.
[   61.928151] localhost systemd[1]: Reached target System Initialization.
[   61.928890] localhost systemd[1]: Reached target Basic System.
[   61.930299] localhost systemd[1]: Starting File System Check on /dev/disk/by-label/ROOT...
[   61.945572] localhost systemd-fsck[463]: ROOT: clean, 11/29310976 files, 2120701/117212625 blocks
[   61.948158] localhost systemd[1]: Started File System Check on /dev/disk/by-label/ROOT.
[   61.949101] localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-fsck-root comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   61.949671] localhost systemd[1]: Mounting /sysroot...
[   61.949102] localhost kernel: audit: type=1130 audit(1534053657.743:19): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-fsck-root comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   61.984779] localhost systemd[1]: Mounted /sysroot.
[   61.983956] localhost kernel: EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
[   61.986408] localhost systemd[1]: Mounting /sysroot/usr...
[   61.991448] localhost kernel: loop: module loaded
[   62.002677] localhost kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher
[   62.003702] localhost systemd[1]: Mounted /sysroot/usr.
[   62.004519] localhost systemd[1]: Reached target Initrd Root File System.
[   62.005689] localhost systemd[1]: Starting Root filesystem setup...
[   62.027833] localhost systemd[1]: Started Root filesystem setup.
[   62.029593] localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=initrd-setup-root comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   62.029636] localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=initrd-setup-root comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   62.029699] localhost systemd[1]: Starting Ignition (files)...
[   62.028625] localhost kernel: audit: type=1130 audit(1534053657.822:20): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=initrd-setup-root comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   62.028626] localhost kernel: audit: type=1131 audit(1534053657.822:21): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=initrd-setup-root comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   62.032360] localhost ignition[518]: Ignition v0.26.0
[   62.033470] localhost ignition[518]: reading system config file "/usr/lib/ignition/base.ign"
[   62.033964] localhost ignition[518]: no config at "/usr/lib/ignition/base.ign"
[   62.060774] localhost ignition[518]: files: createUsers: op(1): [started]  creating or modifying user "core"
[   62.061392] localhost ignition[518]: files: createUsers: op(1): executing: "/usr/sbin/usermod" "--root" "/sysroot" "core"
[   62.062515] localhost ignition[518]: files: createUsers: op(1): [finished] creating or modifying user "core"
[   62.063082] localhost ignition[518]: files: createUsers: op(2): [started]  adding ssh keys to user "core"
[   62.063710] localhost ignition[518]: files: createUsers: op(2): [finished] adding ssh keys to user "core"
[   62.064331] localhost systemd[1]: Started Ignition (files).
[   62.065222] localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=ignition-files comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   62.067704] localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=ignition-files comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   62.065209] localhost kernel: audit: type=1130 audit(1534053657.859:22): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=ignition-files comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   62.067650] localhost kernel: audit: type=1131 audit(1534053657.859:23): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=ignition-files comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.206628] localhost systemd[1]: dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device: Job dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device/start timed out.
[   92.208553] localhost systemd[1]: Timed out waiting for device dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device.
[   92.209415] localhost systemd[1]: Dependency failed for /sysroot/boot.
[   92.210532] localhost systemd[1]: Dependency failed for Populate torcx store to satisfy profile.
[   92.211582] localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-mount comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.211617] localhost systemd[1]: Dependency failed for Initrd Default Target.
[   92.210921] localhost kernel: audit: type=1131 audit(1534053688.004:24): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-mount comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.212074] localhost kernel: audit: type=1131 audit(1534053688.006:25): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-initqueue comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.212693] localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-initqueue comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.212721] localhost systemd[1]: initrd.target: Job initrd.target/start failed with result 'dependency'.
[   92.213063] localhost kernel: audit: type=1131 audit(1534053688.007:26): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-trigger comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.214064] localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-trigger comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.214091] localhost systemd[1]: initrd.target: Triggering OnFailure= dependencies.
[   92.214269] localhost kernel: audit: type=1131 audit(1534053688.008:27): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-udev comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.215077] localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-udev comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.215104] localhost systemd[1]: torcx-profile-populate.service: Job torcx-profile-populate.service/start failed with result 'dependency'.
[   92.215467] localhost kernel: audit: type=1131 audit(1534053688.009:28): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-cmdline comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.216352] localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-cmdline comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.216416] localhost systemd[1]: sysroot-boot.service: Job sysroot-boot.service/start failed with result 'dependency'.
[   92.217136] localhost systemd[1]: dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device: Job dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device/start failed with result 'timeout'.
[   92.218114] localhost systemd[1]: Stopped dracut pre-mount hook.
[   92.218943] localhost systemd[1]: Stopped dracut initqueue hook.
[   92.219466] localhost systemd[1]: Stopped dracut pre-trigger hook.
[   92.223459] localhost systemd[1]: Stopped dracut pre-udev hook.
[   92.223892] localhost systemd[1]: Stopped dracut cmdline hook.
[   92.224370] localhost systemd[1]: Starting Reload Configuration from the Real Root...
[   92.224772] localhost systemd[1]: Starting Setup Virtual Console...
[   92.225307] localhost systemd[1]: Stopped target Basic System.
[   92.225772] localhost systemd[1]: Stopped target System Initialization.
[   92.226346] localhost systemd[1]: Reloading.
[   92.265833] localhost systemd[1]: Started Setup Virtual Console.
[   92.266304] localhost kernel: audit: type=1130 audit(1534053688.060:29): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.266308] localhost kernel: audit: type=1131 audit(1534053688.060:30): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.267426] localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.267473] localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-vconsole-setup comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.267550] localhost systemd[1]: Starting Emergency Shell...
[   92.275758] localhost systemd[1]: Started Reload Configuration from the Real Root.
[   92.276500] localhost kernel: audit: type=1130 audit(1534053688.070:31): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=initrd-parse-etc comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.276501] localhost kernel: audit: type=1131 audit(1534053688.070:32): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=initrd-parse-etc comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.278417] localhost audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=initrd-parse-etc comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.278500] localhost audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=initrd-parse-etc comm="systemd" exe="/usr/lib64/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   92.278543] localhost systemd[1]: Reached target Initrd File Systems.
[   92.279274] localhost systemd[1]: Starting Cleaning Up and Shutting Down Daemons...

[orbistertius]

This happens from alpha 1849.0.0 when iPXE booting a node with empty disk or diskless, and coreos.first_boot=1 (for ignition). Previous versions alpha 1828.0.0 is OK.

Looking at manifest/release.xml last working bootengine commit is deba073. Next commit 622df8e introduces dracut/35torcx/torcx-profile-populate.service which requires sysroot-boot.service which has BindsTo and After dev-disk-by\x2dlabel-EFI\x2dSYSTEM.device.

[lucab]

@micahel71 @orbistertius thanks for catching this in alpha and reporting it!
coreos/bootengine#147 should be taking care of unbreaking it.