User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101
Firefox/68.0
Build Identifier:
Booting today's openSUSE Leap 15.2 qcow2 image with virt-inst fails:
# virsh net-start default
# virt-install --transient --name opensuse --import --memory 16384 --disk
/srv/vm/opensuse/openSUSE-Leap-15.2-ARM-JeOS-efi.aarch64-2020.06.16-Build1.8.qcow2
...
Loading Linux 5.3.18-lp152.18-default ...
...
Welcome to openSUSE Leap 15.2 dracut-049.1+suse.144.ge0eaf296-lp152.1.1
(Initramfs)!
...
[ OK ] Reached target Basic System.
[ *] A start job is running for dev-disk���75ec6bc9c9.device (46s / no
limit)
This runs forever.
Image from:
https://download.opensuse.org/ports/aarch64/distribution/leap/15.2/appliances/
Using a customized kernel and initrd made the image boot:
+ virt-install --transient --name 5.7.0-virt-01309-g9046fbbe2919 --boot
'uefi,kernel=/boot/Image-5.7.0-virt-01309-g9046fbbe2919,initrd=/boot/initrd-5.7.0-virt-01309-g9046fbbe2919,kernel_args=root=/dev/sda3
ro console=ttyS0,115200n8 no_timer_check net.ifnames=0 crashkernel=auto
rd.shell rd.debug log_buf_len=1M' --memory 16384 --disk
/srv/vm/opensuse/openSUSE-Leap-15.2-ARM-JeOS-efi.aarch64-2020.06.16-Build1.8.qcow2
After applying dracut in the guest the original image could be booted too (with
the above command line):
# dracut -f /boot/initrd-5.3.18-lp152.18-default 5.3.18-lp152.18-default
Though, during boot there is a long timeout of about 15 mins (which are not
seen with the custom kernel, time varies):
[ 915.761207] cloud-init[533]: Cloud-init v. 19.4 running 'init-local' at
Wed, 24 Jun 2020 13:12:32 +0000. Up 900.51 seconds.
Reproducible: Always
Steps to Reproduce:
See above.
Actual Results:
Root device is not found, no root fs.
Systemd start job hangs forever:
[ *] A start job is running for dev-disk���75ec6bc9c9.device (46s / no limit)
Expected Results:
System is booted to the prompt:
Welcome to openSUSE Leap 15.2 - Kernel 5.3.18-lp152.18-default (ttyAMA0).
sbr2s-27 login:
Details on the host (Marvell CN99xx):
sbr2s-27:~ # cat /etc/os-release
NAME="SLES"
VERSION="15-SP1"
VERSION_ID="15.1"
PRETTY_NAME="SUSE Linux Enterprise Server 15 SP1"
ID="sles"
ID_LIKE="suse"
ANSI_COLOR="0;32"
CPE_NAME="cpe:/o:suse:sles:15:sp1"
sbr2s-27:~ # uname -a
Linux sbr2s-27 5.3.18-50.g39d1ea9-default #1 SMP Sun Apr 5 19:41:26 UTC 2020
(39d1ea9) aarch64 aarch64 aarch64 GNU/Linux
sbr2s-27:~ # dmidecode -t 0
# dmidecode 3.2
Getting SMBIOS data from sysfs.
SMBIOS 3.1.1 present.
Handle 0x0000, DMI type 0, 26 bytes
BIOS Information
Vendor: EDK II
Version: 0ACKL029
Release Date: 02/21/2020
Address: 0xF0000
Runtime Size: 64 kB
ROM Size: 64 MB
Characteristics:
PCI is supported
BIOS is upgradeable
BIOS shadowing is allowed
Boot from CD is supported
Selectable boot is supported
BIOS ROM is socketed
ACPI is supported
BIOS boot specification is supported
Targeted content distribution is supported
UEFI is supported
BIOS Revision: 7.4
sbr2s-27:~ # dmidecode -t 1
# dmidecode 3.2
Getting SMBIOS data from sysfs.
SMBIOS 3.1.1 present.
Handle 0x0001, DMI type 1, 27 bytes
System Information
Manufacturer: To be filled by O.E.M.
Product Name: Saber
Version: 1.0
Serial Number: To be filled by O.E.M.
UUID: 6b7bd980-bfde-1000-03f5-e0d55e60f6d4
Wake-up Type: Power Switch
SKU Number: SABER SKU
Family: CN99XX
Systemd log showing boot timing:
Jun 24 12:57:39 sbr2s-27 systemd[1]: Started Apply settings from
/etc/sysconfig/keyboard.
Jun 24 13:07:32 sbr2s-27 systemd[1]: Started Daily Cleanup of Snapper
Snapshots.
Jun 24 13:07:32 sbr2s-27 dbus-daemon[527]: [system] Activating service
name='org.opensuse.Snapper' requested by ':1.2' (uid=0 pid=589
comm="/usr/lib/snapper/systemd-helper --cleanup ") (using servicehelper)
Jun 24 13:07:32 sbr2s-27 dbus-daemon[527]: [system] Successfully activated
service 'org.opensuse.Snapper'
Jun 24 13:07:32 sbr2s-27 systemd-helper[589]: running number cleanup for
'root'.
Jun 24 13:07:32 sbr2s-27 systemd-helper[589]: running timeline cleanup for
'root'.
Jun 24 13:07:32 sbr2s-27 systemd-helper[589]: running empty-pre-post cleanup
for 'root'.
Jun 24 13:12:32 sbr2s-27 kernel: random: crng init done
Jun 24 13:12:32 sbr2s-27 kernel: random: 7 urandom warning(s) missed due to
ratelimiting
Jun 24 13:12:32 sbr2s-27 dhclient[600]: Internet Systems Consortium DHCP Client
4.3.6-P1
Jun 24 13:12:32 sbr2s-27 dhclient[600]: Copyright 2004-2018 Internet Systems
Consortium.
Jun 24 13:12:32 sbr2s-27 dhclient[600]: All rights reserved.
Jun 24 13:12:32 sbr2s-27 dhclient[600]: For info, please visit
https://www.isc.org/software/dhcp/
Jun 24 13:12:32 sbr2s-27 dhclient[600]:
Jun 24 13:12:32 sbr2s-27 dhclient[600]: Listening on LPF/eth0/52:54:00:d7:71:f6
Jun 24 13:12:32 sbr2s-27 dhclient[600]: Sending on LPF/eth0/52:54:00:d7:71:f6
Jun 24 13:12:32 sbr2s-27 dhclient[600]: Sending on Socket/fallback
Jun 24 13:12:32 sbr2s-27 dhclient[600]: DHCPDISCOVER on eth0 to 255.255.255.255
port 67 interval 3 (xid=0x371dbcf6)
Jun 24 13:12:32 sbr2s-27 dhclient[600]: DHCPOFFER from 192.168.122.1
Jun 24 13:12:32 sbr2s-27 kernel: NET: Registered protocol family 17
Jun 24 13:12:37 sbr2s-27 dhclient[600]: DHCPREQUEST on eth0 to 255.255.255.255
port 67 (xid=0x371dbcf6)
Jun 24 13:12:37 sbr2s-27 dhclient[600]: DHCPACK from 192.168.122.1
(xid=0x371dbcf6)
Jun 24 13:12:37 sbr2s-27 dhclient[600]: bound to 192.168.122.196 -- renewal in
1631 seconds.
Jun 24 13:12:47 sbr2s-27 cloud-init[533]: Cloud-init v. 19.4 running
'init-local' at Wed, 24 Jun 2020 13:12:32 +0000. Up 900.51 seconds.
Jun 24 13:12:47 sbr2s-27 cloud-init[533]: 2020-06-24 13:12:47,783 -
util.py[WARNING]: No active metadata service found
Jun 24 13:12:47 sbr2s-27 systemd[1]: Started Initial cloud-init job
(pre-networking).
Jun 24 13:12:47 sbr2s-27 systemd[1]: Reached target Network (Pre).
Jun 24 13:12:47 sbr2s-27 systemd[1]: Starting wicked AutoIPv4 supplicant
service...
Jun 24 13:12:47 sbr2s-27 systemd[1]: Starting wicked DHCPv4 supplicant
service...
Jun 24 13:12:47 sbr2s-27 systemd[1]: Starting wicked DHCPv6 supplicant
service...
Jun 24 13:12:48 sbr2s-27 systemd[1]: Started wicked DHCPv6 supplicant service.
Jun 24 13:12:48 sbr2s-27 systemd[1]: Started wicked AutoIPv4 supplicant
service.
Jun 24 13:12:48 sbr2s-27 systemd[1]: Started wicked DHCPv4 supplicant service.
Jun 24 13:12:48 sbr2s-27 systemd[1]: Starting wicked network management service
daemon...
Jun 24 13:12:48 sbr2s-27 systemd[1]: Started wicked network management service
daemon.
Jun 24 13:12:48 sbr2s-27 systemd[1]: Starting wicked network nanny service...
Jun 24 13:12:48 sbr2s-27 systemd[1]: Started wicked network nanny service.
Jun 24 13:12:48 sbr2s-27 systemd[1]: Starting wicked managed network
interfaces...
Jun 24 13:12:48 sbr2s-27 wickedd-dhcp4[622]: eth0: Request to acquire DHCPv4
lease with UUID 5051f35e-40a5-0300-7002-000004000000
Jun 24 13:12:48 sbr2s-27 wickedd-dhcp4[622]: eth0: Committed DHCPv4 lease with
address 192.168.122.34 (lease time 3600 sec, renew in 1800 sec, rebind in 3150
sec)
Jun 24 13:12:53 sbr2s-27 wicked[628]: lo up
Jun 24 13:12:53 sbr2s-27 wicked[628]: eth0 up
Jun 24 13:12:53 sbr2s-27 systemd[1]: Started wicked managed network interfaces.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Starting Initial cloud-init job (metadata
service crawler)...
Jun 24 13:12:53 sbr2s-27 systemd[1]: Reached target Network.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Starting NTP client/server...
Jun 24 13:12:53 sbr2s-27 chronyd[1045]: chronyd version 3.2 starting (+CMDMON
+NTP +REFCLOCK +RTC +PRIVDROP -SCFILTER +SECHASH -SIGND +ASYNCDNS +IPV6 -DEBUG)
Jun 24 13:12:53 sbr2s-27 chronyd[1045]: Frequency -104.991 +/- 2.220 ppm read
from /var/lib/chrony/drift
Jun 24 13:12:53 sbr2s-27 systemd[1]: Started NTP client/server.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Reached target System Time Synchronized.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Started Discard unused blocks once a week.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Started Backup of /etc/sysconfig.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Started Check if mainboard battery is Ok.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Started Backup of RPM database.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Starting Cleanup of Temporary
Directories...
Jun 24 13:12:53 sbr2s-27 systemd[1]: Started Daily rotation of log files.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Started Timeline of Snapper Snapshots.
Jun 24 13:12:53 sbr2s-27 systemd[1]: Reached target Timers.
Jun 24 13:12:53 sbr2s-27 systemd-tmpfiles[1071]:
[/usr/lib/tmpfiles.d/tmp.conf:13] Duplicate line for path "/var/tmp", ignoring.
Jun 24 13:12:53 sbr2s-27 systemd-tmpfiles[1071]:
[/usr/lib/tmpfiles.d/var.conf:21] Duplicate line for path "/var/lib", ignoring.
Jun 24 13:12:53 sbr2s-27 systemd-tmpfiles[1071]:
[/usr/lib/tmpfiles.d/var.conf:23] Duplicate line for path "/var/spool",
ignoring.
Jun 24 13:12:54 sbr2s-27 systemd[1]: Started Cleanup of Temporary Directories.
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: Cloud-init v. 19.4 running 'init' at
Wed, 24 Jun 2020 13:12:54 +0000. Up 922.48 seconds.
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
++++++++++++++++++++++++++++++++++++++Net device
info++++++++++++++++++++++++++++++++++++++
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+--------+------+----------------------------+---------------+--------+-------------------+
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | Device | Up |
Address | Mask | Scope | Hw-Address |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+--------+------+----------------------------+---------------+--------+-------------------+
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | eth0 | True |
192.168.122.34 | 255.255.255.0 | global | 52:54:00:d7:71:f6 |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | eth0 | True |
fe80::5054:ff:fed7:71f6/64 | . | link | 52:54:00:d7:71:f6 |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | lo | True |
127.0.0.1 | 255.0.0.0 | host | . |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | lo | True |
::1/128 | . | host | . |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+--------+------+----------------------------+---------------+--------+-------------------+
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+++++++++++++++++++++++++++++++Route IPv4 info+++++++++++++++++++++++++++++++
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+-------+---------------+---------------+---------------+-----------+-------+
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | Route | Destination |
Gateway | Genmask | Interface | Flags |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+-------+---------------+---------------+---------------+-----------+-------+
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | 0 | 0.0.0.0 |
192.168.122.1 | 0.0.0.0 | eth0 | UG |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | 1 | 192.168.122.0 |
0.0.0.0 | 255.255.255.0 | eth0 | U |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+-------+---------------+---------------+---------------+-----------+-------+
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: +++++++++++++++++++Route
IPv6 info+++++++++++++++++++
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+-------+-------------+---------+-----------+-------+
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | Route | Destination |
Gateway | Interface | Flags |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+-------+-------------+---------+-----------+-------+
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | 1 | fe80::/64 |
:: | eth0 | U |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | 3 | local |
:: | eth0 | U |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info: | 4 | ff00::/8 |
:: | eth0 | U |
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: ci-info:
+-------+-------------+---------+-----------+-------+
Jun 24 13:13:04 sbr2s-27 cloud-init[1042]: 2020-06-24 13:13:04,683 -
util.py[WARNING]: No active metadata service found
Jun 24 13:13:05 sbr2s-27 kernel: BTRFS info (device sda3): new size for
/dev/sda3 is 1289728000
Jun 24 13:13:05 sbr2s-27 systemd[1]: Started Initial cloud-init job (metadata
service crawler).
Jun 24 13:13:05 sbr2s-27 systemd[1]: Starting Permit User Sessions...
Jun 24 13:13:05 sbr2s-27 systemd[1]: Reached target Network is Online.
Jun 24 13:13:05 sbr2s-27 systemd[1]: Starting OpenSSH Daemon...
Jun 24 13:13:05 sbr2s-27 systemd[1]: Reached target Cloud-config availability.
Jun 24 13:13:05 sbr2s-27 sshd-gen-keys-start[1118]: Checking for missing server
keys in /etc/ssh
Jun 24 13:13:05 sbr2s-27 systemd[1]: Starting Apply the settings specified in
cloud-config...
Jun 24 13:13:05 sbr2s-27 systemd[1]: Started Permit User Sessions.
Jun 24 13:13:05 sbr2s-27 sshd[1122]: Server listening on 0.0.0.0 port 22.
Jun 24 13:13:05 sbr2s-27 sshd[1122]: Server listening on :: port 22.
Jun 24 13:13:05 sbr2s-27 systemd[1]: Started OpenSSH Daemon.
Jun 24 13:13:05 sbr2s-27 systemd[1]: Started Getty on tty1.
Jun 24 13:13:05 sbr2s-27 systemd[1]: Started Serial Getty on ttyAMA0.
Jun 24 13:13:05 sbr2s-27 systemd[1]: Reached target Login Prompts.
Jun 24 13:13:05 sbr2s-27 systemd[1]: Reached target Multi-User System.
Jun 24 13:13:05 sbr2s-27 systemd[1]: Reached target Graphical Interface.
Jun 24 13:13:05 sbr2s-27 systemd[1]: Starting Update UTMP about System Runlevel
Changes...
Jun 24 13:13:05 sbr2s-27 systemd[1]: Started Update UTMP about System Runlevel
Changes.
Jun 24 13:13:06 sbr2s-27 cloud-init[1120]: Cloud-init v. 19.4 running
'modules:config' at Wed, 24 Jun 2020 13:13:06 +0000. Up 933.97 seconds.
Jun 24 13:13:06 sbr2s-27 systemd[1]: Started Apply the settings specified in
cloud-config.
Jun 24 13:13:06 sbr2s-27 systemd[1]: Starting Execute cloud user/final
scripts...
Jun 24 13:13:06 sbr2s-27 cloud-init[1133]: Cloud-init v. 19.4 running
'modules:final' at Wed, 24 Jun 2020 13:13:06 +0000. Up 934.77 seconds.
Jun 24 13:13:06 sbr2s-27 cloud-init[1133]: Cloud-init v. 19.4 finished at Wed,
24 Jun 2020 13:13:06 +0000. Datasource DataSourceNone. Up 934.87 seconds
Jun 24 13:13:06 sbr2s-27 cloud-init[1133]: 2020-06-24 13:13:06,909 -
cc_final_message.py[WARNING]: Used fallback datasource
Jun 24 13:13:06 sbr2s-27 systemd[1]: Started Execute cloud user/final scripts.
Jun 24 13:13:06 sbr2s-27 systemd[1]: Reached target Cloud-init target.
Jun 24 13:13:06 sbr2s-27 systemd[1]: Startup finished in 1.505s (kernel) +
4.647s (initrd) + 15min 28.807s (userspace) = 15min 34.961s.
Jun 24 13:13:41 sbr2s-27 sshd[1142]: Accepted keyboard-interactive/pam for root
from 192.168.122.1 port 42104 ssh2
Jun 24 13:13:41 sbr2s-27 systemd-logind[531]: New session 1 of user root.
Jun 24 13:13:41 sbr2s-27 systemd[1]: Created slice User Slice of UID 0.
Jun 24 13:13:41 sbr2s-27 systemd[1]: Starting User Manager for UID 0...
Jun 24 13:13:41 sbr2s-27 systemd[1]: Started Session 1 of user root.
Jun 24 13:13:41 sbr2s-27 systemd[1145]: pam_unix(systemd-user:session): session
opened for user root by (uid=0)
Jun 24 13:13:41 sbr2s-27 systemd[1145]: Reached target Paths.
Jun 24 13:13:41 sbr2s-27 systemd[1145]: Reached target Timers.
Jun 24 13:13:41 sbr2s-27 systemd[1145]: Starting D-Bus User Message Bus Socket.
Jun 24 13:13:41 sbr2s-27 systemd[1145]: Listening on D-Bus User Message Bus
Socket.
Jun 24 13:13:41 sbr2s-27 systemd[1145]: Reached target Sockets.
Jun 24 13:13:41 sbr2s-27 systemd[1145]: Reached target Basic System.
Jun 24 13:13:41 sbr2s-27 systemd[1]: Started User Manager for UID 0.
Jun 24 13:13:41 sbr2s-27 sshd[1142]: pam_unix(sshd:session): session opened for
user root by (uid=0)
Jun 24 13:13:41 sbr2s-27 systemd[1145]: Reached target Default.
Jun 24 13:13:41 sbr2s-27 systemd[1145]: Startup finished in 52ms.
Additional issue seen:
[FAILED] Failed to start Load Kernel Modules.
See 'systemctl status systemd-modules-load.service' for details.
This is due to multipath-tools package:
sbr2s-27:~ # systemctl status systemd-modules-load
��� systemd-modules-load.service - Load Kernel Modules
Loaded: loaded (/usr/lib/systemd/system/systemd-modules-load.service;
static; vendor preset: disabled)
Active: failed (Result: exit-code) since Wed 2020-06-24 12:57:39 UTC; 24min
ago
Docs: man:systemd-modules-load.service(8)
man:modules-load.d(5)
Process: 480 ExecStart=/usr/lib/systemd/systemd-modules-load (code=exited,
status=1/FAILURE)
Main PID: 480 (code=exited, status=1/FAILURE)
Jun 24 12:57:39 sbr2s-27 systemd[1]: Starting Load Kernel Modules...
Jun 24 12:57:39 sbr2s-27 systemd-modules-load[480]: Failed to find module
'scsi_dh_alua'
Jun 24 12:57:39 sbr2s-27 systemd-modules-load[480]: Failed to find module
'scsi_dh_emc'
Jun 24 12:57:39 sbr2s-27 systemd-modules-load[480]: Failed to find module
'scsi_dh_rdac'
Jun 24 12:57:39 sbr2s-27 systemd-modules-load[480]: Failed to find module
'dm-multipath'
Jun 24 12:57:39 sbr2s-27 systemd[1]: systemd-modules-load.service: Main process
exited, code=exited, status=1/FAILURE
Jun 24 12:57:39 sbr2s-27 systemd[1]: Failed to start Load Kernel Modules.
Jun 24 12:57:39 sbr2s-27 systemd[1]: systemd-modules-load.service: Unit entered
failed state.
Jun 24 12:57:39 sbr2s-27 systemd[1]: systemd-modules-load.service: Failed with
result 'exit-code'.
sbr2s-27:~ # cat /usr/lib/modules-load.d/multipath.conf
# Load device-handler and multipath module at boot
scsi_dh_alua
scsi_dh_emc
scsi_dh_rdac
dm-multipath
sbr2s-27:~ # rpm -qf /usr/lib/modules-load.d/multipath.conf
multipath-tools-0.8.2+18.9ff73e7-lp152.2.1.aarch64
sbr2s-27:~ # find /lib/modules/ -name '*dm-multipath*'
It does not have impact to the boot issue.