QEMU

ppc64le: KVM guest fails to boot with an error `virtio_scsi: probe of virtio1 failed with error -22` on master

Bug #1847440 reported by Satheesh Rajendran on 2019-10-09

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	QEMU	Fix Released	Undecided	Unassigned

Bug Description

PowerPC KVM Guest fails to boot on current qemu master, bad commit: e68cd0cb5cf49d334abe17231a1d2c28b846afa2

Env:
HW: IBM Power9
Host Kernel: 5.4.0-rc2-00038-ge3280b54afed
Guest Kernel: 4.13.9-300.fc27.ppc64le
Qemu: https://github.com/qemu/qemu.git (master)
Libvirt: 5.4.0

Guest boot gets stuck:
...
[ OK ] Mounted Kernel Configuration File System.
[ 7.598740] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)
[ 7.598828] virtio-pci 0000:00:01.0: virtio_pci: leaving for legacy driver
[ 7.598957] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)
[ 7.599017] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
[ 7.599123] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)
[ 7.599182] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
[ 7.620620] synth uevent: /devices/vio: failed to send uevent
[ 7.620624] vio vio: uevent: failed to send synthetic uevent
[ OK ] Started udev Coldplug all Devices.
[ 7.624559] audit: type=1130 audit(1570610300.990:5): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-udev-trigger comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ OK ] Reached target System Initialization.
[ OK ] Reached target Basic System.
[ OK ] Reached target Remote File Systems (Pre).
[ OK ] Reached target Remote File Systems.
[ 7.642961] virtio_scsi: probe of virtio1 failed with error -22
[ *** ] A start job is running for dev-disk…21b3519a80.device (14s / no limit)
...

git bisect, yielded a bad commit [e68cd0cb5cf49d334abe17231a1d2c28b846afa2] spapr: Render full FDT on ibm,client-architecture-support, reverting this commit boot the guest properly.

git bisect start
# good: [9e06029aea3b2eca1d5261352e695edc1e7d7b8b] Update version for v4.1.0 release
git bisect good 9e06029aea3b2eca1d5261352e695edc1e7d7b8b
# bad: [98b2e3c9ab3abfe476a2b02f8f51813edb90e72d] Merge remote-tracking branch 'remotes/stefanha/tags/block-pull-request' into staging
git bisect bad 98b2e3c9ab3abfe476a2b02f8f51813edb90e72d
# good: [56e6250ede81b4e4b4ddb623874d6c3cdad4a96d] target/arm: Convert T16, nop hints
git bisect good 56e6250ede81b4e4b4ddb623874d6c3cdad4a96d
# good: [5d69cbdfdd5cd6dadc9f0c986899844a0e4de703] tests/tcg: target/s390x: Test MVC
git bisect good 5d69cbdfdd5cd6dadc9f0c986899844a0e4de703
# good: [88112488cf228df8b7588c8aa38e16ecd0dff48e] qapi: Make check_type()'s array case a bit more obvious
git bisect good 88112488cf228df8b7588c8aa38e16ecd0dff48e
# good: [972bd57689f1e11311d86b290134ea2ed9c7c11e] ppc/kvm: Skip writing DPDES back when in run time state
git bisect good 972bd57689f1e11311d86b290134ea2ed9c7c11e
# bad: [1aba8716c8335e88b8c358002a6e1ac89f7dd258] ppc/pnv: Remove the XICSFabric Interface from the POWER9 machine
git bisect bad 1aba8716c8335e88b8c358002a6e1ac89f7dd258
# bad: [00ed3da9b5c2e66e796a172df3e19545462b9c90] xics: Minor fixes for XICSFabric interface
git bisect bad 00ed3da9b5c2e66e796a172df3e19545462b9c90
# good: [33432d7737b53c92791f90ece5dbe3b7bb1c79f5] target/ppc: introduce set_dfp{64,128}() helper functions
git bisect good 33432d7737b53c92791f90ece5dbe3b7bb1c79f5
# good: [f6d4c423a222f02bfa84a49c3d306d7341ec9bab] target/ppc: remove unnecessary if() around calls to set_dfp{64,128}() in DFP macros
git bisect good f6d4c423a222f02bfa84a49c3d306d7341ec9bab
# bad: [e68cd0cb5cf49d334abe17231a1d2c28b846afa2] spapr: Render full FDT on ibm,client-architecture-support
git bisect bad e68cd0cb5cf49d334abe17231a1d2c28b846afa2
# good: [c4ec08ab70bab90685d1443d6da47293e3aa312a] spapr-pci: Stop providing assigned-addresses
git bisect good c4ec08ab70bab90685d1443d6da47293e3aa312a
# first bad commit: [e68cd0cb5cf49d334abe17231a1d2c28b846afa2] spapr: Render full FDT on ibm,client-architecture-support

attached vmxml.

qemu commandline:
/home/sath/qemu/ppc64-softmmu/qemu-system-ppc64 -name guest=vm1,debug-threads=on -S -object secret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain-19-vm1/master-key.aes -machine pseries-4.2,accel=kvm,usb=off,dump-guest-core=off -m 81920 -overcommit mem-lock=off -smp 512,sockets=1,cores=128,threads=4 -uuid fd4a5d54-0216-490e-82d2-1d4e89683b3d -display none -no-user-config -nodefaults -chardev socket,id=charmonitor,fd=24,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-shutdown -boot strict=on -device qemu-xhci,id=usb,bus=pci.0,addr=0x3 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x2 -drive file=/home/sath/tests/data/avocado-vt/images/jeos-27-ppc64le_vm1.qcow2,format=qcow2,if=none,id=drive-scsi0-0-0-0 -device scsi-hd,bus=scsi0.0,channel=0,scsi-id=0,lun=0,device_id=drive-scsi0-0-0-0,drive=drive-scsi0-0-0-0,id=scsi0-0-0-0,bootindex=1 -netdev tap,fd=26,id=hostnet0,vhost=on,vhostfd=27 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:e6:df:24,bus=pci.0,addr=0x1 -chardev pty,id=charserial0 -device spapr-vty,chardev=charserial0,id=serial0,reg=0x30000000 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x4 -M pseries,ic-mode=xics -msg timestamp=on

See original description

Tags:

Revision history for this message

Satheesh Rajendran (sathnaga) wrote on 2019-10-09:

KVM Guest XML Edit (2.8 KiB, application/xml)

summary:	ppc64le: KVM guest fails to boot with an error `virtio_scsi: probe of - virtio1 failed with error -22` on - master(98b2e3c9ab3abfe476a2b02f8f51813edb90e72d) + virtio1 failed with error -22` on master
description:	updated

Satheesh Rajendran (sathnaga) on 2019-10-10

description:

updated

Revision history for this message

David Gibson (dwg) wrote on 2019-10-11: Re: [Bug 1847440] [NEW] ppc64le: KVM guest fails to boot with an error `virtio_scsi: probe of virtio1 failed with error -22` on master

Download full text (5.6 KiB)

On Thu, Oct 10, 2019 at 07:16:49AM -0000, Launchpad Bug Tracker wrote:
> You have been subscribed to a public bug by Satheesh Rajendran (sathnaga):
>
> PowerPC KVM Guest fails to boot on current qemu master, bad commit:
> e68cd0cb5cf49d334abe17231a1d2c28b846afa2
>
> Env:
> HW: IBM Power9
> Host Kernel: 5.4.0-rc2-00038-ge3280b54afed
> Guest Kernel: 4.13.9-300.fc27.ppc64le
> Qemu: https://github.com/qemu/qemu.git (master)
> Libvirt: 5.4.0
>
> Guest boot gets stuck:
> ...
> [ OK ] Mounted Kernel Configuration File System.
> [ 7.598740] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)
> [ 7.598828] virtio-pci 0000:00:01.0: virtio_pci: leaving for legacy driver
> [ 7.598957] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)
> [ 7.599017] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
> [ 7.599123] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)
> [ 7.599182] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
> [ 7.620620] synth uevent: /devices/vio: failed to send uevent
> [ 7.620624] vio vio: uevent: failed to send synthetic uevent
> [ OK ] Started udev Coldplug all Devices.
> [ 7.624559] audit: type=1130 audit(1570610300.990:5): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-udev-trigger comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
> [ OK ] Reached target System Initialization.
> [ OK ] Reached target Basic System.
> [ OK ] Reached target Remote File Systems (Pre).
> [ OK ] Reached target Remote File Systems.
> [ 7.642961] virtio_scsi: probe of virtio1 failed with error -22
> [ *** ] A start job is running for dev-disk…21b3519a80.device (14s / no limit)
> ...
>
> git bisect, yielded a bad commit
> [e68cd0cb5cf49d334abe17231a1d2c28b846afa2] spapr: Render full FDT on ibm
> ,client-architecture-support, reverting this commit boot the guest
> properly.
>
> git bisect start
> # good: [9e06029aea3b2eca1d5261352e695edc1e7d7b8b] Update version for v4.1.0 release
> git bisect good 9e06029aea3b2eca1d5261352e695edc1e7d7b8b
> # bad: [98b2e3c9ab3abfe476a2b02f8f51813edb90e72d] Merge remote-tracking branch 'remotes/stefanha/tags/block-pull-request' into staging
> git bisect bad 98b2e3c9ab3abfe476a2b02f8f51813edb90e72d
> # good: [56e6250ede81b4e4b4ddb623874d6c3cdad4a96d] target/arm: Convert T16, nop hints
> git bisect good 56e6250ede81b4e4b4ddb623874d6c3cdad4a96d
> # good: [5d69cbdfdd5cd6dadc9f0c986899844a0e4de703] tests/tcg: target/s390x: Test MVC
> git bisect good 5d69cbdfdd5cd6dadc9f0c986899844a0e4de703
> # good: [88112488cf228df8b7588c8aa38e16ecd0dff48e] qapi: Make check_type()'s array case a bit more obvious
> git bisect good 88112488cf228df8b7588c8aa38e16ecd0dff48e
> # good: [972bd57689f1e11311d86b290134ea2ed9c7c11e] ppc/kvm: Skip writing DPDES back when in run time state
> git bisect good 972bd57689f1e11311d86b290134ea2ed9c7c11e
> # bad: [1aba8716c8335e88b8c358002a6e1ac89f7dd258] ppc/pnv: Remove the XICSFabric Interface from the POWER9 machine
> git bisect bad 1aba8716c8335e88b8c358002a6e1ac89f7dd258
> # bad: [00ed3da9b5c2e66e796a172df3e19545462b9c90] xics: Minor fixes for XICSFabric interfa...

On Thu, Oct 10, 2019 at 07:16:49AM -0000, Launchpad Bug Tracker wrote:
> You have been subscribed to a public bug by Satheesh Rajendran (sathnaga):
> 
> PowerPC KVM Guest fails to boot on current qemu master, bad commit:
> e68cd0cb5cf49d334abe17231a1d2c28b846afa2
> 
> Env:
> HW: IBM Power9
> Host Kernel: 5.4.0-rc2-00038-ge3280b54afed
> Guest Kernel: 4.13.9-300.fc27.ppc64le
> Qemu: https://github.com/qemu/qemu.git (master)
> Libvirt: 5.4.0
> 
> Guest boot gets stuck:
> ...
> [  OK  ] Mounted Kernel Configuration File System.
> [    7.598740] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)
> [    7.598828] virtio-pci 0000:00:01.0: virtio_pci: leaving for legacy driver
> [    7.598957] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)
> [    7.599017] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
> [    7.599123] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)
> [    7.599182] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
> [    7.620620] synth uevent: /devices/vio: failed to send uevent
> [    7.620624] vio vio: uevent: failed to send synthetic uevent
> [  OK  ] Started udev Coldplug all Devices.
> [    7.624559] audit: type=1130 audit(1570610300.990:5): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-udev-trigger comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
> [  OK  ] Reached target System Initialization.
> [  OK  ] Reached target Basic System.
> [  OK  ] Reached target Remote File Systems (Pre).
> [  OK  ] Reached target Remote File Systems.
> [    7.642961] virtio_scsi: probe of virtio1 failed with error -22
> [ ***  ] A start job is running for dev-disk…21b3519a80.device (14s / no limit)
> ...
> 
> git bisect, yielded a bad commit
> [e68cd0cb5cf49d334abe17231a1d2c28b846afa2] spapr: Render full FDT on ibm
> ,client-architecture-support, reverting this commit boot the guest
> properly.
> 
> git bisect start
> # good: [9e06029aea3b2eca1d5261352e695edc1e7d7b8b] Update version for v4.1.0 release
> git bisect good 9e06029aea3b2eca1d5261352e695edc1e7d7b8b
> # bad: [98b2e3c9ab3abfe476a2b02f8f51813edb90e72d] Merge remote-tracking branch 'remotes/stefanha/tags/block-pull-request' into staging
> git bisect bad 98b2e3c9ab3abfe476a2b02f8f51813edb90e72d
> # good: [56e6250ede81b4e4b4ddb623874d6c3cdad4a96d] target/arm: Convert T16, nop hints
> git bisect good 56e6250ede81b4e4b4ddb623874d6c3cdad4a96d
> # good: [5d69cbdfdd5cd6dadc9f0c986899844a0e4de703] tests/tcg: target/s390x: Test MVC
> git bisect good 5d69cbdfdd5cd6dadc9f0c986899844a0e4de703
> # good: [88112488cf228df8b7588c8aa38e16ecd0dff48e] qapi: Make check_type()'s array case a bit more obvious
> git bisect good 88112488cf228df8b7588c8aa38e16ecd0dff48e
> # good: [972bd57689f1e11311d86b290134ea2ed9c7c11e] ppc/kvm: Skip writing DPDES back when in run time state
> git bisect good 972bd57689f1e11311d86b290134ea2ed9c7c11e
> # bad: [1aba8716c8335e88b8c358002a6e1ac89f7dd258] ppc/pnv: Remove the XICSFabric Interface from the POWER9 machine
> git bisect bad 1aba8716c8335e88b8c358002a6e1ac89f7dd258
> # bad: [00ed3da9b5c2e66e796a172df3e19545462b9c90] xics: Minor fixes for XICSFabric interface
> git bisect bad 00ed3da9b5c2e66e796a172df3e19545462b9c90
> # good: [33432d7737b53c92791f90ece5dbe3b7bb1c79f5] target/ppc: introduce set_dfp{64,128}() helper functions
> git bisect good 33432d7737b53c92791f90ece5dbe3b7bb1c79f5
> # good: [f6d4c423a222f02bfa84a49c3d306d7341ec9bab] target/ppc: remove unnecessary if() around calls to set_dfp{64,128}() in DFP macros
> git bisect good f6d4c423a222f02bfa84a49c3d306d7341ec9bab
> # bad: [e68cd0cb5cf49d334abe17231a1d2c28b846afa2] spapr: Render full FDT on ibm,client-architecture-support
> git bisect bad e68cd0cb5cf49d334abe17231a1d2c28b846afa2
> # good: [c4ec08ab70bab90685d1443d6da47293e3aa312a] spapr-pci: Stop providing assigned-addresses
> git bisect good c4ec08ab70bab90685d1443d6da47293e3aa312a
> # first bad commit: [e68cd0cb5cf49d334abe17231a1d2c28b846afa2]
> spapr: Render full FDT on ibm,client-architecture-support

Ah, dammit, I thought we'd fixed the problems with that patch :(.

> 
> attached vmxml.
> 
> qemu commandline:
> /home/sath/qemu/ppc64-softmmu/qemu-system-ppc64 -name guest=vm1,debug-threads=on -S -object secret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain-19-vm1/master-key.aes -machine pseries-4.2,accel=kvm,usb=off,dump-guest-core=off -m 81920 -overcommit mem-lock=off -smp 512,sockets=1,cores=128,threads=4 -uuid fd4a5d54-0216-490e-82d2-1d4e89683b3d -display none -no-user-config -nodefaults -chardev socket,id=charmonitor,fd=24,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-shutdown -boot strict=on -device qemu-xhci,id=usb,bus=pci.0,addr=0x3 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x2 -drive file=/home/sath/tests/data/avocado-vt/images/jeos-27-ppc64le_vm1.qcow2,format=qcow2,if=none,id=drive-scsi0-0-0-0 -device scsi-hd,bus=scsi0.0,channel=0,scsi-id=0,lun=0,device_id=drive-scsi0-0-0-0,drive=drive-scsi0-0-0-0,id=scsi0-0-0-0,bootindex=1 -netdev tap,fd=26,id=hostnet0,vhost=on,vhostfd=27 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:e6:df:24,bus=pci.0,addr=0x1 -chardev pty,id=charserial0 -device spapr-vty,chardev=charserial0,id=serial0,reg=0x30000000 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x4 -M pseries,ic-mode=xics -msg timestamp=on
> 
> ** Affects: qemu
>      Importance: Undecided
>          Status: New
> 
> 
> ** Tags: kvm powerpcm qemu

-- 
David Gibson			| I'll have my music baroque, and my code
david AT gibson.dropbear.id.au	| minimalist, thank you.  NOT _the_ _other_
				| _way_ _around_!
http://www.ozlabs.org/~dgibson

Revision history for this message

David Gibson (dwg) wrote on 2019-10-11:

Ok, I just tried booting a guest with virtio-scsi and ic-mode=xics, and I wasn't able to reproduce this problem.

Can you try simplifying your command line to see what options are needed to trigger this?

Revision history for this message

David Gibson (dwg) wrote on 2019-10-11:

Oh... are you using the SLOF (guest firmware) image included in the qemu tree, or is it coming from a separate package?

If it's from a separate package, that could be the problem - it needs to be updated before that qemu patch is safe.

Revision history for this message

Satheesh Rajendran (sathnaga) wrote on 2019-10-11:

Did try with the slof bin(-bios /usr/local/share/qemu/slof.bin) complied with qemu tree also, same issue persists,

/home/sath/qemu/ppc64-softmmu/qemu-system-ppc64 \
-name guest=vm1,debug-threads=on \
-S \
-object secret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain-2-vm1/master-key.aes \
-machine pseries-4.2,accel=kvm,usb=off,dump-guest-core=off \
-bios /usr/local/share/qemu/slof.bin \
-m 81920 \
-overcommit mem-lock=off \
-smp 512,sockets=1,cores=128,threads=4 \
-uuid fd4a5d54-0216-490e-82d2-1d4e89683b3d \
-display none \
-no-user-config \
-nodefaults \
-chardev socket,id=charmonitor,fd=24,server,nowait \
-mon chardev=charmonitor,id=monitor,mode=control \
-rtc base=utc \
-no-shutdown \
-boot strict=on \
-device qemu-xhci,id=usb,bus=pci.0,addr=0x3 \
-device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x2 \
-drive file=/home/sath/tests/data/avocado-vt/images/jeos-27-ppc64le_vm1.qcow2,format=qcow2,if=none,id=drive-scsi0-0-0-0 \
-device scsi-hd,bus=scsi0.0,channel=0,scsi-id=0,lun=0,device_id=drive-scsi0-0-0-0,drive=drive-scsi0-0-0-0,id=scsi0-0-0-0,bootindex=1 \
-netdev tap,fd=26,id=hostnet0,vhost=on,vhostfd=27 \
-device virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:e6:df:24,bus=pci.0,addr=0x1 \
-chardev pty,id=charserial0 \
-device spapr-vty,chardev=charserial0,id=serial0,reg=0x30000000 \
-device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x4 \
-M pseries,ic-mode=dual \
-msg timestamp=on

Did try with xics aswell, same issue.

Host HW:

#lscpu
Architecture: ppc64le
Byte Order: Little Endian
CPU(s): 128
On-line CPU(s) list: 0-127
Thread(s) per core: 4
Core(s) per socket: 16
Socket(s): 2
NUMA node(s): 2
Model: 2.3 (pvr 004e 1203)
Model name: POWER9, altivec supported
CPU max MHz: 3800.0000
CPU min MHz: 2300.0000
L1d cache: 32K
L1i cache: 32K
L2 cache: 512K
L3 cache: 10240K
NUMA node0 CPU(s): 0-63
NUMA node8 CPU(s): 64-127

FW: skiboot-v6.3.2

Regards,
-Satheesh

Did try with the slof bin(-bios /usr/local/share/qemu/slof.bin) complied with qemu tree also, same issue persists,

Did try with xics aswell, same issue.

Host HW:

#lscpu 
Architecture:        ppc64le
Byte Order:          Little Endian
CPU(s):              128
On-line CPU(s) list: 0-127
Thread(s) per core:  4
Core(s) per socket:  16
Socket(s):           2
NUMA node(s):        2
Model:               2.3 (pvr 004e 1203)
Model name:          POWER9, altivec supported
CPU max MHz:         3800.0000
CPU min MHz:         2300.0000
L1d cache:           32K
L1i cache:           32K
L2 cache:            512K
L3 cache:            10240K
NUMA node0 CPU(s):   0-63
NUMA node8 CPU(s):   64-127

FW: skiboot-v6.3.2

Regards,
-Satheesh

Revision history for this message

Alexey Kardashevskiy (aik-ozlabs) wrote on 2019-10-21:

Please provide the entire guest booting output, from slof till it is stuck.
Also please try with -smp 1. Thanks.

Revision history for this message

Satheesh Rajendran (sathnaga) wrote on 2019-10-21:

Download full text (17.5 KiB)

Domain vm1 started
Connected to domain vm1
Escape character is ^]
Populating /vdevice methods
Populating /vdevice/vty@30000000
Populating /vdevice/nvram@71000000
Populating /pci@800000020000000
                     00 0800 (D) : 1af4 1000 virtio [ net ]
                     00 1000 (D) : 1af4 1004 virtio [ scsi ]
Populating /pci@800000020000000/scsi@2
       SCSI: Looking for devices
          100000000000000 DISK : "QEMU QEMU HARDDISK 2.5+"
                     00 1800 (D) : 1b36 000d serial bus [ usb-xhci ]
                     00 2000 (D) : 1af4 1002 unknown-legacy-device*
No NVRAM common partition, re-initializing...
Scanning USB
  XHCI: Initializing
Using default console: /vdevice/vty@30000000

Welcome to Open Firmware

  Copyright (c) 2004, 2017 IBM Corporation All rights reserved.
  This program and the accompanying materials are made available
  under the terms of the BSD License available at
  http://www.opensource.org/licenses/bsd-license.php

Trying to load: from: /pci@800000020000000/scsi@2/disk@100000000000000 ... Successfully loaded

OF stdout device is: /vdevice/vty@30000000
Preparing to boot Linux version 4.13.9-300.fc27.ppc64le (<email address hidden>) (gcc version 7.2.1 20170915 (Red Hat 7.2.1-2) (GCC)) #1 SMP Mon Oct 23 13:28:27 UTC 2017
Detected machine type: 0000000000000101
command line: BOOT_IMAGE=/boot/vmlinuz-4.13.9-300.fc27.ppc64le root=UUID=500d2159-c568-459e-8864-1c21b3519a80 ro console=tty0 console=ttyS0,115200 console=hvc0
Max number of cores passed to firmware: 1024 (NR_CPUS = 1024)
Calling ibm,client-architecture-support...Node not supported
Node not supported
not implemented
memory layout at init:
  memory_limit : 0000000000000000 (16 MB aligned)
  alloc_bottom : 00000000046a0000
  alloc_top : 0000000010000000
  alloc_top_hi : 0000001400000000
  rmo_top : 0000000010000000
  ram_top : 0000001400000000
instantiating rtas at 0x000000000daf0000... done
prom_hold_cpus: skipped
copying OF device tree...
Building dt strings...
Building dt structure...
Device tree strings 0x00000000046b0000 -> 0x00000000046b0b3f
Device tree struct 0x00000000046c0000 -> 0x00000000046d0000
Quiescing Open Firmware ...
Booting Linux via __start() @ 0x0000000002000000 ...
[ 0.000000] Page sizes from device-tree:
[ 0.000000] Page size shift = 12 AP=0x0
[ 0.000000] Page size shift = 16 AP=0x5
[ 0.000000] Page size shift = 21 AP=0x1
[ 0.000000] Page size shift = 30 AP=0x2
[ 0.000000] Using radix MMU under hypervisor
[ 0.000000] Mapped range 0x0 - 0x1400000000 with 0x40000000
[ 0.000000] Process table c0000013ff000000 and radix root for kernel: c0000000014c0000
[ 0.000000] Linux version 4.13.9-300.fc27.ppc64le (<email address hidden>) (gcc version 7.2.1 20170915 (Red Hat 7.2.1-2) (GCC)) #1 SMP Mon Oct 23 13:28:27 UTC 2017
[ 0.000000] Found initrd at 0xc000000003900000:0xc0000000046967f5
[ 0.000000] Using pSeries machine description
[ 0.000000] bootconsole [udbg0] enabled
[ 0.000000] Partition configured for 2 cpus.
[ 0.000000] CPU maps initialized for 1 thread per core
-> smp_release_cpus()
spi...

Domain vm1 started
Connected to domain vm1
Escape character is ^]
Populating /vdevice methods
Populating /vdevice/vty@30000000
Populating /vdevice/nvram@71000000
Populating /pci@800000020000000
                     00 0800 (D) : 1af4 1000    virtio [ net ]
                     00 1000 (D) : 1af4 1004    virtio [ scsi ]
Populating /pci@800000020000000/scsi@2
       SCSI: Looking for devices
          100000000000000 DISK     : "QEMU     QEMU HARDDISK    2.5+"
                     00 1800 (D) : 1b36 000d    serial bus [ usb-xhci ]
                     00 2000 (D) : 1af4 1002    unknown-legacy-device*
No NVRAM common partition, re-initializing...
Scanning USB 
  XHCI: Initializing
Using default console: /vdevice/vty@30000000
     
  Welcome to Open Firmware

Trying to load:  from: /pci@800000020000000/scsi@2/disk@100000000000000 ...   Successfully loaded

OF stdout device is: /vdevice/vty@30000000
Preparing to boot Linux version 4.13.9-300.fc27.ppc64le (mockbuild@buildvm-ppc64le-06.ppc.fedoraproject.org) (gcc version 7.2.1 20170915 (Red Hat 7.2.1-2) (GCC)) #1 SMP Mon Oct 23 13:28:27 UTC 2017
Detected machine type: 0000000000000101
command line: BOOT_IMAGE=/boot/vmlinuz-4.13.9-300.fc27.ppc64le root=UUID=500d2159-c568-459e-8864-1c21b3519a80 ro console=tty0 console=ttyS0,115200 console=hvc0
Max number of cores passed to firmware: 1024 (NR_CPUS = 1024)
Calling ibm,client-architecture-support...Node not supported 
Node not supported 
 not implemented
memory layout at init:
  memory_limit : 0000000000000000 (16 MB aligned)
  alloc_bottom : 00000000046a0000
  alloc_top    : 0000000010000000
  alloc_top_hi : 0000001400000000
  rmo_top      : 0000000010000000
  ram_top      : 0000001400000000
instantiating rtas at 0x000000000daf0000... done
prom_hold_cpus: skipped
copying OF device tree...
Building dt strings...
Building dt structure...
Device tree strings 0x00000000046b0000 -> 0x00000000046b0b3f
Device tree struct  0x00000000046c0000 -> 0x00000000046d0000
Quiescing Open Firmware ...
Booting Linux via __start() @ 0x0000000002000000 ...
[    0.000000] Page sizes from device-tree:
[    0.000000] Page size shift = 12 AP=0x0
[    0.000000] Page size shift = 16 AP=0x5
[    0.000000] Page size shift = 21 AP=0x1
[    0.000000] Page size shift = 30 AP=0x2
[    0.000000] Using radix MMU under hypervisor
[    0.000000] Mapped range 0x0 - 0x1400000000 with 0x40000000
[    0.000000] Process table c0000013ff000000 and radix root for kernel: c0000000014c0000
[    0.000000] Linux version 4.13.9-300.fc27.ppc64le (mockbuild@buildvm-ppc64le-06.ppc.fedoraproject.org) (gcc version 7.2.1 20170915 (Red Hat 7.2.1-2) (GCC)) #1 SMP Mon Oct 23 13:28:27 UTC 2017
[    0.000000] Found initrd at 0xc000000003900000:0xc0000000046967f5
[    0.000000] Using pSeries machine description
[    0.000000] bootconsole [udbg0] enabled
[    0.000000] Partition configured for 2 cpus.
[    0.000000] CPU maps initialized for 1 thread per core
 -> smp_release_cpus()
spinning_secondaries = 1
 <- smp_release_cpus()
[    0.000000] -----------------------------------------------------
[    0.000000] ppc64_pft_size    = 0x0
[    0.000000] phys_mem_size     = 0x1400000000
[    0.000000] dcache_bsize      = 0x80
[    0.000000] icache_bsize      = 0x80
[    0.000000] cpu_features      = 0x075c7a7c18500249
[    0.000000]   possible        = 0x5fffffff18500649
[    0.000000]   always          = 0x0000000018100040
[    0.000000] cpu_user_features = 0xdc0065c2 0xaee00000
[    0.000000] mmu_features      = 0x3c006041
[    0.000000] firmware_features = 0x00000001455a445f
[    0.000000] -----------------------------------------------------
[    0.000000] numa:   NODE_DATA [mem 0x13fffe7e80-0x13ffff1b7f]
[    0.000000] PCI host bridge /pci@800000020000000  ranges:
[    0.000000]   IO 0x0000200000000000..0x000020000000ffff -> 0x0000000000000000
[    0.000000]  MEM 0x0000200080000000..0x00002000ffffffff -> 0x0000000080000000 
[    0.000000]  MEM 0x0000210000000000..0x000021ffffffffff -> 0x0000210000000000 
[    0.000000] OF: PCI: PROBE_ONLY disabled
[    0.000000] PPC64 nvram contains 65536 bytes
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000000000-0x00000013ffffffff]
[    0.000000]   DMA32    empty
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x00000013ffffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000013ffffffff]
[    0.000000] percpu: Embedded 3 pages/cpu @c0000013fef80000 s151064 r0 d45544 u196608
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 1309440
[    0.000000] Policy zone: DMA
[    0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-4.13.9-300.fc27.ppc64le root=UUID=500d2159-c568-459e-8864-1c21b3519a80 ro console=tty0 console=ttyS0,115200 console=hvc0
[    0.000000] PID hash table entries: 4096 (order: -1, 32768 bytes)
[    0.000000] Memory: 83754240K/83886080K available (11968K kernel code, 1792K rwdata, 3136K rodata, 4288K init, 2405K bss, 131840K reserved, 0K cma-reserved)
[    0.000000] random: get_random_u64 called from cache_random_seq_create+0xa0/0x180 with crng_init=0
[    0.000000] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] ftrace: allocating 29419 entries in 11 pages
[    0.000000] Hierarchical RCU implementation.
[    0.000000] 	RCU restricting CPUs from NR_CPUS=1024 to nr_cpu_ids=2.
[    0.000000] 	Tasks RCU enabled.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    0.000000] NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16
[    0.000000] time_init: 56 bit decrementer (max: 7fffffffffffff)
[    0.000483] clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns
[    0.001327] clocksource: timebase mult[1f40000] shift[24] registered
[    0.001868] Console: colour dummy device 80x25
[    0.002310] console [tty0] enabled
[    0.002588] console [hvc0] enabled
[    0.002588] console [hvc0] enabled
[    0.002890] bootconsole [udbg0] disabled
[    0.002890] bootconsole [udbg0] disabled
[    0.003238] pid_max: default: 32768 minimum: 301
[    0.003336] Security Framework initialized
[    0.003361] Yama: becoming mindful.
[    0.003387] SELinux:  Initializing.
[    0.008989] Dentry cache hash table entries: 8388608 (order: 10, 67108864 bytes)
[    0.011926] Inode-cache hash table entries: 4194304 (order: 9, 33554432 bytes)
[    0.012030] Mount-cache hash table entries: 131072 (order: 4, 1048576 bytes)
[    0.012237] Mountpoint-cache hash table entries: 131072 (order: 4, 1048576 bytes)
[    0.012576] EEH: pSeries platform initialized
[    0.012611] POWER9 performance monitor hardware support registered
[    0.012664] Hierarchical SRCU implementation.
[    0.013001] smp: Bringing up secondary CPUs ...
[    0.015623] smp: Brought up 1 node, 2 CPUs
[    0.015662] numa: Node 0 CPUs: 0-1
[    0.019886] devtmpfs: initialized
[    0.024963] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.025027] futex hash table entries: 512 (order: 0, 65536 bytes)
[    0.025177] NET: Registered protocol family 16
[    0.027932] EEH: No capable adapters found
[    0.030363] cpuidle: using governor menu
[    0.031979] pstore: using zlib compression
[    0.032005] pstore: Registered nvram as persistent store backend
Linux ppc64le
#1 SMP Mon Oct 2[    0.035136] PCI: Probing PCI hardware
[    0.035185] PCI host bridge to bus 0000:00
[    0.035210] pci_bus 0000:00: root bus resource [io  0x10000-0x1ffff] (bus address [0x0000-0xffff])
[    0.035260] pci_bus 0000:00: root bus resource [mem 0x200080000000-0x2000ffffffff] (bus address [0x80000000-0xffffffff])
[    0.035318] pci_bus 0000:00: root bus resource [mem 0x210000000000-0x21ffffffffff]
[    0.035360] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.037044] IOMMU table initialized, virtual merging enabled
[    0.037088] iommu: Adding device 0000:00:01.0 to group 0, default domain type -1
[    0.037145] pci 0000:00:01.0: of_irq_parse_pci: failed with rc=134
[    0.037190] iommu: Adding device 0000:00:02.0 to group 0, default domain type -1
[    0.037242] pci 0000:00:02.0: of_irq_parse_pci: failed with rc=134
[    0.037286] iommu: Adding device 0000:00:03.0 to group 0, default domain type -1
[    0.037337] pci 0000:00:03.0: of_irq_parse_pci: failed with rc=134
[    0.037380] iommu: Adding device 0000:00:04.0 to group 0, default domain type -1
[    0.037442] pci 0000:00:04.0: of_irq_parse_pci: failed with rc=134
[    0.043219] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.043275] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    0.051951] vgaarb: loaded
[    0.052021] SCSI subsystem initialized
[    0.054039] usbcore: registered new interface driver usbfs
[    0.054076] usbcore: registered new interface driver hub
[    0.054113] usbcore: registered new device driver usb
[    0.055226] EDAC MC: Ver: 3.0.0
[    0.060393] NetLabel: Initializing
[    0.060419] NetLabel:  domain hash size = 128
[    0.060447] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.060492] NetLabel:  unlabeled traffic allowed by default
[    0.062836] clocksource: Switched to clocksource timebase
[    0.073228] VFS: Disk quotas dquot_6.6.0
[    0.073275] VFS: Dquot-cache hash table entries: 8192 (order 0, 65536 bytes)
[    0.318455] NET: Registered protocol family 2
[    0.318612] TCP established hash table entries: 524288 (order: 6, 4194304 bytes)
[    0.319695] TCP bind hash table entries: 65536 (order: 4, 1048576 bytes)
[    0.319940] TCP: Hash tables configured (established 524288 bind 65536)
[    0.320000] UDP hash table entries: 65536 (order: 5, 2097152 bytes)
[    0.320342] UDP-Lite hash table entries: 65536 (order: 5, 2097152 bytes)
[    0.320713] NET: Registered protocol family 1
[    0.320782] pci 0000:00:03.0: enabling device (0000 -> 0002)
[    0.320897] Unpacking initramfs...
[    0.536932] Freeing initrd memory: 13888K
[    0.540445] rtas_flash: no firmware flash support
[    0.540685] audit: initializing netlink subsys (disabled)
[    0.544654] Initialise system trusted keyrings
[    0.544693] Key type blacklist registered
[    0.545355] audit: type=2000 audit(1571635628.541:1): state=initialized audit_enabled=0 res=1
[    0.547068] workingset: timestamp_bits=38 max_order=21 bucket_order=0
[    0.548074] zbud: loaded
[    0.693638] random: fast init done
[    0.756362] NET: Registered protocol family 38
[    0.756416] Key type asymmetric registered
[    0.756450] Asymmetric key parser 'x509' registered
[    0.756535] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[    0.757780] io scheduler noop registered
[    0.757818] io scheduler deadline registered
[    0.757900] io scheduler cfq registered (default)
[    0.757944] io scheduler mq-deadline registered
[    0.758947] atomic64_test: passed
[    0.773254] libphy: Fixed MDIO Bus: probed
[    0.775507] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    0.775573] ehci-pci: EHCI PCI platform driver
[    0.775625] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    0.775685] ohci-pci: OHCI PCI platform driver
[    0.775734] uhci_hcd: USB Universal Host Controller Interface driver
[    0.775841] xhci_hcd 0000:00:03.0: enabling device (0000 -> 0002)
[    0.775953] xhci_hcd 0000:00:03.0: xHCI Host Controller
[    0.777192] xhci_hcd 0000:00:03.0: new USB bus registered, assigned bus number 1
[    0.777541] xhci_hcd 0000:00:03.0: ibm,query-pe-dma-windows(2026) 1800 2000 0 returned -3
[    0.778091] xhci_hcd 0000:00:03.0: hcc params 0x00087001 hci version 0x100 quirks 0x00000010
[    0.778169] xhci_hcd 0000:00:03.0: No msi-x/msi found and no IRQ in BIOS
[    0.778223] xhci_hcd 0000:00:03.0: startup error -22
[    0.778268] xhci_hcd 0000:00:03.0: USB bus 1 deregistered
[    0.780041] xhci_hcd 0000:00:03.0: init 0000:00:03.0 fail, -22
[    0.780101] xhci_hcd: probe of 0000:00:03.0 failed with error -22
[    0.780174] usbcore: registered new interface driver usbserial
[    0.780233] usbcore: registered new interface driver usbserial_generic
[    0.780291] usbserial: USB Serial support registered for generic
[    0.782554] mousedev: PS/2 mouse device common for all mice
[    0.782886] rtc-generic rtc-generic: rtc core: registered rtc-generic as rtc0
[    0.783012] device-mapper: uevent: version 1.0.3
[    0.784846] device-mapper: ioctl: 4.37.0-ioctl (2017-09-20) initialised: dm-devel@redhat.com
[    0.786176] hidraw: raw HID events driver (C) Jiri Kosina
[    0.786257] usbcore: registered new interface driver usbhid
[    0.786300] usbhid: USB HID core driver
[    0.786388] drop_monitor: Initializing network drop monitor service
[    0.786511] ip_tables: (C) 2000-2006 Netfilter Core Team
[    0.786564] Initializing XFRM netlink socket
[    0.786734] NET: Registered protocol family 10
[    0.794930] Segment Routing with IPv6
[    0.794983] mip6: Mobile IPv6
[    0.795015] NET: Registered protocol family 17
[    0.800017] registered taskstats version 1
[    0.800060] Loading compiled-in X.509 certificates
[    0.850282] Loaded X.509 cert 'Fedora kernel signing key: a878db2990f3e3239cc963ffd6fea115d9415954'
[    0.850347] zswap: loaded using pool lzo/zbud
[    0.857402] Key type big_key registered
[    0.864367] Key type encrypted registered
[    0.865572] rtc-generic rtc-generic: setting system clock to 2019-10-21 05:27:08 UTC (1571635628)
[    0.866653] Freeing unused kernel memory: 4288K
[    0.866684] This architecture does not have kernel memory protection.
[    0.872683] systemd[1]: systemd 234 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN default-hierarchy=hybrid)
[    0.872817] systemd[1]: Detected virtualization kvm.
[    0.872855] systemd[1]: Detected architecture ppc64-le.
[    0.872885] systemd[1]: Running in initial RAM disk.

Welcome to Fedora 27 (Twenty Seven) dracut-046-5.fc27 (Initramfs)!

[    0.873073] systemd[1]: Set hostname to <atest-guest>.
[    0.952006] systemd[1]: Listening on Journal Audit Socket.
[  OK  ] Listening on Journal Audit Socket.
[    0.952292] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[  OK  ] Started Dispatch Password Requests to Console Directory Watch.
[    0.952488] systemd[1]: Reached target Paths.
[  OK  ] Reached target Paths.
[    0.952639] systemd[1]: Reached target Local File Systems.
[  OK  ] Reached target Local File Systems.
[    0.952816] systemd[1]: Reached target Timers.
[  OK  ] Reached target Timers.
[  OK  ] Listening on Journal Socket (/dev/log).
[  OK  ] Listening on Journal Socket.
[  OK  ] Reached target Swap.
[  OK  ] Listening on udev Control Socket.
[  OK  ] Listening on udev Kernel Socket.
[  OK  ] Reached target Sockets.
[  OK  ] Created slice System Slice.
         Starting Create Volatile Files and Directories...
         Starting Create list of required st…ce nodes for the current kernel...
[  OK  ] Reached target Slices.
         Starting Journal Service...
         Starting Apply Kernel Variables...
[  OK  ] Started Create Volatile Files and Directories.
[  OK  ] Started Apply Kernel Variables.
[  OK  ] Started Create list of required sta…vice nodes for the current kernel.
         Starting Create Static Device Nodes in /dev...
[  OK  ] Started Create Static Device Nodes in /dev.
[    0.967752] audit: type=1130 audit(1571635628.603:2): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-tmpfiles-setup-dev comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
         Starting udev Kernel Device Manager...
[  OK  ] Started Journal Service.
[    0.973468] audit: type=1130 audit(1571635628.608:3): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-journald comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[  OK  ] Started udev Kernel Device Manager.
         Starting udev Coldplug all Devices...
[    0.975851] audit: type=1130 audit(1571635628.610:4): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-udevd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
         Mounting Kernel Configuration File System...
[  OK  ] Mounted Kernel Configuration File System.
[    1.039675] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)
[    1.039749] virtio-pci 0000:00:01.0: virtio_pci: leaving for legacy driver
[    1.041139] synth uevent: /devices/vio: failed to send uevent
[    1.041140] vio vio: uevent: failed to send synthetic uevent
[  OK  ] Started udev Coldplug all Devices.
[    1.042946] audit: type=1130 [audit(1571635628  OK  id=1 umid=0 auid=429496] Reached target R7295 ses=4294967e295 subj=kernel mote File Systemmsg='unit=systemsd-udev-trigger c (Pre).omm="systemd" ex
e="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[    1.043884] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)
[    1.043908] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
[    1.043979] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)
[    1.044003] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
[  OK  ] Reached target Remote File Systems.
[  OK  ] Reached target System Initialization.
[  OK  ] Reached target Basic System.
[    1.102715] virtio_scsi: probe of virtio1 failed with error -22
[**    ] A start job is running for dev-disk…19a80.device (1min 50s / no limit)

Revision history for this message

Satheesh Rajendran (sathnaga) wrote on 2019-10-21:

Same observation with smp 1 even.

Revision history for this message

Alexey Kardashevskiy (aik-ozlabs) wrote on 2019-10-22:

https://patchwork.ozlabs.org/patch/1180363/ should fix it, a SLOF update for QEMU is also posted
https://github.com/aik/qemu/tree/qemu-slof-20191022-branch