Re: [PATCH v3 1/2] init/initramfs.c: do unpacking asynchronously

[Alexander Egorenkov <egorenar@linux.ibm.com>]

Hello,

since e7cb072eb988 ("init/initramfs.c: do unpacking asynchronously"), we
started seeing the following problem on s390 arch regularly:

[    5.039734] wait_for_initramfs() called before rootfs_initcalls
[    5.042003] cryptomgr_test (155) used greatest stack depth: 11952 bytes left
[    5.214115] raid6: vx128x8  gen() 21961 MB/s
[    5.384073] raid6: vx128x8  xor() 14882 MB/s
[    5.384090] raid6: using algorithm vx128x8 gen() 21961 MB/s
[    5.384094] raid6: .... xor() 14882 MB/s, rmw enabled
[    5.384098] raid6: using s390xc recovery algorithm
[    5.386338] iommu: Default domain type: Translated·
[    5.387724] SCSI subsystem initialized
[    5.393858] cio: Partition identifier 4.9
[    6.361599] VFS: Disk quotas dquot_6.6.0
[    6.361852] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    6.374790] NET: Registered PF_INET protocol family
[    6.375187] IP idents hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[    6.381935] tcp_listen_portaddr_hash hash table entries: 8192 (order: 7, 720896 bytes, linear)
[    6.382234] TCP established hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    6.383133] TCP bind hash table entries: 65536 (order: 10, 5242880 bytes, vmalloc)
[    6.385373] TCP: Hash tables configured (established 131072 bind 65536)
[    6.394770] MPTCP token hash table entries: 16384 (order: 8, 1572864 bytes, linear)
[    6.395586] UDP hash table entries: 8192 (order: 8, 1572864 bytes, linear)
[    6.396531] UDP-Lite hash table entries: 8192 (order: 8, 1572864 bytes, linear)
[    6.405284] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    6.405821] Trying to unpack rootfs image as initramfs...
[    6.407794] alg: No test for crc32be (crc32be-vx)
[    6.436676] Initialise system trusted keyrings
[    6.436980] workingset: timestamp_bits=45 max_order=22 bucket_order=0
[    6.500365] zbud: loaded
[    6.516137] fuse: init (API version 7.34)
[    6.517210] SGI XFS with ACLs, security attributes, realtime, quota, fatal assert, debug enabled
[    6.544339] xor: automatically using best checksumming function   xc········
[    6.544363] Key type asymmetric registered
[    6.544389] Asymmetric key parser 'x509' registered
[    6.544448] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    6.545893] io scheduler mq-deadline registered
[    6.545927] io scheduler kyber registered
[    6.545933] blkcg_policy_register: BLKCG_MAX_POLS too small
[    6.599433] rootfs image is not initramfs (broken padding); looks like an initrd
[    6.669373] Freeing initrd memory: 24828K

It is very hard to reproduce, i haven't managed to do it yet and working
on it, but it occurs regularly, nearly every day once but only on a particular
test machine with our nightly s390 CI test runs.

Although the initramfs corruption is hard to reproduce,
the message 'wait_for_initramfs() called before rootfs_initcalls'
appears regularly on each boot at least since 2021-06-24 which we just
noticed a couple of days ago.

Appending 'initramfs_async=0' to the kernel command-line doesn't seem to
help with the 'wait_for_initramfs' message and i can still see it.

[    0.890962] wait_for_initramfs() called before rootfs_initcalls
[    1.060846] raid6: vx128x8  gen() 22394 MB/s
[    1.230783] raid6: vx128x8  xor() 14998 MB/s
[    1.230795] raid6: using algorithm vx128x8 gen() 22394 MB/s
[    1.230797] raid6: .... xor() 14998 MB/s, rmw enabled
[    1.230799] raid6: using s390xc recovery algorithm
[    1.231122] iommu: Default domain type: Translated
[    1.231331] SCSI subsystem initialized
[    1.231804] cio: Partition identifier 3.4
[    1.355331] PCI host bridge to bus 0000:00
[    1.355340] pci_bus 0000:00: root bus resource [bus 00]
[    1.355363] PCI host bridge to bus 0001:00
[    1.355364] pci_bus 0001:00: root bus resource [bus 00]
[    1.355490] pci 0000:00:00.0: [8086:0a54] type 00 class 0x010802
[    1.355541] pci 0000:00:00.0: reg 0x10: [mem 0xffffc00000000000-0xffffc00000003fff 64bit]
[    1.355611] pci 0000:00:00.0: reg 0x30: [mem 0x00000000-0x0000ffff pref]
[    1.355625] pci 0000:00:00.0: enabling Extended Tags
[    1.355921] pci 0000:00:00.0: Adding to iommu group 0
[    1.632566] VFS: Disk quotas dquot_6.6.0
[    1.632624] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    1.634327] NET: Registered PF_INET protocol family
[    1.634395] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    1.635112] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)
[    1.635129] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)
[    1.635296] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)
[    1.635498] TCP: Hash tables configured (established 32768 bind 32768)
[    1.635834] MPTCP token hash table entries: 4096 (order: 4, 98304 bytes, linear)
[    1.635852] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    1.635882] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    1.636249] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    1.636419] Trying to unpack rootfs image as initramfs...
[    1.676907] Freeing initrd memory: 26056K

Regards
Alex