Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

rawhide: systemd-254 drops ostree-prepare-root from transaction #1527

Closed
aaradhak opened this issue Jul 17, 2023 · 25 comments
Closed

rawhide: systemd-254 drops ostree-prepare-root from transaction #1527

aaradhak opened this issue Jul 17, 2023 · 25 comments
Labels
jira for syncing to jira kind/bug

Comments

@aaradhak
Copy link
Member

aaradhak commented Jul 17, 2023 •
edited

Describe the bug

The kola basic tests are failing on the latest rawhide x86_64 builds since build 39.20230716.91.0

  • basic
[2023-07-17T12:49:24.039Z] --- FAIL: basic (8.35s)
[2023-07-17T12:49:24.040Z]         harness.go:1741: mach.Start() failed: machine c78e2b87-ddfa-4237-b769-7d16ddf5fc56 entered emergency.target in initramfs
  • fcos.upgrade.basic
[2023-07-17T12:57:57.919Z]     --- FAIL: fcos.upgrade.basic/upgrade-from-current (120.97s)
[2023-07-17T12:57:57.919Z]             basic.go:318: failed waiting for machine reboot: timed out after 2m0s waiting for machine to reboot

Observed on checking the console logs that these tests began failing after the systemd version upgrade from systemd 253.5-6.fc39 -> systemd 254~rc2-1.fc39

console.log output related to systemd:

[    5.165851] systemd[1]: Failed to start ignition-ostree-check-rootfs-size.service - Ignition OSTree: Check Root Filesystem Size.
[[0;32m  OK  [0m] Stopped [0;1;39mdracut-cmdline.service[0m - dracut cmdline hook.
[    5.167786] systemd[1]: Dependency failed for ignition-complete.target - Ignition Complete.
[[0;32m  OK  [0m] Stopped [0;1;39mdracut-cmdline-ask.service[0m… for additional cmdline parameters.
[    5.170887] systemd[1]: Dependency failed for initrd.target - Initrd Default Target.
[    5.171559] systemd[1]: initrd.target: Job initrd.target/start failed with result 'dependency'.
[[0;32m  OK  [0m] Started [0;1;39memergency.service[0m - Emergency Shell.
[[0;32m  OK  [0m] Reached target [0;1;39memergency.target[0m - Emergency Mode.
         Starting [0;1;39mignition-virtio-dump-jour…ce[0m - Dump Journal to Virtio Port...
[    5.179091] systemd[1]: initrd.target: Triggering OnFailure= dependencies.
[    5.180358] systemd-journald[259]: Received client request to sync journal.
[    5.180937] systemd[1]: ignition-complete.target: Job ignition-complete.target/start failed with result 'dependency'.
[    5.181807] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.

This is the kola basic output from one of the latest rawhide builds:
kola-basic-7146e04d.zip

Reproduction steps

  1. build and run latest FCOS rawhide image
  2. Run kola test - basic
  3. kola basic test fails

Expected behavior

kola basic test to pass with upgraded systemd-254~rc2-1.fc39

Actual behavior

kola basic test fails with systemd-254~rc2-1.fc39

harness.go:1741: mach.Start() failed: machine 7bc8c78e-6a7c-401e-9e30-bbbf318f1706 entered emergency.target in initramfs
 FAIL, output in /home/jenkins/agent/workspace/build/tmp/kola-Off5m/kola-basic/nvme-true

System details

Fedora CoreOS latest x86_64 Rawhide Version - https://builds.coreos.fedoraproject.org/browser?stream=rawhide&arch=x86_64

Butane or Ignition config

No response

Additional information

No response
@aaradhak aaradhak mentioned this issue Jul 17, 2023
Merged
@keszybz
Copy link

keszybz commented Jul 17, 2023 

[  OK  ] Finished ignition-ostree-uuid-root… Regenerate Filesystem UUID (root).
[    4.235734] systemd[1]: Finished ignition-ostree-uuid-root.service - Ignition OSTree: Regenerate Filesystem UUID (root).
         Starting ignition-ostree-growfs.se…ion OSTree: Grow Root Filesystem...
[    4.239818] systemd[1]: Starting ignition-ostree-growfs.service - Ignition OSTree: Grow Root Filesystem...
[    4.642871] SGI XFS with ACLs, security attributes, realtime, scrub, quota, no debug enabled
[    4.646685] XFS (nvme0n1p4): Mounting V5 Filesystem 51455e45-73c0-4d93-803b-ab20c8dee769
[    4.684957] XFS (nvme0n1p4): Ending clean mount
[    4.988317] ignition-ostree-growfs[799]: CHANGED: partition=4 start=1050624 old: size=3856384 end=4907008 new: size=19920863 end=20971487
[    5.122591] ignition-ostree-growfs[837]: meta-data=/dev/nvme0n1p4         isize=512    agcount=4, agsize=120512 blks
[    5.124325] XFS (nvme0n1p4): Unmounting Filesystem 51455e45-73c0-4d93-803b-ab20c8dee769
[    5.125035] ignition-ostree-growfs[837]:          =                       sectsz=512   attr=2, projid32bit=1
[    5.125716] ignition-ostree-growfs[837]:          =                       crc=1        finobt=1, sparse=1, rmapbt=0
[    5.126465] ignition-ostree-growfs[837]:          =                       reflink=1    bigtime=1 inobtcount=1 nrext64=0
[    5.127679] ignition-ostree-growfs[837]: data     =                       bsize=4096   blocks=482048, imaxpct=25
[    5.130755] ignition-ostree-growfs[837]:          =                       sunit=0      swidth=0 blks
[  OK  ] Finished ignition-ostree-growfs.se…ition OSTree: Grow Root Filesystem.
[    5.134839] ignition-ostree-growfs[837]: naming   =version 2              bsize=4096   ascii-ci=0, ftype=1
[    5.135559] ignition-ostree-growfs[837]: log      =internal log           bsize=4096   blocks=16384, version=2
         Starting ignition-ostree-check-roo…Tree: Check Root Filesystem Size...
         Starting ignition-ostree-transpose…e: Autosave XFS Rootfs Partition...
[    5.141921] ignition-ostree-growfs[837]:          =                       sectsz=512   sunit=0 blks, lazy-count=1
[    5.142666] ignition-ostree-growfs[837]: realtime =none                   extsz=4096   blocks=0, rtextents=0
[    5.143354] ignition-ostree-growfs[837]: data blocks changed from 482048 to 2490107
[    5.147811] systemd[1]: Finished ignition-ostree-growfs.service - Ignition OSTree: Grow Root Filesystem.
[FAILED] Failed to start ignition-ostree-ch…OSTree: Check Root Filesystem Size.
See 'systemctl status ignition-ostree-check-rootfs-size.service' for details.

It seems to be something in ignition-ostree-growfs. The output indicates that it executes successfully, but then it exits with a failure…

@dustymabe
Copy link
Member

The source for that is in:

Not really sure what would have changed here. Apparently reverting to the older version of systemd makes tests pass again so something is going on.

@keszybz
Copy link

keszybz commented Jul 18, 2023

Yeah, but I think somebody who groks ignition-ostree-growfs.service needs to look at this. Is the message about "data blocks changed" fatal? Maybe it's racing with some other operation…

@dustymabe
Copy link
Member

actually looking at the log block you copy/pasted it was actually ignition-ostree-check-rootfs-size.service that failed and not ignition-ostree-growfs.service. I'm reproducing this locally and it seems like a lot is stemming from issues with mounts.

On a F38 system I see a bunch of mount units in the initrd:

sh-5.2# systemctl list-units | grep mount | grep sysroot
  sysroot-etc.mount                                                           loaded active     mounted         /sysroot/etc
  sysroot-sysroot-ostree-deploy-fedora\x2dcoreos-var.mount                    loaded active     mounted         /sysroot/sysroot/ostree/deploy/fedora-coreos/var
  sysroot-sysroot.mount                                                       loaded active     mounted         /sysroot/sysroot
  sysroot-usr.mount                                                           loaded active     mounted         /sysroot/usr
  sysroot-var.mount                                                           loaded active     mounted         /sysroot/var
  sysroot.mount                                                               loaded active     mounted         sysroot.mount
  ignition-ostree-mount-firstboot-sysroot.service                             loaded active     exited          Ignition OSTree: Mount /sysroot (First Boot)

but on rawhide with the new systemd I don't:

:/root# systemctl list-units | grep mount 
  -.mount                                                                     loaded active     mounted       Root Mount
  sys-kernel-config.mount                                                     loaded active     mounted       Kernel Configuration File System
  sysroot.mount                                                               loaded active     mounted       sysroot.mount
● ignition-ostree-mount-var.service                                           loaded failed     failed        Mount OSTree /var

@cgwalters
Copy link
Member

That's after ostree-prepare-root.service has run?

If you have a shell in this environment, I'd try just invoking e.g. mount --bind /usr/bin /usr/bin or whatever (any mount) and see whether systemd synthesizes a .mount unit for it or not.

@dustymabe
Copy link
Member

That's after ostree-prepare-root.service has run?

Looks like maybe that is the problem:

:/root# journalctl | grep prepare-root
Jul 18 18:39:46 localhost systemd[1]: ostree-prepare-root-service.service: Failed to load configuration: No such file or directory
Jul 18 18:39:46 localhost systemd[1]: ostree-prepare-root-service.service: Next restart interval calculated as: 100ms
Jul 18 18:39:46 localhost systemd[1]: ostree-prepare-root-service.service: Collecting.

If you have a shell in this environment, I'd try just invoking e.g. mount --bind /usr/bin /usr/bin or whatever (any mount) and see whether systemd synthesizes a .mount unit for it or not.

Yes, this seems to work:

:/root# mount --bind /usr/bin /usr/bin
:/root# systemctl list-units | grep mount
  -.mount                                                                     loaded active     mounted       Root Mount
  sys-kernel-config.mount                                                     loaded active     mounted       Kernel Configuration File System
  sysroot.mount                                                               loaded active     mounted       sysroot.mount
  usr-bin.mount                                                               loaded active     mounted       /usr/bin
● ignition-ostree-mount-var.service                                           loaded failed     failed        Mount OSTree /var

@cgwalters
Copy link
Member

Some notes from realtime debugging

We still believe there's likely some systemd bug here, but we're not sure what it is yet.

@dustymabe
Copy link
Member

With that patch we get:

Welcome to Fedora CoreOS 39.20230718.dev.1 dracut-059-8.fc39 (Initramfs)!

[    1.033588] systemd[1]: No hostname configured, using default hostname.
[    1.034012] systemd[1]: Hostname set to <localhost>.
[    1.034370] systemd[1]: Initializing machine ID from VM UUID.
[    1.082542] systemd[1]: bpf-lsm: LSM BPF program attached
[    1.158115] systemd[1]: Failed to isolate default target: Unit sysroot.mount not found.
[!!!!!!] Failed to isolate default target.
[    1.188971] systemd[1]: Freezing execution.

@dustymabe dustymabe mentioned this issue Jul 18, 2023
Closed
@dustymabe
Copy link
Member

I know from dmesg that early on in boot it does see ostree-prepare-root.service but I can't see any more logging from the transaction because of systemd/systemd#23515

[    1.414475] systemd[1]: unit_file_build_name_map: normal unit file: /usr/lib/systemd/system/ostree-prepare-root.service

@cgwalters
Copy link
Member

Started on some work for this in coreos/fedora-coreos-config#2515

@cgwalters cgwalters mentioned this issue Jul 18, 2023
Closed
@AdamWill
Copy link

@dustymabe points out that the problem I'm seeing in openQA with the DVD package repo not being used on DVD installs may well be related (as they're both about mounts not working) - https://bugzilla.redhat.com/show_bug.cgi?id=2223795 .

@mrc0mmand
Copy link

@dustymabe points out that the problem I'm seeing in openQA with the DVD package repo not being used on DVD installs may well be related (as they're both about mounts not working) - https://bugzilla.redhat.com/show_bug.cgi?id=2223795 .

I played around with the ISO image and the /run/install/* mounts are there in initramfs (when inspecting the state after rd.break) but get lost once the machine transitions to the live system. I'll look into this a bit more.

@mrc0mmand mrc0mmand mentioned this issue Jul 19, 2023
Closed
@dustymabe
Copy link
Member

upstream report: systemd/systemd#28452
in progress fix: systemd/systemd#28454

@dustymabe
Copy link
Member

dustymabe commented Jul 28, 2023 •
edited

Fixed in systemd/systemd@2bfe726 which is in v254 and v254-rc3 so we should be able to unpin this because rawhide is up to systemd-254~rc3-1.fc39

@aaradhak can you take care of that?

@aaradhak
Copy link
Member Author

aaradhak commented Jul 28, 2023 •
edited

sure , will unpin systemd in rawhide

@aaradhak aaradhak mentioned this issue Jul 28, 2023
Closed
aaradhak added a commit to aaradhak/fedora-coreos-config that referenced this issue Jul 28, 2023
@aaradhak
[rawhide] overrides: drop systemd-253.5-6.fc39 pin
1645fad 
The feature that caused us to pin systemd has been fixed and is up to
https://koji.fedoraproject.org/koji/buildinfo?buildID=2259554.
The fix : systemd/systemd@2bfe726
systemd v254: https://github.com/systemd/systemd/releases/tag/v254
systemd v254-rc3: https://github.com/systemd/systemd/releases/tag/v254-rc3
Resolves: coreos/fedora-coreos-tracker#1527
aaradhak added a commit to aaradhak/fedora-coreos-config that referenced this issue Jul 28, 2023
@aaradhak
[rawhide] overrides: drop systemd-253.5-6.fc39 pin
589c1b1 
The feature that caused us to pin systemd has been fixed and is up to
https://koji.fedoraproject.org/koji/buildinfo?buildID=2259554.
The fix : systemd/systemd@2bfe726
systemd v254: https://github.com/systemd/systemd/releases/tag/v254
systemd v254-rc3: https://github.com/systemd/systemd/releases/tag/v254-rc3
Ref: coreos/fedora-coreos-tracker#1527
@dustymabe
Copy link
Member

I'm still seeing the system get dropped into emergency.target so I don't think the "fix" is sufficient for our uses yet.

@AdamWill
Copy link

FWIW, this did fix the "DVD installs do not use repo from DVD" problem in the installer, so it's not like it did nothing.

@mrc0mmand
Copy link

I'm still seeing the system get dropped into emergency.target so I don't think the "fix" is sufficient for our uses yet.

Hmpf, that's strange, I'll try to look into that.

@dustymabe
Copy link
Member

@mrc0mmand - if you'd like to screenshare we can poke around on a running system. Find me in #fedora-coreos in IRC/matrix.

@dustymabe
Copy link
Member

dustymabe commented Jul 28, 2023 •
edited

Some more logging shows a lot of complaining that sysroot.mount doesn't exist:

[    1.104501] systemd[1]: Activating default unit: initrd.target                                                                                                                                           
[    1.104520] systemd[1]: Unit initrd.target has alias default.target.                                                                                                                                     
[    1.107397] systemd[1]: run-systemd-journal-stdout.mount: Failed to load configuration: No such file or directory                                                                                        
[    1.107413] systemd[1]: run.mount: Failed to load configuration: No such file or directory                                                                                                               
[    1.107425] systemd[1]: run-systemd.mount: Failed to load configuration: No such file or directory                                                                                                       
[    1.107437] systemd[1]: run-systemd-journal.mount: Failed to load configuration: No such file or directory                                                                                               
[    1.107450] systemd[1]: run-systemd-journal-socket.mount: Failed to load configuration: No such file or directory                                                                                        
[    1.107739] systemd[1]: systemd-journald.service: Failed to parse system call, ignoring: futex_waitv                                                                                                     
[    1.107787] systemd[1]: systemd-journald.service: Failed to parse system call, ignoring: riscv_hwprobe                                                                                                   
[    1.107821] systemd[1]: /usr/lib/systemd/system/systemd-journald.service:48: Failed to parse system call, ignoring: futex_waitv                                                                          
[    1.107834] systemd[1]: /usr/lib/systemd/system/systemd-journald.service:48: Failed to parse system call, ignoring: riscv_hwprobe                                                                        
[    1.107963] systemd[1]: /usr/lib/systemd/system/systemd-journald.service:48: Failed to parse system call, ignoring: set_mempolicy_home_node                                                              
[    1.109856] systemd[1]: systemd-udevd.service: Failed to parse system call, ignoring: futex_waitv                                                                                                        
[    1.109889] systemd[1]: systemd-udevd.service: Failed to parse system call, ignoring: riscv_hwprobe                                                                                                      
[    1.109917] systemd[1]: /usr/lib/systemd/system/systemd-udevd.service:37: Failed to parse system call, ignoring: futex_waitv                                                                             
[    1.109931] systemd[1]: /usr/lib/systemd/system/systemd-udevd.service:37: Failed to parse system call, ignoring: riscv_hwprobe                                                                           
[    1.110057] systemd[1]: /usr/lib/systemd/system/systemd-udevd.service:37: Failed to parse system call, ignoring: set_mempolicy_home_node                                                                 
[    1.111533] systemd[1]: run-udev.mount: Failed to load configuration: No such file or directory                                                                                                          
[    1.111566] systemd[1]: run-udev-control.mount: Failed to load configuration: No such file or directory                                                                                                  
[    1.111586] systemd[1]: systemd-hwdb-update.service: Failed to load configuration: No such file or directory                                                                                             
[    1.112728] systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dsetup.service.mount: Failed to load configuration: No such file or directory                                                              
[    1.113451] systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dsetup\x2ddev.service.mount: Failed to load configuration: No such file or directory                                                       
[    1.114581] systemd[1]: run-credentials-systemd\x2dsysusers.service.mount: Failed to load configuration: No such file or directory                                                                       
[    1.114602] systemd[1]: systemd-update-done.service: Failed to load configuration: No such file or directory                                                                                             
[    1.114621] systemd[1]: systemd-remount-fs.service: Failed to load configuration: No such file or directory                                                                                              
[    1.115041] systemd[1]: run-credentials-systemd\x2dsysctl.service.mount: Failed to load configuration: No such file or directory                                                                         
[    1.116456] systemd[1]: run-systemd-ask\x2dpassword.mount: Failed to load configuration: No such file or directory                                                                                       
[    1.117891] systemd[1]: run-credentials-systemd\x2dvconsole\x2dsetup.service.mount: Failed to load configuration: No such file or directory                                                              
[    1.118124] systemd[1]: plymouth-start.service: Failed to load configuration: No such file or directory                                                                                                  
[    1.118905] systemd[1]: multipathd.socket: Failed to load configuration: No such file or directory                                                                                                       
[    1.118924] systemd[1]: blk-availability.service: Failed to load configuration: No such file or directory                                                                                                
[    1.118943] systemd[1]: lvm2-activation-early.service: Failed to load configuration: No such file or directory                                                                                           
[    1.119951] systemd[1]: iscsid.service: Failed to load configuration: No such file or directory                                                                                                          
[    1.119971] systemd[1]: iscsi.service: Failed to load configuration: No such file or directory                                                                                                           
[    1.123114] systemd[1]: run-systemd-journal-syslog.mount: Failed to load configuration: No such file or directory                                                                                        
[    1.123134] systemd[1]: syslog.service: Failed to load configuration: No such file or directory                                                                                                          
[    1.124467] systemd[1]: run-systemd-journal-dev\x2dlog.mount: Failed to load configuration: No such file or directory                                                                                    
[    1.127132] systemd[1]: systemd-fsck-root.service: Failed to load configuration: No such file or directory                                                                                               
[    1.129247] systemd[1]: sysroot.mount: Failed to load configuration: No such file or directory                                                                                                           
[    1.131797] systemd[1]: Unit systemd-fsck@dev-disk-by\x2dlabel-dm-mpath-root.service has alias systemd-fsck@.service.                                                                                    
[    1.133039] systemd[1]: systemd-quotacheck.service: Failed to load configuration: No such file or directory                                                                                              
[    1.133957] systemd[1]: Unit systemd-fsck@dev-disk-by\x2dlabel-root.service has alias systemd-fsck@.service.                                                                                             
[    1.142522] systemd[1]: Unit systemd-fsck@dev-disk-by\x2dlabel-boot.service has alias systemd-fsck@.service.                                                                                             
[    1.144424] systemd[1]: Unit dbus-broker.service has alias dbus.service.                                                                                                                                 
[    1.144934] systemd[1]: var.mount: Failed to load configuration: No such file or directory                                                                                                               
[    1.144954] systemd[1]: var-tmp.mount: Failed to load configuration: No such file or directory                                                                                                           
[    1.144968] systemd[1]: tmp.mount: Failed to load configuration: No such file or directory                                                                                                               
[    1.145233] systemd[1]: run-dbus.mount: Failed to load configuration: No such file or directory                                                                                                          
[    1.145249] systemd[1]: run-dbus-system_bus_socket.mount: Failed to load configuration: No such file or directory                                                                                        
[    1.150294] systemd[1]: nm-run.service: Failed to load configuration: No such file or directory                                                                                                          
[    1.150560] systemd[1]: run-media.mount: Failed to load configuration: No such file or directory                                                                                                         
[    1.150568] systemd[1]: run-media-iso.mount: Failed to load configuration: No such file or directory                                                                                                     
[    1.150576] systemd[1]: run-media-iso-mount.service: Failed to load configuration: No such file or directory                                                                                             
[    1.155034] systemd[1]: initrd.target: Trying to enqueue job initrd.target/start/isolate                                                                                                                 
[    1.155089] systemd[1]: tmp.mount: Cannot add dependency job, ignoring: Unit tmp.mount not found.                                                                                                        
[    1.155115] systemd[1]: ostree-prepare-root.service: Cannot add dependency job to transaction, deleting job ostree-prepare-root.service/start again: Unit sysroot.mount not found.                       
[    1.155118] systemd[1]: ostree-prepare-root.service: Cannot add dependency job, ignoring: Unit sysroot.mount not found.                                                                                  
[    1.155192] systemd[1]: initrd-usr-fs.target: Cannot add dependency job to transaction, deleting job initrd-usr-fs.target/start again: Unit sysroot.mount not found.                                     
[    1.155194] systemd[1]: initrd-usr-fs.target: Cannot add dependency job, ignoring: Unit sysroot.mount not found.

This is with systemd 254~rc3-1.fc39

@cgwalters
Copy link
Member

Ultimately for Fedora CoreOS what we're doing in the initramfs is just extremely dynamic...we support reprovisioning the root filesystem from the initramfs, setting up LUKS, doing networking etc.

So for us, sysroot.mount is...well, complicated. It can't really be static because we don't know what we're mounting until we've fetched the Ignition config (possibly from the network). And we can't do that from a generator.

Adding to the complexity is the way the reprovisioning works, we today mount the filesystem, then copy it to RAM, etc. But for that part in theory I think because we're using a mount namespace systemd shouldn't see a sysroot.mount.

I do think coreos/fedora-coreos-config#2515 is probably the right direction - basically, it may make sense to have a sysroot.mount defined statically, and then just overwrite it and systemctl daemon-reload basically. Or possibly we can get away with just drop-ins in some cases.

@mrc0mmand
Copy link

I built an FCOS image with the Rawhide configuration (sans the pinned systemd packages), and it ends up in emergency shell during the first boot. The main difference I see, so far, is that nothing pulls in ostree-prepare-root.service, even though there's a symlink to it under /etc/systemd/system/initrd-root-fs-target.wants/:

Rawhide + systemd-253.5-6.fc39.x86_64:

# journalctl -o short-monotonic -b --grep "(initrd-root-fs.target|ostree-prepare-root.service)"
[    6.426973] localhost systemd[1]: afterburn-hostname.service: starting held back, waiting for: initrd-root-fs.target
[    6.427122] localhost systemd[1]: coreos-propagate-multipath-conf.service: starting held back, waiting for: initrd-root-fs.target
[    9.694337] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ostree-prepare-root.service
[    9.779309] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ostree-prepare-root.service
[   10.156300] localhost systemd[1]: ignition-mount.service: starting held back, waiting for: initrd-root-fs.target
[   13.420804] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ostree-prepare-root.service
[   14.241337] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ostree-prepare-root.service
[   14.241352] localhost systemd[1]: ignition-ostree-check-rootfs-size.service: starting held back, waiting for: ostree-prepare-root.service
[   14.577215] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ostree-prepare-root.service
[   14.579055] localhost systemd[1]: ignition-mount.service: starting held back, waiting for: initrd-root-fs.target
[   14.579071] localhost systemd[1]: ostree-prepare-root.service: ConditionPathExists=/etc/initrd-release succeeded.
[   14.579086] localhost systemd[1]: ostree-prepare-root.service: ConditionKernelCommandLine=ostree succeeded.
[   14.579100] localhost systemd[1]: ostree-prepare-root.service: Will spawn child (service_enter_start): /usr/lib/ostree/ostree-prepare-root
[   14.579134] localhost systemd[1]: ostree-prepare-root.service: Passing 0 fds to service
[   14.579150] localhost systemd[1]: ostree-prepare-root.service: About to execute /usr/lib/ostree/ostree-prepare-root /sysroot
[   14.579179] localhost systemd[1]: ostree-prepare-root.service: Forked /usr/lib/ostree/ostree-prepare-root as 944
[   14.586628] localhost (are-[944]: ostree-prepare-root.service: Executing: /usr/lib/ostree/ostree-prepare-root /sysroot
[   14.589640] localhost systemd[1]: ostree-prepare-root.service: Changed dead -> start
[   14.589674] localhost systemd[1]: Starting ostree-prepare-root.service - OSTree Prepare OS/...
[   14.592553] localhost systemd[1]: ostree-prepare-root.service: Child 944 belongs to ostree-prepare-root.service.
[   14.592569] localhost systemd[1]: ostree-prepare-root.service: Main process exited, code=exited, status=0/SUCCESS (success)
[   14.602078] localhost systemd[1]: ostree-prepare-root.service: bpf-lsm: Failed to delete cgroup entry from LSM BPF map: No such file or directory
[   14.602154] localhost systemd[1]: ostree-prepare-root.service: Changed start -> exited
[   14.602201] localhost systemd[1]: ostree-prepare-root.service: Job 17 ostree-prepare-root.service/start finished, result=done
[   14.602226] localhost systemd[1]: Finished ostree-prepare-root.service - OSTree Prepare OS/.
[   14.606067] localhost systemd[1]: ostree-prepare-root.service: Control group is empty.
[   14.606123] localhost systemd[1]: initrd-root-fs.target: AssertPathExists=/etc/initrd-release succeeded.
[   14.606141] localhost systemd[1]: initrd-root-fs.target changed dead -> active
[   14.606155] localhost systemd[1]: initrd-root-fs.target: Job 15 initrd-root-fs.target/start finished, result=done
[   14.606172] localhost systemd[1]: Reached target initrd-root-fs.target - Initrd Root File System.

Rawhide + systemd-254~rc3-1.fc39.x86_64

# journalctl -o short-monotonic -b --grep "(initrd-root-fs.target|ostree-prepare-root.service)"
[    6.617154] localhost systemd[1]: afterburn-hostname.service: starting held back, waiting for: initrd-root-fs.target
[    9.898471] localhost systemd[1]: dracut-mount.service: starting held back, waiting for: initrd-root-fs.target
[    9.911201] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ignition-ostree-uuid-root.service
[    9.911214] localhost systemd[1]: dracut-mount.service: starting held back, waiting for: initrd-root-fs.target
[   10.036613] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ignition-ostree-uuid-root.service
[   10.405738] localhost systemd[1]: ignition-mount.service: starting held back, waiting for: initrd-root-fs.target
[   13.617243] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ignition-ostree-mount-firstboot-sysroot.service
[   14.429072] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ignition-ostree-mount-firstboot-sysroot.service
[   14.475188] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ignition-ostree-mount-firstboot-sysroot.service
[   14.475232] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ignition-ostree-mount-firstboot-sysroot.service
[   14.480977] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ignition-ostree-mount-firstboot-sysroot.service
[   14.481882] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ignition-ostree-mount-firstboot-sysroot.service
[   14.487171] localhost systemd[1]: initrd-root-fs.target: starting held back, waiting for: ignition-ostree-mount-firstboot-sysroot.service
[   14.530562] localhost systemd[1]: ignition-mount.service: starting held back, waiting for: initrd-root-fs.target
[   14.825550] localhost systemd[1]: initrd-root-fs.target: AssertPathExists=/etc/initrd-release succeeded.
[   14.825575] localhost systemd[1]: initrd-root-fs.target changed dead -> active
[   14.825591] localhost systemd[1]: initrd-root-fs.target: Job 47 initrd-root-fs.target/start finished, result=done
[   14.825606] localhost systemd[1]: Reached target initrd-root-fs.target - Initrd Root File System.
[   14.864680] localhost systemd[1]: initrd-root-fs.target: Installed new job initrd-root-fs.target/stop as 341
[   14.867910] localhost systemd[1]: initrd-root-fs.target: stopping held back, waiting for: initrd-parse-etc.service
[   14.916135] localhost systemd[1]: ignition-ostree-mount-firstboot-sysroot.service: stopping held back, waiting for: initrd-root-fs.target
[   14.927337] localhost systemd[1]: ignition-ostree-uuid-root.service: stopping held back, waiting for: initrd-root-fs.target
[   14.928134] localhost systemd[1]: initrd-root-fs.target: stopping held back, waiting for: ignition-mount.service
[   14.928232] localhost systemd[1]: initrd-root-fs.target changed active -> dead
[   14.928248] localhost systemd[1]: initrd-root-fs.target: Job 341 initrd-root-fs.target/stop finished, result=done
[   14.928264] localhost systemd[1]: Stopped target initrd-root-fs.target - Initrd Root File System.
[   55.505445] localhost systemd[1]: ostree-prepare-root.service: Next restart interval calculated as: 100ms
[   55.505619] localhost systemd[1]: Found unit ostree-prepare-root.service at /usr/lib/systemd/system/ostree-prepare-root.service (regular file)
[   55.505771] localhost systemd[1]: Preset files don't specify rule for ostree-prepare-root.service. Enabling.
[  108.687794] localhost systemd[1]: initrd-root-fs-target.service: Failed to load configuration: No such file or directory
[  108.687952] localhost systemd[1]: initrd-root-fs-target.service: Next restart interval calculated as: 100ms
[  108.688622] localhost systemd[1]: initrd-root-fs-target.service: Collecting.
[  111.364458] localhost systemd[1]: Found unit initrd-root-fs.target at /usr/lib/systemd/system/initrd-root-fs.target (regular file)
[  111.365192] localhost systemd[1]: Preset files don't specify rule for initrd-root-fs.target. Enabling.

Leading to:

Displaying logs from failed units: ignition-ostree-check-rootfs-size.service
ignition-ostree-mount-var.service
Jul 29 11:37:03 systemd[1]: Starting ignition-ostree-check-rootfs-size.service - Ignition OSTree: Check Root Filesystem Size...
Jul 29 11:37:03 systemd[1]: ignition-ostree-check-rootfs-size.service: Main process exited, code=exited, status=1/FAILURE
Jul 29 11:37:03 systemd[1]: ignition-ostree-check-rootfs-size.service: Failed with result 'exit-code'.
Jul 29 11:37:03 systemd[1]: Failed to start ignition-ostree-check-rootfs-size.service - Ignition OSTree: Check Root Filesystem Size.
Jul 29 11:37:04 systemd[1]: Starting ignition-ostree-mount-var.service - Mount OSTree /var...
Jul 29 11:37:04 ignition-ostree-mount-var[1011]: Mounting /sysroot/ostree/deploy/fedora-coreos/var
Jul 29 11:37:04 ignition-ostree-mount-var[1016]: mount: /sysroot/var: mount point does not exist.
Jul 29 11:37:04 ignition-ostree-mount-var[1016]:        dmesg(1) may have more information after failed mount system call.
Jul 29 11:37:04 systemd[1]: ignition-ostree-mount-var.service: Main process exited, code=exited, status=32/n/a
Jul 29 11:37:04 systemd[1]: ignition-ostree-mount-var.service: Failed with result 'exit-code'.
Jul 29 11:37:04 systemd[1]: Failed to start ignition-ostree-mount-var.service - Mount OSTree /var.
Jul 29 11:37:04 systemd[1]: ignition-ostree-mount-var.service: Triggering OnFailure= dependencies.

Hopefully a bisect will pinpoint the culprit.

@mrc0mmand
Copy link

Ah, latest Rawhide:

initrd.target: Trying to enqueue job initrd.target/start/isolate
ostree-prepare-root.service: Cannot add dependency job to transaction, deleting job ostree-prepare-root.service/start again: Unit sysroot.mount not found.
ostree-prepare-root.service: Cannot add dependency job, ignoring: Unit sysroot.mount not found.
initrd-usr-fs.target: Cannot add dependency job to transaction, deleting job initrd-usr-fs.target/start again: Unit sysroot.mount not found.
initrd-usr-fs.target: Cannot add dependency job, ignoring: Unit sysroot.mount not found.

vs the working systemd build:

initrd.target: Trying to enqueue job initrd.target/start/isolate
ostree-prepare-root.service: Cannot add dependency job, ignoring: Unit sysroot.mount not found.
tmp.mount: Cannot add dependency job, ignoring: Unit tmp.mount not found.
initrd-usr-fs.target: Cannot add dependency job, ignoring: Unit sysroot.mount not found.

Which points to systemd/systemd@89e9df1 introduced in systemd/systemd#27852.

aaradhak added a commit to aaradhak/fedora-coreos-config that referenced this issue Jul 31, 2023
@aaradhak
[rawhide] overrides: drop systemd-253.5-6.fc39 pin
5fc9ed4 
The feature that caused us to pin systemd has been fixed and is up to
https://koji.fedoraproject.org/koji/buildinfo?buildID=2259554.
The fix: systemd/systemd@2bfe726
systemdv254: https://github.com/systemd/systemd/releases/tag/v254
systemdv254-rc3: https://github.com/systemd/systemd/releases/tag/v254-rc3
Ref: coreos/fedora-coreos-tracker#1527
aaradhak added a commit to aaradhak/fedora-coreos-config that referenced this issue Jul 31, 2023
@aaradhak
[rawhide] overrides: drop systemd-253.5-6.fc39 pin
338b16a 
The feature that caused us to pin systemd has been fixed and is up to
https://koji.fedoraproject.org/koji/buildinfo?buildID=2259554.
The fix: systemd/systemd@2bfe726
systemdv254: https://github.com/systemd/systemd/releases/tag/v254
systemdv254-rc3: https://github.com/systemd/systemd/releases/tag/v254-rc3
Ref: coreos/fedora-coreos-tracker#1527
dustymabe added a commit to dustymabe/fedora-coreos-config that referenced this issue Aug 9, 2023
@dustymabe
overlay.d/05core: add coreos-rootflags back to diskful sysroot.mount
02dcdd5 
In e8eb4cb we started creating a static sysroot.mount to appease
systemd 254+ (see [1]), but it missed the `coreos-rootflags` handling
that was present in xxx

This PR adds back in the dynamic rootflags by using an EnvironmentFile
generated by a coreos-rootflags.service to get the same behavior.

[1] coreos/fedora-coreos-tracker#1527 (comment)
dustymabe added a commit to dustymabe/fedora-coreos-config that referenced this issue Aug 9, 2023
@dustymabe
overlay.d/05core: add coreos-rootflags back to diskful sysroot.mount
431e6aa 
In 45396d8 we started creating a static sysroot.mount to appease
systemd 254+ (see [1]), but it missed the `coreos-rootflags` handling
that was present in ignition-ostree-mount-sysroot.sh.

This PR adds back in the dynamic rootflags by using an EnvironmentFile
generated by a coreos-rootflags.service to get the same behavior.

[1] coreos/fedora-coreos-tracker#1527 (comment)
@dustymabe
Copy link
Member

Thanks @mrc0mmand that investigation really helped us figure out the change was a desired change and we needed to adjust.

I opened a new PR that builds on top of Colin's PR to address this: coreos/fedora-coreos-config#2543

@dustymabe dustymabe added the jira for syncing to jira label Aug 9, 2023
@dustymabe dustymabe changed the title rawhide: kola basic tests are failing on x86_64 with systemd-254~rc2-1.fc39 update rawhide: systemd-254 drops ostree-prepare-root from transaction Aug 9, 2023
@dustymabe dustymabe mentioned this issue Aug 11, 2023
Closed
dustymabe added a commit to dustymabe/fedora-coreos-config that referenced this issue Aug 11, 2023
@dustymabe
overlay.d/05core: add coreos-rootflags back to diskful sysroot.mount
e495ec6 
In 45396d8 we started creating a static sysroot.mount to appease
systemd 254+ (see [1]), but it missed the `coreos-rootflags` handling
that was present in ignition-ostree-mount-sysroot.sh.

This PR adds back in the dynamic rootflags by using an EnvironmentFile
generated by a coreos-rootflags.service to get the same behavior.

[1] coreos/fedora-coreos-tracker#1527 (comment)
dustymabe added a commit to coreos/fedora-coreos-config that referenced this issue Aug 14, 2023
@dustymabe
overlay.d/05core: add coreos-rootflags back to diskful sysroot.mount
b7f5dab 
In 45396d8 we started creating a static sysroot.mount to appease
systemd 254+ (see [1]), but it missed the `coreos-rootflags` handling
that was present in ignition-ostree-mount-sysroot.sh.

This PR adds back in the dynamic rootflags by using an EnvironmentFile
generated by a coreos-rootflags.service to get the same behavior.

[1] coreos/fedora-coreos-tracker#1527 (comment)
@dustymabe
Copy link
Member

This should be fixed with coreos/fedora-coreos-config#2543

@dustymabe dustymabe mentioned this issue Aug 28, 2023
Merged
HuijingHei pushed a commit to HuijingHei/fedora-coreos-config that referenced this issue Oct 10, 2023
@dustymabe @HuijingHei
overlay.d/05core: add coreos-rootflags back to diskful sysroot.mount
d6c891d 
In 45396d8 we started creating a static sysroot.mount to appease
systemd 254+ (see [1]), but it missed the `coreos-rootflags` handling
that was present in ignition-ostree-mount-sysroot.sh.

This PR adds back in the dynamic rootflags by using an EnvironmentFile
generated by a coreos-rootflags.service to get the same behavior.

[1] coreos/fedora-coreos-tracker#1527 (comment)
HuijingHei pushed a commit to HuijingHei/fedora-coreos-config that referenced this issue Oct 10, 2023
@dustymabe @HuijingHei
overlay.d/05core: add coreos-rootflags back to diskful sysroot.mount
e832f3c 
In 45396d8 we started creating a static sysroot.mount to appease
systemd 254+ (see [1]), but it missed the `coreos-rootflags` handling
that was present in ignition-ostree-mount-sysroot.sh.

This PR adds back in the dynamic rootflags by using an EnvironmentFile
generated by a coreos-rootflags.service to get the same behavior.

[1] coreos/fedora-coreos-tracker#1527 (comment)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
jira for syncing to jira kind/bug
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

initramfs: Remove manual sysroot mounting cgwalters/fedora-coreos-config
6 participants
@cgwalters @keszybz @mrc0mmand @AdamWill @dustymabe @aaradhak