dhcpcd stuck for 5 Minutes (300 Seconds) during Boot Process (LUKS/Clevis Autounlock)

Also adding DMESG Output immediately after Boot Process finishes.

Thank you for taking the time to report this bug and helping to make Ubuntu better. The first question is: Why is the network configured in the initrd in the first place? Your dmesg says that the ZFS is used to boot and no "ip" parameter is specified there.

The second question is: Why did /usr/lib/dhcpcd/dhcpcd-run-hooks fail? Can you modify the shell script /usr/lib/dhcpcd/dhcpcd-run-hooks to run with "set -x" to log the commands?

What scripts do you have on your system?

```
find {/etc/initramfs-tools,/usr/share/initramfs-tools}/scripts ! -type d | sort
```

Thank you for your quick answer.

a1. Why no network configured ? I think that clevis initramfs unlock would just use DHCP and get a lease from the DHCP Server. Is an IP entry really needed ?

https://www.kernel.org/doc/Documentation/frv/booting.txt shows some examples in specifying ip just by configuring Network via DHCP but it doesn't say that an ip=:::::dhcp is mandatory ...

I remember that for some time it just booted normally anyways, so if an IP entry is required, it's something relatively new.

a2. ZFS is my Root Fileystem. However, first LUKS (cryptsetup/dmcrypt) needs to be unlucked. And that can happen either by 1) typing the passphrase in manually or 2) (more desired) having Clevis contacting a Tang Server during boot to unlock its Keyslots (stored in LUKS).

The order therefore, for automated unlock, is:

Network is UP -> Clevis can contact one of the Tang Servers (I believe using `curl`) -> Tang provides a key to Clevis -> Clevis unlocks LUKS DM (Device Mapper) Device -> ZFS imports Pool -> the boot Process continues as normal

(TLDR: ZFS on top of LUKS, automatically decrypted by Clevis+Tang if some Tang Servers are up in my LAN)

b. Modified /usr/lib/dhcpcd/dhcpcd-run-hooks with set -x at the top of the File, just AFTER the shebang.
Rebuilt initr with `update-initramfs -k all -u`, `update-grub`, `update-initramfs -k all -u` and again `update-grub` to make sure no old stuff was hanging around anymore.

Log will be provided shortly ...

c. The scripts were listed in the original post ... including those in /etc (none, hence not listed).
But anyhow here you have it:
```
root@MYHOST:~# find {/etc/initramfs-tools,/usr/share/initramfs-tools}/scripts ! -type d | sort
/usr/share/initramfs-tools/scripts/functions
/usr/share/initramfs-tools/scripts/init-bottom/lvm2
/usr/share/initramfs-tools/scripts/init-bottom/plymouth
/usr/share/initramfs-tools/scripts/init-bottom/udev
/usr/share/initramfs-tools/scripts/init-premount/brltty
/usr/share/initramfs-tools/scripts/init-premount/plymouth
/usr/share/initramfs-tools/scripts/init-top/all_generic_ide
/usr/share/initramfs-tools/scripts/init-top/blacklist
/usr/share/initramfs-tools/scripts/init-top/brltty
/usr/share/initramfs-tools/scripts/init-top/console_setup
/usr/share/initramfs-tools/scripts/init-top/framebuffer
/usr/share/initramfs-tools/scripts/init-top/udev
/usr/share/initramfs-tools/scripts/local
/usr/share/initramfs-tools/scripts/local-block/cryptroot
/usr/share/initramfs-tools/scripts/local-bottom/clevis
/usr/share/initramfs-tools/scripts/local-bottom/cryptgnupg-sc
/usr/share/initramfs-tools/scripts/local-bottom/cryptopensc
/usr/share/initramfs-tools/scripts/local-bottom/cryptroot
/usr/share/initramfs-tools/scripts/local-bottom/ntfs_3g
/usr/share/initramfs-tools/scripts/local-premount/fixrtc
/usr/share/initramfs-tools/scripts/local-premount/ntfs_3g
/usr/share/initramfs-tools/scripts/local-premount/resume
/usr/share/initramfs-tools/scripts/local-top/clevis
/usr/share/initramfs-tools/scripts/local-top/cryptopensc
/usr/share/initramfs-tools/scripts/local-top/cryptroot
/usr/share/initramfs-tools/scripts/local-top/zfs
/usr/share/initramfs-tools/scripts/nfs
/usr/share/initramfs-tools/script...

Updated /run/initramfs/initramfs.debug with set -x in dhcpcd Script

Thanks. So clevis-initramfs (from the clavis source package) ships /usr/share/initramfs-tools/scripts/local-top/clevis which calls configure_networking. As you described configuring the network is desired. So clevis and initramfs-tools behave as expected and the bug is inside dhcpcd. Let's see what debugging /usr/lib/dhcpcd/dhcpcd-run-hooks reveals.

I had uploaded it ... it's approximately 300 more lines than before.

I started writing my comment before you posted your log output. That's why I saw it only afterwards.

I tracked it down to: /usr/lib/dhcpcd/dhcpcd-run-hooks -> /usr/lib/dhcpcd/dhcpcd-hooks/30-hostname -> need_hostname function:

```
 is_default_hostname "$hostname" && return 0
```

/usr/lib/dhcpcd/dhcpcd-hooks/10-mtu calls "set -e" which is still present when sourcing /usr/lib/dhcpcd/dhcpcd-hooks/30-hostname.

Distilled down `test` shell code:

```
#!/bin/sh
set -e

need_hostname()
{
    false && return 0
    echo "remaining"
}

need_hostname
```

busybox behaves differently than dash in that case:

```
$ sh test; echo $?
remaining
0
$ busybox test; echo $?
1
```

No worries, you are super quick to reply, I appreciate that a lot.

But ... What does this mean ? Is it a BUG that lingered around for 1.5 years without anybody else reporting it ?

Or is it a (mis)configuration Issue somewhere on my side ?

Scratch my last comment. My test should have called `busybox sh test` instead of `busybox test`.

The failing code is a bit later. need_hostname hits the last else part and calls false (after the "No old hostname" comment). The caller code in set_hostname:

```
 need_hostname || return
```

Distilled down `test` shell code:

```
#!/bin/sh
set -e

set_hostname()
{
    false || return
    echo "remaining"
}

set_hostname
```

```
$ busybox sh test; echo $?
1
$ sh test; echo $?
1
```

It's a bug in /usr/lib/dhcpcd/dhcpcd-hooks/30-hostname when executed with "set -e" that nobody has noticed/reported in 1.5 years.

If I understand correctly, need_hostname returns 0 in case the hostname is already set to the correct name. It return 1 if the hostname needs to be set. "need_hostname || return" returns set_hostname before setting the hostname in case need_hostname returns 1. I am confused.

Can you add a call to `env | sort` at the beginning of /usr/lib/dhcpcd/dhcpcd-hooks/30-hostname to log what environment variables are set?

Sure. Do I also need to add set -x there as well ?

Could it be related to the fact that I completely uninstalled `netplan` from my Ubuntu Desktop ?

I saw lots of References to Netplan in `/usr/share/initramfs-tools/scripts/functions`.

No additional "set -x" is needed there since that file is sourced and therefore your initial "set -x" is still set.

This bug does not look like being related to netplan at all. initramfs-tools generates configs for netplan, but this is unrelated to the dhcpcd hooks.

Seems like only PATH and PWD are set ...

EDIT: correction, these variables are set (I ignored the lowercase ones because I expected everything in ENV to be uppercase):
```
PATH=/sbin:/usr/sbin:/bin:/usr/bin:/usr/local/bin
PWD=/
hostname_fqdn=no
if_configured=true
if_down=false
if_up=false
ifcarrier=up
ifflags=69699
ifmetric=1002
ifmtu=1500
ifwireless=0
interface=enp0s25
interface_order=enp0s25
pid=517
protocol=link
reason=PREINIT
```

Updated /run/initramfs/initramfs.debug with env | sort (and also set -x immediately afterwards) in dhcpcd Script (v3)

Looking for reason environment variable in initramfs_v3.debug, we have following result: reason=PREINIT, reason=NOCARRIER, and reason=CARRIER have no problems.

reason=BOUND and reason=REBOOT show the failure. environment variables there:

```
hostname_fqdn=no
if_configured=true
if_down=false
if_up=true
ifcarrier=up
ifflags=69699
ifmetric=1002
ifmtu=1500
ifwireless=0
interface=enp0s25
interface_order=enp0s25
new_broadcast_address=192.168.15.255
new_dhcp_lease_time=3600
new_dhcp_message_type=5
new_dhcp_server_identifier=192.168.1.7
new_domain_name=MYDOMAIN.TLD
new_domain_name_servers=192.168.1.3 192.168.1.4
new_filename=pxelinux.0
new_host_name=WORKSTATION01
new_ip_address=192.168.3.61
new_network_number=192.168.0.0
new_routers=192.168.1.1
new_subnet_cidr=20
new_subnet_mask=255.255.240.0
pid=517
protocol=dhcp
reason=BOUND
```

If I understand the code correctly, 30-hostname only changes the hostname if it was the default like `(none)` or if it was set by dhcpcd previously (that's why need_hostname checks for the old hostname).

In case /etc/hostname is included in the initrd (which is probably the case for your initrd), the hostname will not be changed by 30-hostname.

Can you change

```
 need_hostname || return
```

to

```
 need_hostname || return 0
```

This should exit 30-hostname in this case.

Sure, I can change it.

I'll do the change and reboot ... We'll have an answer in about 30 Minutes.

Another thing that I was thinking about is ... The `/etc/hostname` of the System is `ubuntuworkstation01` and the DHCP-assigned (or should I say "registered" ?) hostname is apparently `WORKSTATION01`(probably because for dual-boot machines I want the same DHCP IP Lease assigned, yet want different hostnames set on OS level).

Could this be (one of) the causes of the Issue ?

/etc/hostname seems to be included in the Initramfs:
```
root@ubuntuworkstation01:~# lsinitramfs /boot/initrd.img* | grep -i hostname
etc/hostname
usr/bin/hostname
usr/lib/dhcpcd/dhcpcd-hooks/30-hostname
etc/hostname
usr/bin/hostname
usr/lib/dhcpcd/dhcpcd-hooks/30-hostname
```

And
```
root@ubuntuworkstation01:~# cat /etc/hostname
ubuntuworkstation01
```

It seems, looking at `dmesg` at least, that the "frozen" / "hang" state went from 300 Seconds to 45 Seconds.

PS: is it normal that I cannot attach multiple files at once ?

Yes, I can confirm. Without a precise clock but just counting in my head, it's around 45 seconds. Definitively much less than before.

Maybe I'll try to quickly play with PXE Boot / TFTP Server settings on my OPNSense Router and see if that's responsible for the slowdown (dhcpcd reported those PXELinux settings so maybe that's hindering it).

EDIT 1: Disabling TFTP Server / Network Book / PXE Boot on the DHCP Server didn't make any difference. Still frozen/hanging for 45 Seconds.

Still WAY better than 300 seconds though.

The Launchpad UI only allows to attach one file at once. So that is normal.

I'll prepare the upload containing the fix. That your boot takes around 45 seconds instead of 15 seconds is caused by a separate issue. Please file another bug for that. Here is the relevant log:

```
dhcpcd-10.0.6 starting
[...]
no interfaces have a carrier
exiting due to oneshot
dhcpcd exited
Sleeping 29 seconds before retrying getting a DHCP lease
dhcpcd-10.0.6 starting
```

dhcpcd is called before the interfaces are ready. It should succeed in the first try.

Alright.

Can you please tell me what I should report in the other bug exactly though ?

My original idea in the first post ?

>>A possible workaround would be to manually edit /usr/share/initramfs-tools/scripts/functions
>>Changing this:
>>`for ROUNDTTT in 30 60 90 120; do`

>>To this:
>>`for ROUNDTTT in 15 15 15 15; do`

?

Forwarded fix upstream: https://github.com/NetworkConfiguration/dhcpcd/pull/320
and to Debian: https://salsa.debian.org/debian/dhcpcd/-/merge_requests/6

Suggested title for the second bug: dhcpcd is called before interfaces have carrier causing a 29 seconds boot delay

The bug title and description can be updated afterwards.

Super, many thanks. But I'll basically have to "patch" it locally, because I guess this will not make it to Ubuntu before 24.10 at best, right ?

New BUG Report at (hope I did it correctly): https://bugs.launchpad.net/ubuntu/+source/dhcpcd/+bug/2065037

EDIT 1: I accidentally assigned it to initramfs-tools Package first, but I switched now to dhcpcd Package only. Feel free to correct if needed (I guess this kinda falls in-between the two ... again)

We can include the fix in Ubuntu 24.04 via a stable release update.

Debdiff for noble

Pretty sure the same/similar occurs in Mantic and probably even before (even if I believe dhcpcd version is different).

But maybe it's too much effort for little benefit to fix those (Mantic will be anyways EOL July 2024 so just a few months away). I had upgraded all Systems that I own to Ubuntu 24.04 already.

So how does it work with this patch now ? Will it go eventually in `noble-proposed` then in `noble-updates` repository ?

mantic and before are not worth the backport, but noble is a LTS release.

Once the SRU team accepts the upload, it will land in noble-proposed and you will get asked to test the fix. See https://wiki.ubuntu.com/StableReleaseUpdates

Just for my understanding (I had a look at that Wiki Page but didn't understand very well) ... Did you create a SRU Bug Template ? I only see a Patch here and the Upstream Bug Reports.

Is the SRU Bug Template creation part an automatic Pipeline ran by a Bot ?

Yes, I edited the bug description to add the SRU bug sections. There is no automation for that.

Hello Stefano, or anyone else affected,

Accepted dhcpcd into noble-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/dhcpcd/1:10.0.6-1ubuntu3.1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, what testing has been performed on the package and change the tag from verification-needed-noble to verification-done-noble. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-noble. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

Hello Timo.

Sure, I just tested it and I get to the (same) Result I was getting while performing preliminary Investigations. The boot time is around 22 Seconds (down from the Original 300 Seconds).

So it's Good, from what I can tell :).

# Test Procedure & Log

# Pin noble-proposed Packages with Lower Priority by Default
create /etc/apt/preferences.d/proposed-updates if it doesn't exist yet
###########################################################################
# Configure apt to allow selective installs of packages from proposed
Package: *
Pin: release a=noble-proposed
Pin-Priority: 400
###########################################################################

# Pin DHCPCD Packages with Maximum Priority
create /etc/apt/preferences.d/dhcpcd-proposed

###########################################################################
Package: dhcpcd dhcpcd-base dhcpcd5 dhcpcd-base-dbgsym
Pin: release a=noble-proposed
Pin-Priority: 1000
###########################################################################

# View Pinning Policy
apt policy dhcpcd-base

# Priority is higher on noble-proposed, so that's good
# This means that a Package Upgrade will be performed
```
dhcpcd-base:
  Installed: 1:10.0.6-1ubuntu3
  Candidate: 1:10.0.6-1ubuntu3.1
  Version table:
     1:10.0.6-3 1
          1 http://ftp.dk.debian.org/debian testing/main amd64 Packages
     1:10.0.6-1ubuntu3.1 1000
        400 http://archive.ubuntu.com/ubuntu noble-proposed/main amd64 Packages
 *** 1:10.0.6-1ubuntu3 500
        500 http://archive.ubuntu.com/ubuntu noble/main amd64 Packages
        100 /var/lib/dpkg/status
     1:10.0.2-3ubuntu3 1
          1 http://archive.ubuntu.com/ubuntu mantic/main amd64 Packages
     9.4.1-24~deb12u3 1
          1 http://ftp.dk.debian.org/debian bookworm/main amd64 Packages
```

# Update Repositories
apt update

# Print Current Date
date
2024-05-10T13:32:00 CEST

# Before Upgrade
ls -l /usr/lib/dhcpcd/dhcpcd-hooks/30-hostname
   -rw-r--r-- 1 root root 3764 May 9 09:42 /usr/lib/dhcpcd/dhcpcd-hooks/30-hostname

# Upgrade Package
apt dist-upgrade

# After Upgrade
ls -l /usr/lib/dhcpcd/dhcpcd-hooks/30-hostname
   -rw-r--r-- 1 root root 3764 May 7 12:12 /usr/lib/dhcpcd/dhcpcd-hooks/30-hostname

# After Upgrade - Excerpt of the File Contents
```
set_hostname()
{
        hfqdn=false
        hshort=false
        case "$hostname_fqdn" in
        [Yy][Ee][Ss]|[Tt][Rr][Uu][Ee]|1) hfqdn=true;;
        ""|[Ss][Ee][Rr][Vv][Ee][Rr]) ;;
        *) hshort=true;;
        esac

        need_hostname || return 0
```

# Final Remarks
The last line looks Good (it reflects the correct Fix, i.e. the `|| return` got modified into `|| return 0`).
Not sure why the File has a timestamp "so old" though (May 7 12:12), probably this is the time when the patch was written (https://bugs.launchpad.net/ubuntu/+source/initramfs-tools/+bug/2064926/comments/32).

# Reboot
update-initramfs -k all -u; update-grub; update-initramfs -k all; update-grub; reboot

# Save dmesg
dmesg

# Save initramfs debug log
cat /run/initramfs/initramfs.debug

# Save systemd-analze
systemd-analyze
Startup finished in 22.809s (kernel) + 53.824s ...

All autopkgtests for the newly accepted dhcpcd (1:10.0.6-1ubuntu3.1) for noble have finished running.
The following regressions have been reported in tests triggered by the package:

initramfs-tools/0.142ubuntu25 (armhf)

Please visit the excuses page listed below and investigate the failures, proceeding afterwards as per the StableReleaseUpdates policy regarding autopkgtest regressions [1].

https://people.canonical.com/~ubuntu-archive/proposed-migration/noble/update_excuses.html#dhcpcd

[1] https://wiki.ubuntu.com/StableReleaseUpdates#Autopkgtest_Regressions

Thank you!

This bug was fixed in the package dhcpcd - 1:10.0.6-4

---------------
dhcpcd (1:10.0.6-4) unstable; urgency=medium

  [ Benjamin Drung ]
  * [ patches ]
    + hooks/30-hostname:
      Exit with 0 if setting hostname is not needed (LP: #2064926).

 -- Martin-Éric Racine <email address hidden> Tue, 07 May 2024 13:49:47 +0300