Score:0

Kubuntu 23.04 hangs at boot for ~90 seconds

in flag
C-B

I'm experiencing a ~90 seconds hang when booting a fresh install of Kubuntu 23.04 using a encrypted LLVM volume created by the Kubuntu installer without further customization.

When the boot hangs, I'm seeing the Kubuntu splash screen.

Looking at output of dmesg, I don't know where to look further and would be happy for any pointers. Excerpt from dmesg:

[snip]
[   10.101831] input: HDA Intel PCH Front Mic as /devices/pci0000:00/0000:00:1f.3/sound/card0/input15
[   10.101867] input: HDA Intel PCH Rear Mic as /devices/pci0000:00/0000:00:1f.3/sound/card0/input16
[   10.101892] input: HDA Intel PCH Line as /devices/pci0000:00/0000:00:1f.3/sound/card0/input17
[   10.101913] input: HDA Intel PCH Line Out as /devices/pci0000:00/0000:00:1f.3/sound/card0/input18
[   10.101936] input: HDA Intel PCH Front Headphone as /devices/pci0000:00/0000:00:1f.3/sound/card0/input19
[   10.780731] loop0: detected capacity change from 0 to 8
[   10.781940] EXT4-fs (nvme0n1p2): mounted filesystem xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx with ordered data mode. Quota mode: none.
[   10.781992] loop1: detected capacity change from 0 to 149488
[   10.782535] loop2: detected capacity change from 0 to 149720
[   10.782992] loop3: detected capacity change from 0 to 495928
[   10.785986] loop4: detected capacity change from 0 to 498592
[   10.788070] loop5: detected capacity change from 0 to 943224
[   10.790246] loop6: detected capacity change from 0 to 942872
[   10.792170] loop7: detected capacity change from 0 to 187776
[   10.794978] loop8: detected capacity change from 0 to 102072
[   10.796585] loop9: detected capacity change from 0 to 109032
[   10.831368] audit: type=1400 audit(1684910795.895:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-senddoc" pid=935 comm="apparmor_parser"
[   10.831461] audit: type=1400 audit(1684910795.895:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-xpdfimport" pid=937 comm="apparmor_parser"
[   10.831545] audit: type=1400 audit(1684910795.895:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/haveged" pid=941 comm="apparmor_parser"
[   10.831918] audit: type=1400 audit(1684910795.895:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lsb_release" pid=929 comm="apparmor_parser"
[   10.832420] audit: type=1400 audit(1684910795.899:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-oosplash" pid=934 comm="apparmor_parser"
[   10.832524] audit: type=1400 audit(1684910795.899:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe" pid=930 comm="apparmor_parser"
[   10.832534] audit: type=1400 audit(1684910795.899:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe//kmod" pid=930 comm="apparmor_parser"
[   10.833457] audit: type=1400 audit(1684910795.899:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=932 comm="apparmor_parser"
[   10.833466] audit: type=1400 audit(1684910795.899:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_filter" pid=932 comm="apparmor_parser"
[   10.833473] audit: type=1400 audit(1684910795.899:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_groff" pid=932 comm="apparmor_parser"
[  100.058873] kauditd_printk_skb: 25 callbacks suppressed
[  100.058875] audit: type=1400 audit(1684910885.123:37): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="rsyslogd" pid=1008 comm="apparmor_parser"
[  100.076442] audit: type=1400 audit(1684910885.143:38): apparmor="DENIED" operation="capable" class="cap" profile="/usr/sbin/cupsd" pid=1113 comm="cupsd" capability=12  capname="net_admin"
[  100.124379] RTL8226B_RTL8221B 2.5Gbps PHY r8169-0-500:00: attached PHY driver (mii_bus:phy_addr=r8169-0-500:00, irq=MAC)
[  100.324582] r8169 0000:05:00.0 enp5s0: Link is Down
[  100.590480] loop10: detected capacity change from 0 to 8
[  102.660852] r8169 0000:05:00.0 enp5s0: Link is Up - 1Gbps/Full - flow control off
[  102.660863] IPv6: ADDRCONF(NETDEV_CHANGE): enp5s0: link becomes ready
[  102.662121] r8169 0000:05:00.0 enp5s0: Link is Up - 1Gbps/Full - flow control off
[  102.662146] r8169 0000:05:00.0 enp5s0: Link is Down
[  105.730946] r8169 0000:05:00.0 enp5s0: Link is Up - 1Gbps/Full - flow control off
[  115.464695] audit: type=1400 audit(1684910900.531:39): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/19122/usr/lib/snapd/snap-confine" pid=1903 comm="snap-confine" capability=12  capname="net_admin"
[  115.464702] audit: type=1400 audit(1684910900.531:40): apparmor="DENIED" operation="capable" class="cap" profile="/snap/snapd/19122/usr/lib/snapd/snap-confine" pid=1903 comm="snap-confine" capability=38  capname="perfmon"
[  115.675756] audit: type=1400 audit(1684910900.739:41): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.firefox" name="/var/lib/" pid=1944 comm="5" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[  115.675807] audit: type=1400 audit(1684910900.739:42): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.firefox" name="/var/lib/" pid=1944 comm="5" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[  115.675942] audit: type=1400 audit(1684910900.739:43): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.firefox" name="/var/lib/" pid=1944 comm="5" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[  115.675969] audit: type=1400 audit(1684910900.739:44): apparmor="DENIED" operation="open" class="file" profile="snap-update-ns.firefox" name="/var/lib/" pid=1944 comm="5" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[  116.335800] audit: type=1400 audit(1684910901.399:45): apparmor="DENIED" operation="unlink" class="file" profile="snap.firefox.firefox" name="/dev/char/195:255" pid=2014 comm="firefox" requested_mask="d" denied_mask="d" fsuid=1001 ouid=0
[  116.335896] audit: type=1400 audit(1684910901.399:46): apparmor="DENIED" operation="unlink" class="file" profile="snap.firefox.firefox" name="/dev/char/195:0" pid=2014 comm="firefox" requested_mask="d" denied_mask="d" fsuid=1001 ouid=0
[  116.335930] audit: type=1400 audit(1684910901.399:47): apparmor="DENIED" operation="unlink" class="file" profile="snap.firefox.firefox" name="/dev/char/195:0" pid=2014 comm="firefox" requested_mask="d" denied_mask="d" fsuid=1001 ouid=0
[  116.335980] audit: type=1400 audit(1684910901.399:48): apparmor="DENIED" operation="unlink" class="file" profile="snap.firefox.firefox" name="/dev/char/195:0" pid=2014 comm="firefox" requested_mask="d" denied_mask="d" fsuid=1001 ouid=0
[snip]

I'm seeing apparmor="DENIED" regarding cupsd in the vicinity. Could this somehow be related to the delay?

Zeiss Ikon avatar
cn flag
Try editing "nosplash" (without the quotes) into the "vmlinuz" command in the GRUB startup and watch for a start job counting down during that 90 second freeze period -- and report back what the start job is for.
C-B avatar
in flag
C-B
I booted with nosplash. After unlocking the encrypted volume, the last two lines I'm seeing when booting hangs are `cryptsetup [...] set up successfully` and `/dev/mapper/vgkubuntu-root: clean, x/y files, z blocks`. Then it hangs.
C-B avatar
in flag
C-B
I set pass to 0 in /etc/fstab to exclude fsck as a possible culprit, btw.
C-B avatar
in flag
C-B
Found it. I also removed "quiet" from the vmlinuz command and then had some more information: The hanging job was `job dev-disk-by\` followed by something looking like a UUID. I did not find that UUID in /etc/fstab, but in /etc/crypttab. It belonged to an external backup hdd that was once mounted and then removed again, but somehow created a permanent entry in /etc/crypttab. Of course mounting that non-existing drive couldn't work. Thanks for the pointer in the right direction!
Zeiss Ikon avatar
cn flag
Sounds like you should write a self-answer. Then you can get some rep for this. :)
I sit in a Tesla and translated this thread with Ai:

mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.