[Bug 2098515] Re: IPv6-only (single stack) instances configuring network over dhcp in initramfs will take a long time to boot due to loop in dhcpcd -4

Sun Apr 13 12:55:58 UTC 2025

I am not sure if this is a right place but I did not find WQ_UNBOUND
elsewhere for plucky.

Using ISO from /current/plucky-desktop-amd64.iso 2025-04-13 06:38
Installing as VBox VM I could see few lines of consider using WQ_UNBOUND

2025-04-13T11:56:54.371841+00:00 ubuntu kernel: loop16: detected capacity change from 0 to 187776
2025-04-13T11:56:54.371842+00:00 ubuntu kernel: workqueue: ata_sff_pio_task hogged CPU for >13333us 4 times, consider switching to WQ_UNBOUND

2025-04-13T11:56:54.371842+00:00 ubuntu kernel: audit: type=1400 audit(1744545388.859:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="snap-update-ns.desktop-security-center" pid=1453 comm="apparmor_parser"
2025-04-13T11:56:54.371843+00:00 ubuntu kernel: audit: type=1400 audit(1744545388.995:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/snap/snapd/23771/usr/lib/snapd/snap-confine" pid=1452 comm="apparmor_parser"

...

2025-04-13T11:56:54.371887+00:00 ubuntu kernel: audit: type=1400 audit(1744545397.183:13): apparmor="STATUS" operation="profile_load" profile="unconfined" name="snap.desktop-security-center.desktop-security-center" pid=1520 comm="apparmor_parser"
2025-04-13T11:56:54.371887+00:00 ubuntu kernel: workqueue: drm_fb_helper_damage_work hogged CPU for >13333us 7 times, consider switching to WQ_UNBOUND

...

2025-04-13T11:56:54.371893+00:00 ubuntu kernel: workqueue: ata_sff_pio_task hogged CPU for >13333us 5 times, consider switching to WQ_UNBOUND
2025-04-13T11:56:54.371893+00:00 ubuntu kernel: audit: type=1400 audit(1744545401.126:20): apparmor="STATUS" operation="profile_load" profile="unconfined" name="snap.firmware-updater.firmware-notifier" pid=1606 comm="apparmor_parser"

...

2025-04-13T11:56:54.371905+00:00 ubuntu kernel: audit: type=1400 audit(1744545408.012:36): apparmor="STATUS" operation="profile_load" profile="unconfined" name="snap.thunderbird.hook.post-refresh" pid=1669 comm="apparmor_parser"
2025-04-13T11:56:54.371906+00:00 ubuntu kernel: workqueue: drm_fb_helper_damage_work hogged CPU for >13333us 11 times, consider switching to WQ_UNBOUND

2025-04-13T11:56:54.371906+00:00 ubuntu kernel: kauditd_printk_skb: 6 callbacks suppressed
2025-04-13T11:56:54.371907+00:00 ubuntu kernel: audit: type=1400 audit(1744545412.145:43): apparmor="STATUS" operation="profile_load" profile="unconfined" name="rsyslogd" pid=1715 comm="apparmor_parser"
2025-04-13T11:56:56.543550+00:00 ubuntu kernel: workqueue: ata_sff_pio_task hogged CPU for >13333us 7 times, consider switching to WQ_UNBOUND

2025-04-13T11:56:58.576126+00:00 ubuntu kernel: NET: Registered PF_QIPCRTR protocol family

2025-04-13T11:56:54.371844+00:00 ubuntu kernel: audit: type=1400
audit(1744545389.129:4): apparmor="STATUS" operation="profile_load"
profile="unconfined" name="/snap/snapd/23771/usr/lib/snapd/snap-
confine//mount-namespace-capture-helper" pid=1452 comm="apparmor_parser"

2025-04-13T11:56:54.371845+00:00 ubuntu kernel: workqueue: drm_fb_helper_damage_work hogged CPU for >13333us 4 times, consider switching to WQ_UNBOUND
2025-04-13T11:56:54.371845+00:00 ubuntu kernel: workqueue: drm_fb_helper_damage_work hogged CPU for >13333us 5 times, consider switching to WQ_UNBOUND
2025-04-13T11:56:54.371846+00:00 ubuntu kernel: audit: type=1400 audit(1744545391.110:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="snap-update-ns.firefox" pid=1455 comm="apparmor_parser"

...

profile="snap.firefox.hook.install" name="/var/lib/snapd/hostfs/usr/share/hunspell/" pid=2964 comm="find" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
2025-04-13T09:58:24.211456+00:00 ubuntu kernel: workqueue: ata_sff_pio_task hogged CPU for >13333us 11 times, consider switching to WQ_UNBOUND

...

2025-04-13T10:04:03.545660+00:00 ubuntu kernel: overlayfs: lowerdir is in-use as upperdir/workdir of another mount, accessing files from both mounts will result in undefined behavior.
2025-04-13T10:04:14.999014+00:00 ubuntu kernel: workqueue: e1000_watchdog [e1000] hogged CPU for >13333us 4 times, consider switching to WQ_UNBOUND
2025-04-13T10:04:17.029030+00:00 ubuntu kernel: workqueue: e1000_watchdog [e1000] hogged CPU for >13333us 5 times, consider switching to WQ_UNBOUND
2025-04-13T10:04:43.082137+00:00 ubuntu kernel: workqueue: e1000_watchdog [e1000] hogged CPU for >13333us 7 times, consider switching to WQ_UNBOUND
2025-04-13T10:04:44.897495+00:00 ubuntu kernel: overlayfs: fs on '/tmp/tmpsazhlq2l/root.dir' does not support file handles, falling back to xino=off.

...

2025-04-13T10:05:19.300871+00:00 ubuntu kernel: EXT4-fs (sda2): mounted filesystem 1154c3a9-0fc8-4334-9344-672e4870360f r/w with ordered data mode. Quota mode: none.
2025-04-13T10:06:02.937331+00:00 ubuntu kernel: workqueue: blk_mq_run_work_fn hogged CPU for >13333us 4 times, consider switching to WQ_UNBOUND
2025-04-13T10:06:03.095185+00:00 ubuntu kernel: workqueue: blk_mq_run_work_fn hogged CPU for >13333us 5 times, consider switching to WQ_UNBOUND
2025-04-13T10:06:03.279123+00:00 ubuntu kernel: workqueue: blk_mq_run_work_fn hogged CPU for >13333us 7 times, consider switching to WQ_UNBOUND
2025-04-13T10:06:27.357878+00:00 ubuntu kernel: workqueue: blk_mq_run_work_fn hogged CPU for >13333us 11 times, consider switching to WQ_UNBOUND
2025-04-13T10:06:29.999963+00:00 ubuntu kernel: workqueue: e1000_watchdog [e1000] hogged CPU for >13333us 11 times, consider switching to WQ_UNBOUND
2025-04-13T10:06:31.937178+00:00 ubuntu kernel: workqueue: ata_sff_pio_task hogged CPU for >13333us 19 times, consider switching to WQ_UNBOUND
2025-04-13T10:06:33.205187+00:00 ubuntu kernel: workqueue: blk_mq_run_work_fn hogged CPU for >13333us 19 times, consider switching to WQ_UNBOUND
2025-04-13T10:07:27.783845+00:00 ubuntu kernel: workqueue: blk_mq_run_work_fn hogged CPU for >13333us 35 times, consider switching to WQ_UNBOUND
2025-04-13T10:08:53.705942+00:00 ubuntu kernel: workqueue: blk_mq_run_work_fn hogged CPU for >13333us 67 times, consider switching to WQ_UNBOUND
2025-04-13T10:14:04.202004+00:00 ubuntu kernel: workqueue: blk_mq_run_work_fn hogged CPU for >13333us 131 times, consider switching to WQ_UNBOUND 

The system did not crash so I could not make a proper bug-report and I installed the Extended version, rebooted, updated, installed language, made canges to settings etc with no problem...

I have saved the /var/log directory in case you need any file or the whole directory, I will be happy to send.

Thank you all

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to open-iscsi in Ubuntu.
https://bugs.launchpad.net/bugs/2098515

Title:
  IPv6-only (single stack) instances configuring network over dhcp in
  initramfs will take a long time to boot due to loop in dhcpcd -4

Status in open-iscsi package in Ubuntu:
  Triaged
Status in open-iscsi source package in Jammy:
  New
Status in open-iscsi source package in Noble:
  New
Status in open-iscsi source package in Plucky:
  Triaged

Bug description:
  Cloud instances that configure network over DHCP in initramfs, will go
  through a "for ROUNDTTT in 30 60 90 120" loop inside
  configure_networking().

  If the DHCP server is only offering a IPv6 (no IPv4), the instance
  will take more than 5 minutes to boot, because it will first go
  through a loop trying to obtain IPv4 IP (dhcpcd -1KL -t $ROUNDTTT -4
  ${DEVICE:+"${DEVICE}"}) for 30+60+90+120 seconds (total 300 seconds -
  5 minutes), which won't work, until it times out, and then resume the
  boot process.

  In https://bugs.launchpad.net/ubuntu/+source/initramfs-
  tools/+bug/2091904 initramfs-tools improved this situation, looking
  for IPv6 information in /sys/firmware/ibft/ethernet*/ip-addr to decide
  whether to look for IPv6 or IPv4, however that assumes that IP
  information will be available through ibft, which is not always true.

  If no IP information is available through ibft, we still go through
  this incorrect loop, delaying the boot process.

  Example from an instance booting through virtual disks, with no ibft,
  and IPv6-only on Oracle Cloud:

  ```
  [    0.000000] Command line: BOOT_IMAGE=/vmlinuz-6.12.0-1001-oracle root=LABEL=cloudimg-rootfs ro console=tty1 console=ttyS0 nvme.shutdown_timeout=10 libiscsi.debug_libiscsi_eh=1 crash_kexec_post_notifiers
  [...]
  Begin: Running /scripts/init-premount ... done.
  Begin: Mounting root file system ... Begin: Running /scripts/local-top ... [    2.863248] No iBFT detected.
  Could not setup fw entries.
  Begin: Waiting up to 180 secs for any network device to become available ... done.
  dhcpcd-10.1.0 starting
  dev: loaded udev
  [    2.906793] 8021q: 802.1Q VLAN Support v1.8
  [    2.917496] 8021q: adding VLAN 0 to HW filter on device enp0s5
  DUID 00:03:00:01:02:00:17:36:95:6d
  enp0s5: IAID 17:36:95:6d
  enp0s5: carrier acquired
  enp0s5: IAID 17:36:95:6d
  [    2.983134] workqueue: drm_fb_helper_damage_work hogged CPU for >10000us 7 times, consider switching to WQ_UNBOUND
  enp0s5: soliciting a DHCP lease
  timed out
  exiting due to oneshot
  dhcpcd exited
  Sleeping 0 seconds before retrying getting a DHCP lease
  dhcpcd-10.1.0 starting
  dev: loaded udev
  DUID 00:03:00:01:02:00:17:36:95:6d
  enp0s5: IAID 17:36:95:6d
  enp0s5: soliciting a DHCP lease
  timed out
  exiting due to oneshot
  dhcpcd exited
  Sleeping 0 seconds before retrying getting a DHCP lease
  dhcpcd-10.1.0 starting
  dev: loaded udev
  DUID 00:03:00:01:02:00:17:36:95:6d
  enp0s5: IAID 17:36:95:6d
  enp0s5: soliciting a DHCP lease
  timed out
  exiting due to oneshot
  dhcpcd exited
  Sleeping 0 seconds before retrying getting a DHCP lease
  dhcpcd-10.1.0 starting
  dev: loaded udev
  DUID 00:03:00:01:02:00:17:36:95:6d
  enp0s5: IAID 17:36:95:6d
  enp0s5: soliciting a DHCP lease
  timed out
  exiting due to oneshot
  dhcpcd exited
  Sleeping 0 seconds before retrying getting a DHCP lease
  no search or nameservers found in /run/net-.conf /run/net-*.conf /run/net6-*.conf
  [  303.057039] Loading iSCSI transport class v2.0-870.
  [  303.069113] iscsi: registered transport (tcp)
  Could not get boot entry.
  done.
  ```

  Full log: https://pastebin.ubuntu.com/p/Sk5dcvpPyY/

  We can see such loop between lines 1136 and 1176.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/open-iscsi/+bug/2098515/+subscriptions