jammy beta (220330) arm iso pxe boot kernel panic on Ampere Mt. Jade

[Taihsiang Ho]

= Description =
Platforms: Ampere Mt. Jade Altra (bizzy), Cavium thunderX crb2s (recht)
Image: Jammy Beta (220330)

I setup my pxe server to provision jammy beta and got the following kernel panic message after grub stage:

log from console log

[ 1.176614] integrity: Couldn't parse dbx signatures: -74^M
[ 1.371630] Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(0,0)^M
[ 1.379891] CPU: 42 PID: 1 Comm: swapper/0 Not tainted 5.15.0-23-generic #23-Ubuntu^M
[ 1.387535] Hardware name: WIWYNN Mt.Jade Server System B81.030Z1.0007/Mt.Jade Motherboard, BIOS 1.6.20210526 (SCP: 1.06.20210526) 2021/05/26^M
[ 1.400215] Call trace:^M
[ 1.402649] dump_backtrace+0x0/0x1ec^M
[ 1.406310] show_stack+0x24/0x30^M
[ 1.409614] dump_stack_lvl+0x68/0x84^M
[ 1.413271] dump_stack+0x18/0x34^M
[ 1.416573] panic+0x18c/0x39c^M
[ 1.419616] mount_block_root+0x160/0x210^M
[ 1.423622] mount_root+0x12c/0x14c^M
[ 1.427097] prepare_namespace+0x140/0x1a0^M
[ 1.431182] kernel_init_freeable+0x1c8/0x214^M
[ 1.435527] kernel_init+0x30/0x160^M
[ 1.439006] ret_from_fork+0x10/0x20^M
[ 1.442573] SMP: stopping secondary CPUs^M
[ 1.447323] Kernel Offset: 0x55263ee90000 from 0xffff800008000000^M
[ 1.453404] PHYS_OFFSET: 0x80000000^M
[ 1.456879] CPU features: 0x000085c1,a3302e42^M
[ 1.461225] Memory Limit: none^M
[ 1.464271] ---[ end Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(0,0) ]---^M

= Steps to Reproduce =
1. Followed this guide to setup the pxe server https://discourse.ubuntu.com/t/netbooting-the-live-server-installer-via-uefi-pxe-on-arm-aarch64-arm64-and-x86-64-amd64/19240 with the jammy beta image (220330) http://cdimage.ubuntu.com/ubuntu-server/daily-live/20220330/jammy-live-server-arm64.iso
1-1. You may use this script to perform the set-up https://github.com/tai271828/ubuntu-autoinstall-pxe-server by invoking: `sudo ./setup-pxe-server.sh --url http://cdimage.ubuntu.com/ubuntu-server/daily-live/20220330/jammy-live-server-arm64.iso`
2. Boot the system via PXE
3. Select Ubuntu at Grub menu

= Expected Result =
The image is loaded to the system locally via PXE, and subiquity is launched

= Actual Result =
Console log simply shows nothing for 10 seconds and then the kernel panic shows up.

= Additional Information =
- If we install via the virtual CD of the server, subiquity could be launched and the installation process completes successfully.
- MAAS could deploy Jammy to the Mt. Jade server as well.

[Taihsiang Ho (tai271828)]

bizzy.log is the console log of the Mt. Jade server. The last entry is the kernel panic because of the pxe boot. The last successful deployment in bizzy.log is performed by MAAS.

[Taihsiang Ho (tai271828)]

Attached bizzy-debug.log, which is the console log of the Mt. Jade server (bizzy) with the kernel parameter "debug" enabled.

[Ubuntu Kernel Bot (ubuntu-kernel-bot)]

This bug is missing log files that will aid in diagnosing the problem. While running an Ubuntu kernel (not a mainline or third-party kernel) please enter the following command in a terminal window:

apport-collect 1967562

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

[Paolo Pisati (p-pisati)]

I just deployed Jammy on recht (using MAAS) and it seems fine:

...
ubuntu@recht:~$ uname -a
Linux recht 5.15.0-23-generic #23-Ubuntu SMP Fri Mar 11 14:57:40 UTC 2022 aarch64 aarch64 aarch64 GNU/Linux

ubuntu@recht:~$ lsb_release -d
Description: Ubuntu Jammy Jellyfish (development branch)

ubuntu@recht:~$ sudo dmesg | grep "Machine model"
[ 0.000000] Machine model: cavium,thunder-88xx
...

[dann frazier (dannf)]

Yeah, it's not a MAAS deploy issue, but a subiquity PXE install issue (MAAS deploys this system fine).

@Tai this bit looks weird to me:

[ 0.000000] Kernel command line: BOOT_IMAGE=/casper/vmlinuz debug root=/dev/ram0 ramdisk_size=1500000 ip=dhcp url=http://10.229.56.0/jammy-live-server-arm64.iso autoinstall ds=nocloud-net;s=http://10.229.56.0/ ---
[ 0.000000] Unknown kernel command line parameters "autoinstall --- BOOT_IMAGE=/casper/vmlinuz ramdisk_size=1500000 ip=dhcp url=http://10.229.56.0/jammy-live-server-arm64.iso ds=nocloud-net;s=http://10.229.56.0/", will be passed to user space.

Like that there maybe two "---" delimiters. Can you provide the grub.cfg used?

[Taihsiang Ho (tai271828)]

@dann , I checked the grub entry prior to filing this bug. For now the pxe server is used for the other purpose. Let me reproduce the post-mortem information later on. Thanks for the tip!

[Taihsiang Ho (tai271828)]

@Paolo , thanks for verifying. Right, MAAS deployment looks good (see my comment of "Additional Information" in the bug description) as what Dann pointed out.

[Taihsiang Ho (tai271828)]

Redo with the same iso but different downloading url: http://cdimage.ubuntu.com/releases/22.04/beta/ubuntu-22.04-beta-live-server-arm64.iso

I can still reproduce the issue. The grub entry looks good (no duplicate ---)[1].

The attachment bizzy-maas-220406-01.log is the corresponding console log.

setparams 'Ubuntu Server'

        set gfxpayload=keep
        linux /casper/vmlinuz quiet root=/dev/ram0 ramdisk_size=1500000 ip=dhcp url=http://cdimage.ubuntu.com/releases/22.04/beta/ubuntu-22.04-beta-live-server-arm64.iso autoinstall "ds=nocloud-net;s=http://10.229.56.0/" ---
        initrd /casper/initrd

[Taihsiang Ho (tai271828)]

log snippet from the attachment "bizzy-maas-220406-01.log" of comment#8

[ 1.354637] CPU: 2 PID: 1 Comm: swapper/0 Not tainted 5.15.0-23-generic #23-Ubuntu
[ 1.362195] Hardware name: WIWYNN Mt.Jade Server System B81.030Z1.0007/Mt.Jade Motherboard, BIOS 1.6.20210526 (SCP: 1.06.20210526) 2021/05/26
[ 1.374876] Call trace:
[ 1.377310] dump_backtrace+0x0/0x1ec
[ 1.380968] show_stack+0x24/0x30
[ 1.384272] dump_stack_lvl+0x68/0x84
[ 1.387929] dump_stack+0x18/0x34
[ 1.391232] panic+0x18c/0x39c
[ 1.394275] mount_block_root+0x160/0x210
[ 1.398281] mount_root+0x12c/0x14c
[ 1.401757] prepare_namespace+0x140/0x1a0
[ 1.405842] kernel_init_freeable+0x1c8/0x214
[ 1.410187] kernel_init+0x30/0x160
[ 1.413667] ret_from_fork+0x10/0x20
[ 1.417235] SMP: stopping secondary CPUs
[ 1.421957] Kernel Offset: 0x34a8864c0000 from 0xffff800008000000
[ 1.428038] PHYS_OFFSET: 0x80000000
[ 1.431514] CPU features: 0x000085c1,a3302e42
[ 1.435859] Memory Limit: none
[ 1.438905] ---[ end Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(0,0) ]---

[dann frazier (dannf)]

I can reproduce, and I've attached the full console log (!quiet, +debug). Here's some interesting pieces of the log:

EFI stub: Booting Linux Kernel...
EFI stub: Generating empty DTB
error: couldn't send network packet.
EFI stub: Loaded initrd from LINUX_EFI_INITRD_MEDIA_GUID device path
EFI stub: Exiting boot services...
[ 0.000000] Booting Linux on physical CPU 0x0000120000 [0x413fd0c1]
[ 0.000000] Linux version 5.15.0-25-generic (buildd@bos02-arm64-058) (gcc (Ubuntu 11.2.0-19ubuntu1) 11.2.0, GNU ld (GNU Binutils for Ubuntu) 2.38) #25-Ubuntu SMP Wed Mar 30 15:57:31 UTC 2022 (Ubuntu 5.15.0-25.25-generic 5.15.30)
[...]
[ 15.338070] Trying to unpack rootfs image as initramfs...
[ 15.439137] Initramfs unpacking failed: invalid magic at start of compressed archive
[ 15.461425] Freeing initrd memory: 103244K
[...]

We can see at the end there that the initrd failed to unpack, and that will definitely lead to a "Unable to mount root fs" panic. But why did it fail to unpack? One possibility is that the initrd failed to download. The TFTP server does report that it downloaded:

Apr 8 19:38:59 avoton02 in.tftpd[4218]: RRQ from 10.229.58.47 filename /casper/vmlinuz
Apr 8 19:39:02 avoton02 in.tftpd[4220]: RRQ from 10.229.58.47 filename /casper/vmlinuz
Apr 8 19:39:06 avoton02 in.tftpd[4221]: RRQ from 10.229.58.47 filename /casper/initrd

OK, then maybe it only partially downloaded? Well, the amount of memory the kernel reports freeing is close to the size of the initrd, so that's probably not it:

$ du -s /srv/tftp/casper/initrd
103248 /srv/tftp/casper/initrd

Then perhaps the kernel doesn't support decompressing this compression format. What is the compression format?

$ file /srv/tftp/casper/initrd
/srv/tftp/casper/initrd: Zstandard compressed data (v0.8+), Dictionary ID: None

Does the kernel support that? Let's look at the kernel config:

ubuntu@avoton02:/tmp$ dpkg-deb -x linux-modules-5.15.0-25-generic_5.15.0-25.25_arm64.deb x
ubuntu@avoton02:/tmp$ grep ZSTD_DECOMPRESS x/boot/config-5.15.0-25-generic
CONFIG_ZSTD_DECOMPRESS=y

hm.. it does. That's weird. The other mystery is that this all seems to work when booted from the ISO. Let's take a look at that boot log and see if we can spot anything different.

[dann frazier (dannf)]

The iso-booted-kernel has no problem unpacking the initramfs:

[ 15.282839] Trying to unpack rootfs image as initramfs...
[...]
[ 15.935483] Freeing initrd memory: 103248K

But that's interesting, the freed initrd memory size reported is different here. When PXE-booted, it was 103244K. 103248K actually matches the initrd size reported by `ls`. I assumed some kind of rounding error, but maybe that 4K difference is a clue.

EDIT: No, turns out I was pointing at a daily ISO build and it has been updated, and initrd sizes between the two have a 4K initrd difference.

[dann frazier (dannf)]

GRUB is responsible for loading the initrd into memory, so it is possible that this is a GRUB regression. Also, this message is new to me:
  EFI stub: Loaded initrd from LINUX_EFI_INITRD_MEDIA_GUID device path
So maybe this is related to a new GRUB initrd loading method?

To test that, I grabbed focal's grubnetaa64.efi[*] and retested. This actually worked, and contains no "LINUX_EFI_INITRD_MEDIA_GUID" messages in the stub:

EFI stub: Booting Linux Kernel...
EFI stub: Using DTB from configuration table
EFI stub: Exiting boot services...
[ 0.000000] Booting Linux on physical CPU 0x0000120000 [0x413fd0c1]

So, adding a grub task.

[*] http://ports.ubuntu.com/ubuntu-ports/dists/focal/main/uefi/grub2-arm64/2.04-1ubuntu26/grubnetaa64.efi.signed

[dann frazier (dannf)]

I turned on grub debugging (set debug=all in grub.cfg), and this seems interesting. The "error: couldn't send network packet." message may actually be telling us something is wrong with downloading the initrd. Full log attached, here's a filtered version:

[...]
loader/efi/linux.c:80: UEFI stub kernel:
loader/efi/linux.c:81: PE/COFF header @ 00000040
loader/efi/linux.c:95: LoadFile2 initrd loading enabled
loader/efi/linux.c:459: kernel file size: 46496128
loader/efi/linux.c:461: kernel numpages: 11352
loader/efi/linux.c:478: kernel @ 0xa1e43000
kern/disk.c:196: Opening `tftp,10.229.58.59'...
disk/efi/efidisk.c:482: opening tftp
kern/disk.c:281: Opening `tftp,10.229.58.59' failed.
kern/disk.c:295: Closing `tftp'.
kern/verifiers.c:88: file: /casper/initrd type: 131076
loader/efi/linux.c:396: LoadFile2 initrd loading protocol installed
]
loader/efi/linux.c:141: Installed/updated FDT configuration table @ 0x0
loader/efi/linux.c:191: linux command line: 'BOOT_IMAGE=/casper/vmlinuz
root=/dev/ram0 ramdisk_size=1500000 ip=dhcp
url=http://cdimage.ubuntu.com/ubuntu-server/daily-live/20220408/jammy-live-serv
er-arm64.iso --- debug'
kern/efi/sb.c:111: UEFI Secure Boot state: Disabled
loader/efi/peimage.c:215: PE-COFF header checked
loader/efi/peimage.c:282: sections loaded
loader/efi/peimage.c:493: no relocations
loader/efi/peimage.c:709: Executing image loaded at 0x9f0b0000
Entry point 0xa0fb8428
Size 0x02d90000
EFI stub: Booting Linux Kernel...
EFI stub: Generating empty DTB
loader/efi/linux.c:348: Providing initrd via LOAD_FILE2_PROTOCOL
net/net.c:1596: error receiving: 28: couldn't send network packet
net/net.c:1596: error receiving: 28: couldn't send network packet
net/net.c:1596: error receiving: 28: couldn't send network packet
net/net.c:1596: error receiving: 28: couldn't send network packet
net/net.c:1596: error receiving: 28: couldn't send network packet
net/net.c:1596: error receiving: 28: couldn't send network packet
net/net.c:1596: error receiving: 28: couldn't send network packet
net/net.c:1596: error receiving: 28: couldn't send network packet
error: couldn't send network packet.
EFI stub: Loaded initrd from LINUX_EFI_INITRD_MEDIA_GUID device path
EFI stub: Exiting boot services...

[Julian Andres Klode (juliank)]

To figure out if it's the new loader code, remove efi-implement-grub_efi_run_image.patch (or the grub-core/loader/efi/linux.c hunk) or enable secure boot (if available). The new code path on insecure systems uses the upstream loader + LoadFile2 support, as is necessary for RISC-V.

[Julian Andres Klode (juliank)]

Though maybe you also need to unapply efi-implemented-LoadFile2-initrd-loading-protocol-fo.patch

[dann frazier (dannf)]

Removing efi-implement-grub_efi_run_image.patch didn't avoid the problem, nor did removing both that and efi-implemented-LoadFile2-initrd-loading-protocol-fo.patch, but that appears to just be because the arm64 code gets migrated to the efi loader code later in the series, basically reintroducing the LoadFile2 support.

Instead, I just made the following change, which does avoid the problem:

Index: grub2-unsigned-2.06/grub-core/loader/efi/linux.c
===================================================================
--- grub2-unsigned-2.06.orig/grub-core/loader/efi/linux.c
+++ grub2-unsigned-2.06/grub-core/loader/efi/linux.c
@@ -88,7 +88,7 @@ grub_arch_efi_linux_check_image (struct
    * LoadFile2 based initrd loading protocol if the image version is >= 1.
    */
   if (optional_header->major_image_version >= 1)
- initrd_use_loadfile2 = 1;
+ initrd_use_loadfile2 = 0;
    else
     initrd_use_loadfile2 = 0;

[dann frazier (dannf)]

I randomly picked another ARM server, a Cavium ThunderX system, and it also fails to net boot w/ jammy's GRUB, but works fine w/ the patch in comment #16. So this is looking like possibly an architecture-wide issue. I tested on an x86 VM, but I didn't see any of the LoadFile2 messages. I assume (didn't check the code) that LoadFile2 initramfs is disabled there.

[Taihsiang Ho (tai271828)]

Since it seems a grub issue, I reported the issue to qatracker of daily build to make the release team aware of this issue, and hopefully the information will be helpful before releasing RC.

http://iso.qa.ubuntu.com/qatracker/milestones/429/builds/246802/testcases/1697/results

[Ubuntu QA Website (ubuntuqa)]

This bug has been reported on the Ubuntu ISO testing tracker.

A list of all reports related to this bug can be found here:
http://iso.qa.ubuntu.com/qatracker/reports/bugs/1967562

[Heinrich Schuchardt (xypron)]

On riscv64 we cannot boot without the LoadFile2 protocol. So the short term fix of forcing to 0 must be architecture specific. Check for __riscv not defined.

[Heinrich Schuchardt (xypron)]

As the log below shows grub_net_fini_hw() is called before entering the kernel and before the LoadFile2 protocol is executed:

loader/efi/linux.c:478: kernel @ 0xf63d8000
net/net.c:1559: fs_close() name: /casper/vmlinuz
net/net.c:1510: fs_open() name: /casper/initrd
loader/efi/linux.c:396: LoadFile2 initrd loading protocol installed
net/net.c:1819: grub_net_fini_hw()
net/drivers/efi/efinet.c:232: efi_net close_card
loader/efi/linux.c:141: Installed/updated FDT configuration table @ 0x0
loader/efi/linux.c:191: linux command line: 'BOOT_IMAGE=/casper/vmlinuz
efi=debug earlyprintk
url=https://cdimage.ubuntu.com/ubuntu-server/daily-live/current/jammy-live-serv
er-arm64.iso'
loader/efi/peimage.c:215: PE-COFF header checked
loader/efi/peimage.c:282: sections loaded
loader/efi/peimage.c:493: no relocations
loader/efi/peimage.c:709: Executing image loaded at 0xf3640000
Entry point 0xf55473c8
Size 0x02d90000
EFI stub: Booting Linux Kernel...
EFI stub: EFI_RNG_PROTOCOL unavailable
EFI stub: Generating empty DTB
loader/efi/linux.c:348: Providing initrd via LOAD_FILE2_PROTOCOL
net/net.c:1685: fs_read_real() name: /casper/initrd
net/drivers/efi/efinet.c:169: efi_net open_card
net/drivers/efi/efinet.c:75: Timeout: limit_time 50680, new_time 50681
error: couldn't send network packet.

[dann frazier (dannf)]

Well spotted Heinrich. I'd hypothesized that something was shutting down the network stack, but didn't yet no where to look, and overlooked grub_net_fini_hw() message! With that hint, I went ahead and tried commenting out[*] the registration of that callback, and voila, the ReadFile2 initramfs loading from TFTP worked:

loader/efi/linux.c:348: Providing initrd via LOAD_FILE2_PROTOCOL
EFI stub: Loaded initrd from LINUX_EFI_INITRD_MEDIA_GUID device path
EFI stub: Exiting boot services...

But I'm not sure of the correct way to address it. Perhaps the kernel's efi stub needs to own network device shutdown to do this properly? I'm happy to bring this discussion up on the mailing list. But, for jammy, seems like disabling ReadFile2 initramfs for !riscv64 would be the safest approach at this point.

[*]
Index: grub2-unsigned-2.06/grub-core/net/net.c
===================================================================
--- grub2-unsigned-2.06.orig/grub-core/net/net.c
+++ grub2-unsigned-2.06/grub-core/net/net.c
@@ -1818,11 +1818,11 @@ grub_net_fini_hw (int noreturn __attribu
   return GRUB_ERR_NONE;
 }

-static grub_err_t
+/*static grub_err_t
 grub_net_restore_hw (void)
 {
   return GRUB_ERR_NONE;
-}
+ }*/

 static int
 grub_config_search_through (char *config, char *suffix,
@@ -2048,9 +2048,9 @@ GRUB_MOD_INIT(net)
   grub_dns_init ();

   grub_net_open = grub_net_open_real;
- fini_hnd = grub_loader_register_preboot_hook (grub_net_fini_hw,
+ /* fini_hnd = grub_loader_register_preboot_hook (grub_net_fini_hw,
       grub_net_restore_hw,
- GRUB_LOADER_PREBOOT_HOOK_PRIO_DISK);
+ GRUB_LOADER_PREBOOT_HOOK_PRIO_DISK);*/
   grub_net_poll_cards_idle = grub_net_poll_cards_idle_real;

 #ifdef GRUB_MACHINE_EFI

[Heinrich Schuchardt (xypron)]

As long as the kernel stub does not invoke the SNP protocol itself it is safe for GRUB to assume that it is still in a good state when reaching the Load File2 protocol call.

I am not aware of any requirement in the UEFI specification to leave the network adapter in a specific state on ExitBootServices().

[Heinrich Schuchardt (xypron)]

As we are close to release date we should simply disable Load File2 protocol on ARM in Jammy:
https://code.launchpad.net/~xypron/grub/+git/grub/+merge/419407

[dann frazier (dannf)]

reported upstream: https://lists.gnu.org/archive/html/grub-devel/2022-04/msg00055.html

[Launchpad Janitor (janitor)]

This bug was fixed in the package grub2 - 2.06-2ubuntu7

---------------
grub2 (2.06-2ubuntu7) jammy; urgency=medium

  [ Heinrich Schuchardt ]
  * Disable LOAD FILE2 protocol for initrd on ARM (LP: #1967562)

 -- dann frazier <email address hidden> Fri, 15 Apr 2022 15:50:11 -0600

[Taihsiang Ho (tai271828)]

The jammy RC (20220418.2) looks good for Ampere Mt. Jade Altra (bizzy). I can pxe install the server successfully.

By the way autoinstall of subiquity also works like a charm.