http://bugzilla.opensuse.org/show_bug.cgi?id=1173313 Bug ID: 1173313 Summary: [aarch64] jeos qcow2 image: Root device not found during virt-install boot Classification: openSUSE Product: openSUSE Distribution Version: Leap 15.2 Hardware: aarch64 OS: Other Status: NEW Severity: Major Priority: P5 - None Component: Cloud:Images Assignee: public-cloud-maintainers@suse.de Reporter: rrichter@marvell.com QA Contact: qa-bugs@suse.de Found By: --- Blocker: --- 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/appliance... 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. -- You are receiving this mail because: You are on the CC list for the bug.