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.

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

🐛 Extremely slow boot with "Build Kairos from scratch" on bare metal #1529

Closed
GrabbenD opened this issue Jun 19, 2023 · 18 comments
Closed
Assignees
Labels
bug Something isn't working

Comments

@GrabbenD
Copy link

GrabbenD commented Jun 19, 2023

Issue

Following the instructions from https://kairos.io/docs/reference/build-from-scratch/ + https://kairos.io/docs/getting-started/#booting on bare metal leads to a successful installation which shows a BIOS boot entry for the specified USB device.

However, after booting into KairOS and selecting Kairos (interactive install) in GRUB2, it takes a extremely long time to load before it freezes.

This message is shown for about 1 minute 20 seconds:

Loading kernel...
Loading initrd...

Then after another minute the boot process freezes at:

[drm] amdgpu kernel modesetting enabled.
input: HDA ATI HDMI HDMI/DP,pcm=3 as /device/pci0000:00/0000:00:03.1/000:09:00.0/0000:0a:00.0/0000:0b:00.1/sound/card0/input16
amdgpu: Ignoring ACPI CRAFT on non-APU system

Reproduce

These are copy and pasted instructions from the documentation:

Dockerfile

FROM fedora:36

# Install any package wanted here
# Note we need to install _at least_ the minimum required packages for Kairos to work:
# - An init system (systemd)
# - Grub
# - kernel/initramfs 
RUN echo "install_weak_deps=False" >> /etc/dnf/dnf.conf

RUN dnf install -y \
    audit \
    coreutils \
    curl \
    device-mapper \
    dosfstools \
    dracut \
    dracut-live \
    dracut-network \
    dracut-squash \
    e2fsprogs \
    efibootmgr \
    gawk \
    gdisk \
    grub2 \
    grub2-efi-x64 \
    grub2-efi-x64-modules \
    grub2-pc \
    haveged \
    kernel \
    kernel-modules \
    kernel-modules-extra \
    livecd-tools \
    lvm2 \
    nano \
    NetworkManager \
    openssh-server \
    parted \
    polkit \
    rsync \
    shim-x64 \
    squashfs-tools \ 
    sudo \
    systemd \
    systemd-networkd \
    systemd-resolved \
    tar \
    which \
    && dnf clean all

RUN mkdir -p /run/lock
RUN touch /usr/libexec/.keep

# Copy the Kairos framework files. We use master builds here for fedora. See https://quay.io/repository/kairos/framework?tab=tags for a list
COPY --from=quay.io/kairos/framework:master_fedora / /

# Activate Kairos services
RUN systemctl enable cos-setup-reconcile.timer && \
          systemctl enable cos-setup-fs.service && \
          systemctl enable cos-setup-boot.service && \
          systemctl enable cos-setup-network.service

## Generate initrd
RUN kernel=$(ls /boot/vmlinuz-* | head -n1) && \
            ln -sf "${kernel#/boot/}" /boot/vmlinuz
RUN kernel=$(ls /lib/modules | head -n1) && \
            dracut -v -N -f "/boot/initrd-${kernel}" "${kernel}" && \
            ln -sf "initrd-${kernel}" /boot/initrd && depmod -a "${kernel}"
RUN rm -rf /boot/initramfs-*

Commands:

$ docker build -t test-byoi .

$ docker run -v "$PWD"/build:/tmp/auroraboot \
    -v /var/run/docker.sock:/var/run/docker.sock \
    --rm -ti quay.io/kairos/auroraboot:v0.2.4 \
    --set container_image=docker://test-byoi \
    --set "disable_http_server=true" \
    --set "disable_netboot=true" \
    --set "state_dir=/tmp/auroraboot"

# Flash ISO to USB
$ fdisk /dev/sdc
g
w

$ sudo dd if=build/iso/kairos.iso of=/dev/sdc bs=4MB

More info

Kairos version:

  • quay.io/kairos/framework:master_fedora
  • quay.io/kairos/auroraboot:v0.2.4

CPU architecture, OS, and Version:
x86_64, Fedora 36

Expected behavior
Booting Fedora Workstation & Server from the official ISO takes merely seconds and doesn't freeze

Additional context
CPU: AMD Ryzen 9 5950X
GPU: AMD Radeon RX 6800 XT

@GrabbenD GrabbenD added the bug Something isn't working label Jun 19, 2023
@GrabbenD GrabbenD changed the title [Docs] Extremely slow installation with "Build KairOS from scratch" on bare metal [Docs] Extremely slow installation before freezing with "Build KairOS from scratch" on bare metal Jun 19, 2023
@GrabbenD
Copy link
Author

GrabbenD commented Jun 19, 2023

Update

I tried a different approach (from https://kairos.io/docs/installation/automated/#iso-remastering):

# Prepare KairOS ISO
$ cat <<'EOF' > cloud_init.yaml
#cloud-config
users:
- name: "kairos"
  passwd: "kairos"
EOF
$ export IMAGE=quay.io/kairos/core-opensuse-tumbleweed:latest
$ docker pull $IMAGE
$ docker run -v $PWD/cloud_init.yaml:/cloud_init.yaml \
    -v $PWD/build:/tmp/auroraboot \
    -v /var/run/docker.sock:/var/run/docker.sock \
    --rm -ti quay.io/kairos/auroraboot \
    --set container_image=docker://$IMAGE \
    --set "disable_http_server=true" \
    --set "disable_netboot=true" \
    --cloud-config /cloud_init.yaml \
    --set "state_dir=/tmp/auroraboot"
# Flash to USB
$ fdisk /dev/sdc
g
w
$ sudo dd if=build/iso/kairos.iso of=/dev/sdc bs=4MB

It's equally as slow but it doesn't freeze (perhaps because it has a newer kernel?).
Although it fails at:

squashfs: version 4.0 (2009/01/31) Philip Lougher
loop0: detected capacity change from 0 to 1714560
memfd_create() without MFD_EXEC nor MFD_NOEXEC_SEAL, pid=1 'systemd'
overlayfs: failed to resolve '/run/overlayfs': -2

@GrabbenD
Copy link
Author

GrabbenD commented Jun 19, 2023

Update 2

If I instead use IMAGE=quay.io/kairos/core-fedora (which has the same boot time as Tumbleweed and Fedora 36 images from above), it shows exactly the same error as OpenSuSE Tumbleweed but it ignores it and continues into the interactive installer.

After completing the installation, rebooting into the disk and selecting KairOS from Grub2, it just shows a black screen for 1m10s before proceeding with the boot process which takes another 1 minute on a 7gb/s SN850 2TB Gen4 NVME SSD 🙁

What is causing KairOS boot to be this slow even after initial installation?

@GrabbenD GrabbenD changed the title [Docs] Extremely slow installation before freezing with "Build KairOS from scratch" on bare metal [Docs] Extremely slow installation with "Build KairOS from scratch" on bare metal Jun 19, 2023
@GrabbenD GrabbenD changed the title [Docs] Extremely slow installation with "Build KairOS from scratch" on bare metal [Docs] Extremely slow boot with "Build KairOS from scratch" on bare metal Jun 19, 2023
@Itxaka
Copy link
Member

Itxaka commented Jun 19, 2023

Hi @GrabbenD !

Are you able to get serial logs of the machine?

@mudler
Copy link
Member

mudler commented Jun 20, 2023

I'd check if it's due to compression of the initramfs. Try disabling it creating a file in /etc/dracut.conf.d/disable_compression.conf before the dracut calls containing:

compress="cat"

@Itxaka
Copy link
Member

Itxaka commented Jun 20, 2023

just tested this on my baremetal and can reproduce it (with the first comment image)

You should edit the grub cmdline and remove the console=ttyS0 , that fixed it for me. Seems like as normal PCs dont have serial ports (usually) initrd gets kind of stuck there, maybe trying to connect or something?

Removing that part from the cmdline causes the initrd to load in a couple of seconds and then it fails to load something nvidia related :D

Testing with the update 1 way.

@GrabbenD
Copy link
Author

GrabbenD commented Jun 20, 2023

Thanks for the replies guys!

Are you able to get serial logs of the machine?

Yes, @Itxaka
Here's a recap:

Hope this helps!

@Itxaka
Copy link
Member

Itxaka commented Jun 20, 2023

umm yeah, kind of slow userspace:

Jun 20 11:15:15 fedora systemd[1]: Startup finished in 19.245s (firmware) + 8.432s (loader) + 55.466s (kernel) + 27.342s (initrd) + 1min 31.544s (userspace) = 3min 22.031s.

initrd is expected to be that kind of "slow" as immucore runs 2 stages(rootfs and initramfs) that need to be run in serial before we switch root in order to have everything settled up for the real root, and they expect the environment to be static at that point in order to apply certain configurations, so it can easily eat between 10 to 20 seconds just by the stages.

And indeed that its the case, 10 seconds expend on immucore which doesnt run anything else on parallel (sysroot.service is waiting for immucore):

Jun 20 11:13:26 fedora systemd[1]: Starting immucore.service - immucore...
Jun 20 11:13:33 fedora systemd[1]: Finished immucore.service - immucore.

There is also a big gap when switching root which I dont understand:

Jun 20 11:13:43 fedora systemd[1]: Switching root.
Jun 20 11:13:43 fedora systemd-journald[690]: Received SIGTERM from PID 1 (n/a).
Jun 20 11:13:43 fedora systemd-journald[690]: Journal stopped
Jun 20 11:13:58 fedora systemd[1]: systemd 253.5-1.fc38 running in system mode (+PAM +AUDIT +SELINUX -APPARMOR +IMA +SMACK +SECCOMP -GCRYPT +GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN -IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK +XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)

Thats 15 seconds for doing the switch_root which makes no sense 🤔 everything should be stopped at that point and systemd should have started earlier. Maybe there is some dangling service not killed?

Then we got the cos-setup-boot service which unfortunately is reloaded in the middle of its run, so that may also affect it:

Jun 20 11:15:15 fedora systemd[1]: Reloading requested from client PID 1798 (unit cos-setup-boot.service)...
Jun 20 11:15:15 fedora systemd[1]: Reloading...

And of course, that service prevents getty.target from starting until is finished, which in turn blocks the multi-user.target which is the "end" of booting.

We should check first, why is it being restarted, then if we can run it earlier on the process or not make it block getty.target and let it run on the background while we "finish" the boot process.

@Itxaka
Copy link
Member

Itxaka commented Jun 20, 2023

yeah cos-setup-boot is taking way too long:

image

@Itxaka
Copy link
Member

Itxaka commented Jun 20, 2023

In my case it looks like its the metadata probing the one failing?? but in the cos-setup-network stage.

So there is clearly some kind of mix in there between services because the boot stage was froze until the network stage finished.

And the network stage was frozen due to the metadata adquisition, which would make sense, but it should not block others.

@GrabbenD can you post your systemd-analyze critical-chain?

@GrabbenD
Copy link
Author

GrabbenD commented Jun 20, 2023

I'd check if it's due to compression of the initramfs

Thanks @mudler
I believe this is already the default option for quay.io/kairos/core-fedora:latest as that file already exists under /etc/dracut.conf.d/disable_compression.conf. There's also /etc/dracut.conf.d/10-immucore.conf which uses compress="xz". Just to be on the safe side I went with the Byoi image and added sed -i 's/compress=.*/compress="cat"/' /etc/dracut.conf.d/10-immucore.conf

Dockerfile spoiler
# https://github.com/kairos-io/kairos/blob/master/images/Dockerfile.fedora
ARG BASE_IMAGE=fedora:latest

FROM $BASE_IMAGE

RUN echo "install_weak_deps=False" >> /etc/dnf/dnf.conf
RUN dnf install -y "https://zfsonlinux.org/fedora/zfs-release-2-3$(rpm --eval "%{dist}").noarch.rpm" && dnf clean all
RUN dnf install -y \
    NetworkManager \
    squashfs-tools \
    dracut-live \
    livecd-tools \
    dracut-squash \
    dracut-network \
    efibootmgr \
    audit \
    coreutils \
    curl \
    device-mapper \
    dosfstools \
    dracut \
    dracut-live \
    dracut-network \
    dracut-squash \
    e2fsprogs \
    efibootmgr \
    gawk \
    gdisk \
    grub2 \
    grub2-efi-x64 \
    grub2-efi-x64-modules \
    grub2-pc \
    haveged \
    kernel \
    kernel-modules \
    kernel-modules-extra \
    livecd-tools \
    lvm2 \
    nano \
    NetworkManager \
    openssh-server \
    parted \
    polkit \
    rsync \
    shim-x64 \
    squashfs-tools \
    sudo \
    systemd \
    systemd-networkd \
    systemd-resolved \
    tar \
    which \
    kernel kernel-modules kernel-modules-extra \
    zfs \
    rsync && dnf clean all

RUN mkdir -p /run/lock && \
  touch /usr/libexec/.keep && \
  systemctl enable getty@tty1.service && \
  systemctl enable getty@tty2.service && \
  systemctl enable getty@tty3.service && \
  systemctl enable systemd-networkd && \
  systemctl enable systemd-resolved && \
  systemctl enable sshd

# https://github.com/kairos-io/kairos/blob/master/examples/byoi/fedora/Dockerfile
COPY --from=quay.io/kairos/framework:master_fedora / /

# Activate Kairos services
RUN systemctl enable cos-setup-reconcile.timer && \
          systemctl enable cos-setup-fs.service && \
          systemctl enable cos-setup-boot.service && \
          systemctl enable cos-setup-network.service

# https://github.com/kairos-io/kairos/issues/1529#issuecomment-1598520387
RUN sed -i 's/compress=.*/compress="cat"/' /etc/dracut.conf.d/10-immucore.conf

## Generate initrd
SHELL ["/bin/bash", "-o", "pipefail", "-c"]
RUN kernel=$(ls /boot/vmlinuz-* | head -n1) && \
            ln -sf "${kernel#/boot/}" /boot/vmlinuz
RUN kernel=$(ls /lib/modules | head -n1) && \
            dracut -v -N -f "/boot/initrd-${kernel}" "${kernel}" && \
            ln -sf "initrd-${kernel}" /boot/initrd && depmod -a "${kernel}"
RUN rm -rf /boot/initramfs-*

With this configuration the difference in boot time was unfortunately less than 1 second. I've also verified that the change is actually present in 10-immucore.conf after reinstalling

can you post your systemd-analyze critical-chain?

Of course @Itxaka
Seems like you're onto something 🙂

Text spoiler
$ sudo systemd-analyze critical-chain
multi-user.target @1min 33.136s
└─getty.target @1min 33.136s
  └─cos-setup-boot.service @35.490s +57.645s
    └─basic.target @35.394s
      └─dbus-broker.service @37.096s +186ms
        └─dbus.socket @35.207s
          └─sysinit.target @34.445s
            └─systemd-update-utmp.service @33.641s +704ms
              └─auditd.service @32.718s +731ms
                └─systemd-tmpfiles-setup.service @31.311s +1.072s
                  └─local-fs.target @30.905s
                    └─run-user-0.mount @1min 28.561s
                      └─local-fs-pre.target @20.276s
                        └─systemd-tmpfiles-setup-dev.service @20.078s +97ms
                          └─systemd-sysusers.service @15.510s +4.464s
                            └─systemd-remount-fs.service @9.927s +3.837s
                              └─systemd-fsck-root.service @584542y 2w 2d 20h 1min 36.072s +2.476s
                                └─dracut-pre-mount.service @584542y 2w 2d 20h 1min 35.203s +397ms
                                  └─cryptsetup.target @2.620s
                                    └─systemd-ask-password-wall.path @2.144s

boot

You should edit the grub cmdline and remove the console=ttyS0

I can't seem to find how to actually change boot parameters in the documentation @Itxaka
There's instructions on how to append more options to Grub though?
https://kairos.io/docs/reference/configuration/

@Itxaka
Copy link
Member

Itxaka commented Jun 20, 2023


![boot](https://user-images.githubusercontent.com/45666572/247134539-94607f7f-a91d-4418-a36c-2d4af805b05d.png)

> You should edit the grub cmdline and remove the console=ttyS0

I can't seem to find how to actually change boot parameters in the documentation @Itxaka There's instructions on how to append more options to Grub though? [kairos.io/docs/reference/configuration](https://kairos.io/docs/reference/configuration/) ?

Unfortunately that is a manual step, when presented with the grub menu selection to boot from USB you can press e and it will drop you into the entry config. There you can remove the console=ttyS0 and press ctrl+x to boot from the edited entry:

image

Pretty sure the delay is due to the metadata providers, specifically the Packet provider which doesnt have a default timeout of 2 seconds like the rest, and its NOT an internal address! So its always resolved but never answers...I guess it gets resolved internally if you run teh query inside an equinix machine 👍

https://deploy.equinix.com/developers/docs/metal/server-metadata/metadata/

$ time curl https://metadata.platformequinix.com  -v
*   Trying 192.80.8.124:443...
* connect to 192.80.8.124 port 443 failed: Connection timed out
* Failed to connect to metadata.platformequinix.com port 443 after 130692 ms: Couldn't connect to server
* Closing connection 0
curl: (28) Failed to connect to metadata.platformequinix.com port 443 after 130692 ms: Couldn't connect to server
curl https://metadata.platformequinix.com -v  
0,00s user 0,00s system 0% cpu 2:10,69 total

The rest of the providers have a 2 second timeout which should be more than enough. I already solved this issue in the upstream library but it never trickled down to kairos 🤦

So fix to upstream is: rancher-sandbox/linuxkit@432a87b
Fix to yip: mudler/yip@dcdc988
Fix to kairos-agent: kairos-io/kairos-agent#65

There is also a workaround for now in which you just need to remove the "packer" provider from the 00_datasource.yaml file which comes from the framework and should be under /system/oem/ by running in your dockerfile after copying the framework files:

sed -e 's/"packet", //g' overlay/files/system/oem/00_datasource.yaml

@Itxaka
Copy link
Member

Itxaka commented Jun 20, 2023

With the patch it looks much better:

image

Still 20 seconds to run, which makes sense as there are 10 providers with a max 2 seconfs timeout, so they are maxing out the timeout (we can ignore the cdrom provider as that one doesn't have a timeout)

I think we could still improve this by shipping only the cdrom provider out of the box and letting users set the datasources themselves in they cloud-config @mudler @mauromorales @jimmykarily thoughts? Any reason we need to ship all 10 providers?

@Itxaka
Copy link
Member

Itxaka commented Jun 20, 2023

This is boot with only the cdrom datasource enabled:

image

And you can override the providers in your cloud-config, so no idea why we want to have that massive list without faster checks for validation.

@Itxaka
Copy link
Member

Itxaka commented Jun 20, 2023

umm I guess if booting from cd and providing those datasources via metadata it makes it impossible to override them for the install properly.

Then we need to look into making the datasources faster, maybe via parallel processing or having a faster pre-check?

@GrabbenD
Copy link
Author

GrabbenD commented Jun 20, 2023

This is boot with only the cdrom datasource enabled:

Thanks for taking the rime to debug this @Itxaka

I'm using KairOS to create my own minimal immutable desktop distro and I'm confused about the cos* services. Do I really need them at boot? What purpose do they have outside of k3s/cloud?

@Itxaka
Copy link
Member

Itxaka commented Jun 20, 2023

This is boot with only the cdrom datasource enabled:

Thanks for taking the rime to debug this @Itxaka

I'm using KairOS to create my own minimal immutable desktop distro and I'm confused about the cos* services. Do I really need them at boot? What purpose do they have outside of k3s/cloud?

They are facilities to fully configure the system and modify it via config files, cloud-config style. See the base system has several of those to enable services based on the system boot selection, store things to make immutability work and even generates the bind/ephemeral mounts during boot.

They are run at different times during boot and they differ, for example there is the initramfs stage in which the configs are run in the initrafms with the system already mounted and chrooted into it, so you can modify things before moving into userspace like if you were on the system.
Another stage is network which is triggered once there is network availabel, another one is rootfs which is the first one run, during initramfs when the sysroot is mounted but we dont run it inside the system, so you can modify things in the initramfs.

For example, when you use the interactive installer, a config file is generated that on each boot creates your user during the initramfs stage (you can check your own file in any installed system under /oem/90_custom.yaml):

#cloud-config
install:
    device: /dev/vda
name: Config generated by the installer
stages:
    initramfs:
        - users:
            kairos:
                groups:
                    - admin
                name: kairos
                passwd: kairos

You can see all of the base system confis under: https://github.com/kairos-io/kairos/tree/master/overlay/files/system/oem
And read more about it and the stages on: https://kairos.io/docs/architecture/cloud-init/

@GrabbenD GrabbenD changed the title [Docs] Extremely slow boot with "Build KairOS from scratch" on bare metal Extremely slow boot with "Build KairOS from scratch" on bare metal Jun 21, 2023
@Itxaka
Copy link
Member

Itxaka commented Jun 21, 2023

Patch has landed on yip to run the datasources in parallel mudler/yip#99
This will be in the v2.3.0 kairos release and should reduce the time it takes the cos-setup-boot to about 2/3 seconds max.

@mudler mudler removed their assignment Jul 4, 2023
@mudler mudler changed the title Extremely slow boot with "Build KairOS from scratch" on bare metal 🐛 Extremely slow boot with "Build KairOS from scratch" on bare metal Jul 4, 2023
@mudler mudler changed the title 🐛 Extremely slow boot with "Build KairOS from scratch" on bare metal 🐛 Extremely slow boot with "Build Kairos from scratch" on bare metal Jul 4, 2023
@mudler
Copy link
Member

mudler commented Jul 4, 2023

We have merged all the fixes, and 2.3.0 is about to be released soon (#1066 ) , closing this issue for now. Please re-open if it's still present in 2.3.0

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
Archived in project
Development

No branches or pull requests

3 participants