Hit this issue by automation. The steps in above. Not hit it on linux guest.


Details:

Host:
kernel-4.18.0-67.el8.x86_64
qemu-kvm-3.1.0-13.module+el8+2792+e33e01a0
spice-server-0.14.0-6.el8.x86_64
seabios-bin-1.12.0-1.module+el8+2706+3c6581b6.noarch
seavgabios-bin-1.12.0-1.module+el8+2706+3c6581b6.noarch

Guest:
windows2019
virtio-win-prewhql-0.1-163.iso


How reproducible:
8/150


auto cmd lines:
python3 ConfigTest.py --testcase=block_hotplug..block_virtio..fmt_qcow2..with_plug..with_repetition..multi_pci,block_hotplug..block_virtio..fmt_qcow2..with_plug..with_reboot..multi_pci,block_hotplug..block_virtio..fmt_raw..with_plug..with_reboot..one_pci --imageformat=qcow2 --guestname=Win2019 --driveformat=virtio_scsi --nicmodel=virtio_net --clone=no --nrepeat=50


qemu cmd lines:

/usr/libexec/qemu-kvm \
    -S  \
    -name 'avocado-vt-vm1' \
    -machine pc  \
    -nodefaults \
    -device VGA,bus=pci.0,addr=0x2  \
    -chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/avocado_lnugh56o/monitor-qmpmonitor1-20190213-064618-wQK6mV75,server,nowait \
    -mon chardev=qmp_id_qmpmonitor1,mode=control  \
    -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/avocado_lnugh56o/monitor-catch_monitor-20190213-064618-wQK6mV75,server,nowait \
    -mon chardev=qmp_id_catch_monitor,mode=control \
    -device pvpanic,ioport=0x505,id=idCfFrlu  \
    -chardev socket,id=serial_id_serial0,path=/var/tmp/avocado_lnugh56o/serial-serial0-20190213-064618-wQK6mV75,server,nowait \
    -device isa-serial,chardev=serial_id_serial0  \
    -chardev socket,id=seabioslog_id_20190213-064618-wQK6mV75,path=/var/tmp/avocado_lnugh56o/seabios-20190213-064618-wQK6mV75,server,nowait \
    -device isa-debugcon,chardev=seabioslog_id_20190213-064618-wQK6mV75,iobase=0x402 \
    -device ich9-usb-ehci1,id=usb1,addr=0x1d.7,multifunction=on,bus=pci.0 \
    -device ich9-usb-uhci1,id=usb1.0,multifunction=on,masterbus=usb1.0,addr=0x1d.0,firstport=0,bus=pci.0 \
    -device ich9-usb-uhci2,id=usb1.1,multifunction=on,masterbus=usb1.0,addr=0x1d.2,firstport=2,bus=pci.0 \
    -device ich9-usb-uhci3,id=usb1.2,multifunction=on,masterbus=usb1.0,addr=0x1d.4,firstport=4,bus=pci.0 \
    -device virtio-scsi-pci,id=virtio_scsi_pci0,bus=pci.0,addr=0x3 \
    -drive id=drive_image1,if=none,snapshot=off,aio=threads,cache=none,format=qcow2,file=/home/kvm_autotest_root/images/win2019-64-virtio-scsi.qcow2 \
    -device scsi-hd,id=image1,drive=drive_image1,bootindex=0 \
    -device virtio-net-pci,mac=9a:8c:8d:8e:8f:90,id=idEdiTUW,vectors=4,netdev=idH26O4o,bus=pci.0,addr=0x4  \
    -netdev tap,id=idH26O4o,vhost=on \
    -m 18432  \
    -smp 12,maxcpus=12,cores=6,threads=1,sockets=2  \
    -cpu 'SandyBridge',+kvm_pv_unhalt,hv_relaxed,hv_spinlocks=0x1fff,hv_vapic,hv_time \
    -drive id=drive_cd1,if=none,snapshot=off,aio=threads,cache=none,media=cdrom,file=/home/kvm_autotest_root/iso/windows/winutils.iso \
    -device scsi-cd,id=cd1,drive=drive_cd1 \
    -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1  \
    -vnc :0  \
    -rtc base=localtime,clock=host,driftfix=slew  \
    -boot order=cdn,once=c,menu=off,strict=off \
    -enable-kvm \
    -monitor stdio \



Not receive "DEVICE_DELETED" event, after execute "device_del".

e.g.
2019-02-13 06:49:57: {"timestamp": {"seconds": 1550058592, "microseconds": 888245}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral/stg1/virtio-backend"}}
2019-02-13 06:49:57: {"timestamp": {"seconds": 1550058592, "microseconds": 893544}, "event": "DEVICE_DELETED", "data": {"device": "stg1", "path": "/machine/peripheral/stg1"}}



logs:

2019-02-13 07:50:37: {"execute": "device_del", "arguments": {"id": "stg1"}, "id": "66pzh8b6"}
2019-02-13 07:50:37: {"return": {}, "id": "66pzh8b6"}
2019-02-13 07:50:38: {"execute": "human-monitor-command", "arguments": {"command-line": "info qtree"}, "id": "DibEIDiZ"}

stg1 in qtree,

30 seconds later, stg1 is still existent in qtree and not receive "DEVICE_DELETED" event.

120 seconds later, stg1 is still existent in qtree and not receive "DEVICE_DELETED" event.


both q35+blockdev and pc+drive also hit this issue.

Similar bug: Bug 1669931 - It's failed to hot unplug virtio-serial device on win2019 guest sometimes. 

It is for chardev device, so report a new bug, if they are same issue, please close one.

unplug virtio-blk disk hit this issue, unplug virtio-scsi disk not hit this issue.

 
unplug virtio-blk disk hit this issue, downgrade viostor to virtio-win-prewhql-0.1-160 and retest on windows10 and windows2019, also hit this issue.


Details:

Host:
kernel-4.18.0-68.el8.x86_64
qemu-kvm-3.1.0-15.module+el8+2792+e33e01a0


Guest:
Windows10 x86_64
Windows2019

guest system disk is virtio-scsi disk, vioscsi version is virtio-win-prewhql-0.1-163
guest data disk is virio-blk disk, viostor version is virtio-win-prewhql-0.1-160

See also bug 1669931 and bug 1523017, it might be a windows driver issue.

Xueqiang Wei reproduced with upstream commit 9d86712365 plus tracing patches I created (to be polished and pushed upstream later).  I'm going to attach the diff to commit 9d86712365 so you can reproduce his findings.

Xueqiang Wei reported this trace for a good run (some decoration stripped off for clarity)

    acpi_pci_unplug_request unplug request bsel 0 slot 6
    acpi_pci_sel_write pci_sel write 10 <== 0
    acpi_pci_up_read pci_up_read 0
    acpi_pci_down_read pci_down_read 64
    acpi_pci_sel_write pci_sel write 10 <== 0
    acpi_pci_eject_slot eject bsel 0 slot 6
    acpi_pci_unplug unplug bsel 6 slot 0
    acpi_pci_ej_write pci_ej write 8 <== 64

and this one for a bad run:

    acpi_pci_unplug_request unplug request bsel 0 slot 6
    acpi_pci_sel_write pci_sel write 10 <== 0
    acpi_pci_up_read pci_up_read 0
    acpi_pci_down_read pci_down_read 64

It's an exact prefix of the good run's trace.

What this shows is that QEMU initiates the hotplug, the guest responds by examining some state.  In the good run, it then tells QEMU it completed the unplug.  In the bad run, it doesn't.  Looks like a guest issue to me.

Let me explain the common prefix, step by step:

* acpi_pci_unplug_request unplug request bsel 0 slot 6

  This is acpi_pcihp_device_unplug_request_cb().  Its where QMP command
  device_del hits the PIIX4_PM device.  Call chain:

    piix4_device_unplug_request_cb()
    hotplug_handler_unplug_request()
    qdev_unplug()
    qmp_device_del()

* acpi_pci_sel_write pci_sel write 10 <== 0

  This is pci_write().  The guest just wrote 32 bit value 10 to memory
  region "acpi-pci-hotplug" address 0x0010 (PCI_SEL_BASE).

* acpi_pci_up_read pci_up_read 0

  This is pci_down_read().  The guest just read 32 bit value 0 from
  address 0x0000 (PCI_UP_BASE).

* acpi_pci_down_read pci_down_read 64

  This is pci_down_read().  The guest just read 32 bit value 64 from
  address 0x0004 (PCI_DOWN_BASE).

The bad run stops right here.  The good run goes on:

* acpi_pci_sel_write pci_sel write 10 <== 0

  This is pci_write().  The guest just wrote 32 bit value 0 to address
  0x0010 (PCI_SEL_BASE).

* acpi_pci_eject_slot eject bsel 0 slot 6

  This is acpi_pcihp_eject_slot(), called from pci_write() below.

* acpi_pci_unplug unplug bsel 6 slot 0

  This is acpi_pcihp_device_unplug_cb(), ultimately called from
  pci_write() below.  Call chain:

    piix4_device_unplug_cb()
    hotplug_handler_unplug()
    acpi_pcihp_eject_slot()
    pci_write()

* acpi_pci_ej_write pci_ej write 8 <== 64

  This is pci_write().  The guest just wrote 32 bit value 64 to address
  0x0008 (PCI_EJ_BASE).

Created attachment 1549469 [details]
Additional trace points for ACPI unplug, use -trace 'enable=acpi_pci_*'  to enable

Hit similar issue when hotunplug virtio-net-pci device on rhel8 fast train, it can be reproduced 100%.

steps:
1. boot guest up with virtio-net-pci device:
-device pcie-root-port,id=pcie.0-root-port-4,slot=4,chassis=4,addr=0x4,bus=pcie.0 \
-device virtio-net-pci,mac=9a:37:38:39:3a:3b,id=net1,mq=on,vectors=10,netdev=hostnet1,bus=pcie.0-root-port-4,addr=0x0 \
-netdev tap,id=hostnet1,vhost=on,queues=4 \
-m 2048 -smp 4,maxcpus=4,cores=2,threads=1,sockets=2

2. From qmp monitor, unplug the virtio-net-pci device.
telnet host_ip 4445
{ 'execute': 'qmp_capabilities' }
{ 'execute': 'device_del', 'arguments': {'id': 'net1' }}

3. check the "event": "DEVICE_DELETED" logs, only return "/machine/peripheral/net1/virtio-backend" be deleted info, as follow: 
{"timestamp": {"seconds": 1554088482, "microseconds": 474877}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral/net1/virtio-backend"}}
no return {"device": "net0", "path": "/machine/peripheral/net1"} be deleted info, it should return follow as well:
{"timestamp": {"seconds": 1511509084, "microseconds": 162214}, "event": "DEVICE_DELETED", "data": {"device": "net1", "path": "/machine/peripheral/net0"}}

Also tried on rhel8 slow train, it can be reproduced 20%.

RHEL8 Fast train versions:
kernel-4.18.0-80.4.el8.x86_64
qemu-kvm-3.1.0-20.module+el8+2888+cdc893a8.x86_64
seabios-bin-1.12.0-1.module+el8+2706+3c6581b6.noarch
virtio-win-prewhql-169

RHEL8 Slow train versions:
kernel-4.18.0-80.4.el8.x86_64
qemu-kvm-15:2.12.0-63.module+el8+2833+c7d6d092.x86_64 
seabios-bin-1.12.0-1.module+el8+2706+3c6581b6.noarch
virtio-win-prewhql-169

Hi Markus, could you help to check if need to file a new bug for this?

Thanks a lot~
Peixiu

In reply to comment#11: 

It could be the same root cause or not.  If you send me trace output with the trace patches from comment#11 for a good and a bad run, I'll gladly look for clues there.

I hit the same issue as comment#11 on ws2019 (q35/ovmf)

And tried with rhel8.1.0 guest, cannot reproduce it.
So the issue is comment#11 a windows only bug. 

Thanks
Yu Wang

(In reply to Markus Armbruster from comment #13)
> In reply to comment#11: 
> 
> It could be the same root cause or not.  If you send me trace output with
> the trace patches from comment#11 for a good and a bad run, I'll gladly look
> for clues there.

Setting needinfo based on the comment above.

Thanks.

(In reply to CongLi from comment #15)
> (In reply to Markus Armbruster from comment #13)
> > In reply to comment#11: 
> > 
> > It could be the same root cause or not.  If you send me trace output with
> > the trace patches from comment#11 for a good and a bad run, I'll gladly look
> > for clues there.
> 
> Setting needinfo based on the comment above.
> 
> Thanks.

Hi Markus, coli,

I tried to reproduce the issue I hit in comment#11 with upstream qemu http://git.engineering.redhat.com/git/users/armbru/qemu.git/

the issue can reproduced easily, but no trace log output when do unplug the virtio-net-pci device.

Also tried to hotplug a virtio-blk-pci and unplug a virtio-blk-pci device, both no trace log output.

Configured upstream qemu commands as:
#./configure \
--target-list=x86_64-softmmu  \
--prefix=/usr  \
--libdir=/usr/lib64  \
--sysconfdir=/etc  \
--interp-prefix=/usr/qemu-%M  \
--localstatedir=/var  \
--docdir=/usr/share/doc/qemu-kvm  \
--libexecdir=/usr/libexec  \
--extra-ldflags="-Wl,-z,relro -Wl,-z,now"  \
--extra-cflags="-O2 -g -pipe -Wall -Werror=format-security -Wp,-D_FORTIFY_SOURCE=2 -Wp,-D_GLIBCXX_ASSERTIONS -fexceptions -fstack-protector-strong -grecord-gcc-switches -specs=/usr/lib/rpm/redhat/redhat-hardened-cc1 -specs=/usr/lib/rpm/redhat/redhat-annobin-cc1 -m64 -mtune=generic -fasynchronous-unwind-tables -fstack-clash-protection -fcf-protection"   \
--python=/usr/libexec/platform-python  \
--with-confsuffix=/qemu-kvm  \
--with-coroutine=ucontext  \
--tls-priority=NORMAL  \
--disable-bluez  \
--disable-brlapi  \
--disable-cap-ng  \
--enable-coroutine-pool  \
--enable-curl  \
--disable-curses  \
--disable-debug-tcg  \
--enable-docs  \
--disable-gtk  \
--enable-kvm  \
--enable-libiscsi  \
--disable-libnfs  \
--enable-libusb  \
--disable-bzip2  \
--enable-linux-aio  \
--disable-live-block-migration  \
--enable-lzo  \
--disable-opengl  \
--enable-pie  \
--disable-qom-cast-debug  \
--disable-sdl  \
--enable-snappy  \
--disable-sparse  \
--disable-strip  \
--disable-tpm  \
--enable-trace-backend=log  \
--disable-vde  \
--disable-vhost-scsi  \
--disable-virtfs  \
--disable-vnc-jpeg  \
--disable-vte  \
--enable-vnc-png  \
--enable-vnc-sasl  \
--enable-werror  \
--disable-xen  \
--disable-xfsctl  \
--enable-gnutls  \
--enable-gcrypt  \
--disable-nettle  \
--enable-attr  \
--disable-bsd-user  \
--disable-cocoa  \
--enable-debug-info  \
--disable-guest-agent-msi  \
--disable-hax  \
--disable-jemalloc  \
--disable-linux-user  \
--disable-modules  \
--disable-netmap  \
--disable-replication  \
--enable-system  \
--enable-tools  \
--disable-user  \
--enable-vhost-net  \
--enable-vhost-vsock  \
--enable-vnc  \
--enable-mpath  \
--disable-virglrenderer  \
--disable-xen-pci-passthrough  \
--enable-tcg  \
--disable-crypto-afalg  \
--disable-fdt  \
--disable-glusterfs  \
--enable-guest-agent  \
--enable-numa  \
--enable-rbd  \
--enable-rdma  \
--enable-seccomp  \
--enable-spice  \
--enable-smartcard  \
--disable-vxhs  \
--enable-usb-redir  \
--disable-tcmalloc  \
--enable-vhost-user  \
--audio-drv-list=  \
--block-drv-rw-whitelist=qcow2,raw,file,host_device,nbd,iscsi,rbd,blkdebug,luks,null-co  \
--block-drv-ro-whitelist=vmdk,vhdx,vpc,https,ssh  \
--extra-ldflags=-lrt \
--enable-gcrypt \
--with-pkgversion=commit-0c8ff38ec32d38aa5f07ffc5adca3a7f3f90e79e  \

#make
#make install

[root@dell-per440-03 qemu]# /usr/bin/qemu-system-x86_64 --version
QEMU emulator version 3.1.50 (commit-0c8ff38ec32d38aa5f07ffc5adca3a7f3f90e79e)
Copyright (c) 2003-2019 Fabrice Bellard and the QEMU Project developers

#git log
commit 0c8ff38ec32d38aa5f07ffc5adca3a7f3f90e79e (HEAD -> trace-unplug, origin/trace-unplug)
Author: Markus Armbruster <armbru>
Date:   Wed Mar 13 13:37:09 2019 +0100

    acpi/pcihp: Add a few more trace points related to unplug
    
    Signed-off-by: Markus Armbruster <armbru>

commit d26358e7b31d5000ae5c3698bad70d014aa85401
Author: Markus Armbruster <armbru>
Date:   Wed Mar 13 13:11:46 2019 +0100

    acpi/pcihp: Convert debug printf()s to trace events
    
    Signed-off-by: Markus Armbruster <armbru>

[root@dell-per440-03 qemu]# locate pcihp.c
/home/qemu-upstream/qemu/hw/acpi/pcihp.c
/usr/src/debug/qemu-kvm-3.1.0-22.module+el8.0.1+3032+a09688b9.x86_64/hw/acpi/pcihp.c

checked the /home/qemu-upstream/qemu/hw/acpi/pcihp.c file:
the code changed as your commit changed, pasted part of:
=======================================================================================
static void acpi_pcihp_eject_slot(AcpiPciHpState *s, unsigned bsel, unsigned slots)
{
    HotplugHandler *hotplug_ctrl;
    BusChild *kid, *next;
    int slot = ctz32(slots);
    PCIBus *bus = acpi_pcihp_find_hotplug_bus(s, bsel);

    trace_acpi_pci_eject_slot(bsel, slot);
    if (!bus) {
        return;
    }
========================================================================================

Used qemu command line as:
/usr/bin/qemu-system-x86_64 \
    -name 'avocado-vt-vm1' \
    -trace 'enable=acpi_pci_*' \
    -machine q35  \
    -drive id=drive_image1,if=none,snapshot=off,aio=native,cache=none,format=qcow2,file=/home/kvm_autotest_root/images/win10-32-virtio.qcow2 \
    -device pcie-root-port,id=pcie.0-root-port-3,slot=3,chassis=3,addr=0x3,bus=pcie.0 \
    -device virtio-blk-pci,id=image1,drive=drive_image1,bootindex=0,bus=pcie.0-root-port-3,addr=0x0 \
    -device pcie-root-port,id=pcie.0-root-port-5,slot=5,chassis=5,addr=0x5,bus=pcie.0 \
    -netdev tap,script=/etc/qemu-ifup,downscript=no,id=hostnet1,vhost=on \
    -device virtio-net-pci,netdev=hostnet1,id=net1,mac=00:52:20:76:1a:4d,bus=pcie.0-root-port-5,addr=0x0 \
    -m 24576  \
    -smp 32,maxcpus=32,cores=16,threads=1,sockets=2  \
    -cpu host,hv_stimer,hv_synic,hv_vpindex,hv_reset,hv_relaxed,hv_spinlocks=0x1fff,hv_vapic,hv_time,hv-tlbflush,+kvm_pv_unhalt \
    -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1  \
    -vnc :5  \
    -rtc base=localtime,clock=host,driftfix=slew  \
    -boot order=cdn,once=c,menu=off,strict=off \
    -enable-kvm \
    -monitor stdio \
    -qmp tcp::4445,server,nowait \

Best Regards~
Peixiu

Peixiu,

My series adding the tracepoints hasn't been merged upstream, yet.  Please apply

From: Markus Armbruster <armbru>
Subject: [PATCH 0/3] acpi: More trace points
To: qemu-devel
Cc: mst, imammedo, marcel.apfelbaum
Date: Tue,  2 Apr 2019 18:18:57 +0200 (5 weeks, 19 hours, 24 seconds ago)
Message-Id: <20190402161900.7374-1-armbru>
https://lists.gnu.org/archive/html/qemu-devel/2019-04/msg00552.html

For your convenience, I pushed it to branch trace-unplug in my public repository
<https://repo.or.cz/qemu/armbru.git>.  The branch is temporary there.

(In reply to Markus Armbruster from comment #17)
> Peixiu,
> 
> My series adding the tracepoints hasn't been merged upstream, yet.  Please
> apply
> 
> From: Markus Armbruster <armbru>
> Subject: [PATCH 0/3] acpi: More trace points
> To: qemu-devel
> Cc: mst, imammedo, marcel.apfelbaum
> Date: Tue,  2 Apr 2019 18:18:57 +0200 (5 weeks, 19 hours, 24 seconds ago)
> Message-Id: <20190402161900.7374-1-armbru>
> https://lists.gnu.org/archive/html/qemu-devel/2019-04/msg00552.html
> 
> For your convenience, I pushed it to branch trace-unplug in my public
> repository
> <https://repo.or.cz/qemu/armbru.git>.  The branch is temporary there.

Hi markus,

Thanks a lot for your information~

I tried to test with -machine pc on win7-32 guest, the trace output worked. But this issue(mentioned on comment#11) cannot be reproduced with pc.
I tried to test with -machine q35 again on win7-32 guest, reproduced this issue(mentioned on comment#11) easily, but none trace log output.

sorry for missing this info in comment#11, hit it only with q35 guest, not hit this issue on pc guest.

With -machine q35, q35 default use pcie bus, the virtio-net-pci/virtio-blk-pci device both added under pcie-root-port, but the trace patch seems set for acpi_pci_*, I guess that's why trace unplug patch cannot work on q35 machine guest.


Best Regards~
Peixiu

Yes, my "acpi: More trace points" helps only with ACPI hotplug.  Q35 takes a different path.

Since you can reproduce your bug only with Q35, but this BZ reproduces with i440FX, yours is probably a separate bug.  Please file a separate BZ, and we'll take it from there.

(In reply to Markus Armbruster from comment #19)
> Yes, my "acpi: More trace points" helps only with ACPI hotplug.  Q35 takes a
> different path.
> 
> Since you can reproduce your bug only with Q35, but this BZ reproduces with
> i440FX, yours is probably a separate bug.  Please file a separate BZ, and
> we'll take it from there.

Ok, I file a new bug https://bugzilla.redhat.com/show_bug.cgi?id=1708480 for virtio-net-pci unplug.

Thanks a lot~
Peixiu

Change the priority to high since it's a normal use case and easy to reproduce.

Comment 9 from Markus, maybe it's useful.

(In reply to Markus Armbruster from comment #9)
> Xueqiang Wei reproduced with upstream commit 9d86712365 plus tracing patches
> I created (to be polished and pushed upstream later).  I'm going to attach
> the diff to commit 9d86712365 so you can reproduce his findings.
> 
> Xueqiang Wei reported this trace for a good run (some decoration stripped
> off for clarity)
> 
>     acpi_pci_unplug_request unplug request bsel 0 slot 6
>     acpi_pci_sel_write pci_sel write 10 <== 0
>     acpi_pci_up_read pci_up_read 0
>     acpi_pci_down_read pci_down_read 64
>     acpi_pci_sel_write pci_sel write 10 <== 0
>     acpi_pci_eject_slot eject bsel 0 slot 6
>     acpi_pci_unplug unplug bsel 6 slot 0
>     acpi_pci_ej_write pci_ej write 8 <== 64
> 
> and this one for a bad run:
> 
>     acpi_pci_unplug_request unplug request bsel 0 slot 6
>     acpi_pci_sel_write pci_sel write 10 <== 0
>     acpi_pci_up_read pci_up_read 0
>     acpi_pci_down_read pci_down_read 64
> 
> It's an exact prefix of the good run's trace.
> 
> What this shows is that QEMU initiates the hotplug, the guest responds by
> examining some state.  In the good run, it then tells QEMU it completed the
> unplug.  In the bad run, it doesn't.  Looks like a guest issue to me.
> 
> Let me explain the common prefix, step by step:
> 
> * acpi_pci_unplug_request unplug request bsel 0 slot 6
> 
>   This is acpi_pcihp_device_unplug_request_cb().  Its where QMP command
>   device_del hits the PIIX4_PM device.  Call chain:
> 
>     piix4_device_unplug_request_cb()
>     hotplug_handler_unplug_request()
>     qdev_unplug()
>     qmp_device_del()
> 
> * acpi_pci_sel_write pci_sel write 10 <== 0
> 
>   This is pci_write().  The guest just wrote 32 bit value 10 to memory
>   region "acpi-pci-hotplug" address 0x0010 (PCI_SEL_BASE).
> 
> * acpi_pci_up_read pci_up_read 0
> 
>   This is pci_down_read().  The guest just read 32 bit value 0 from
>   address 0x0000 (PCI_UP_BASE).
> 
> * acpi_pci_down_read pci_down_read 64
> 
>   This is pci_down_read().  The guest just read 32 bit value 64 from
>   address 0x0004 (PCI_DOWN_BASE).

Looks like QEMU ACPI code works here as expected and guest ACPI handler
knows that it should eject device at slot 6 (64 == 1 << 6) at this point.


> The bad run stops right here.  The good run goes on:
> 
> * acpi_pci_sel_write pci_sel write 10 <== 0
> 
>   This is pci_write().  The guest just wrote 32 bit value 0 to address
>   0x0010 (PCI_SEL_BASE).
pick a bus that device is on 

> * acpi_pci_eject_slot eject bsel 0 slot 6
> 
>   This is acpi_pcihp_eject_slot(), called from pci_write() below.

eject slot 6

> 
> * acpi_pci_unplug unplug bsel 6 slot 0
> 
>   This is acpi_pcihp_device_unplug_cb(), ultimately called from
>   pci_write() below.  Call chain:
> 
>     piix4_device_unplug_cb()
>     hotplug_handler_unplug()
>     acpi_pcihp_eject_slot()
>     pci_write()
> 
> * acpi_pci_ej_write pci_ej write 8 <== 64
> 
>   This is pci_write().  The guest just wrote 32 bit value 64 to address
>   0x0008 (PCI_EJ_BASE).
clean up (processed) removal request register
--



Xueqiang Wei,
I couldn't reproduce issue with comment 1 qemu/virtio-win versions and tried with virtio-win-1.9.8
which also works as expected. I was using Widndows 2019 DC with KB4464455 installed.
BZ doesn't have a complete steps desribing reproducer for PC machine (as it was cloned from Q35),
so tring to provide one and cutting CLI options to the minimum necesarry to reproduce
might help developers to find where problem is (otherwise we are just palying guess game).

At this point I'd say it's guest side issue and QEMU behaves as expected.
Hence I'm moving it to virtio-win component.

(In reply to Igor Mammedov from comment #23)
> (In reply to Markus Armbruster from comment #9)
> > Xueqiang Wei reproduced with upstream commit 9d86712365 plus tracing patches
[...]
> 
> > The bad run stops right here.  The good run goes on:
> > 
> > * acpi_pci_sel_write pci_sel write 10 <== 0
> > 
> >   This is pci_write().  The guest just wrote 32 bit value 0 to address
> >   0x0010 (PCI_SEL_BASE).
> pick a bus that device is on 
> 
> > * acpi_pci_eject_slot eject bsel 0 slot 6
> > 
> >   This is acpi_pcihp_eject_slot(), called from pci_write() below.
> 
> eject slot 6
> 
> > 
> > * acpi_pci_unplug unplug bsel 6 slot 0
> > 
> >   This is acpi_pcihp_device_unplug_cb(), ultimately called from
> >   pci_write() below.  Call chain:
> > 
> >     piix4_device_unplug_cb()
> >     hotplug_handler_unplug()
> >     acpi_pcihp_eject_slot()
> >     pci_write()
> > 
> > * acpi_pci_ej_write pci_ej write 8 <== 64
> > 
> >   This is pci_write().  The guest just wrote 32 bit value 64 to address
> >   0x0008 (PCI_EJ_BASE).
> clean up (processed) removal request register
correction: cleanup is part of ejection process triggered by this write

Created attachment 1616986 [details]
qmplog-block

Created attachment 1616987 [details]
libvirt-vm

Given this couldn't be reproduced using libvirt, I'm setting the priority to medium, as it should not be affecting customers.

bz1523017, bz1678311, and bz1678290 are quite similar, can we close dup bugs and track the similar issues in one bug to make things together?

I hit similar issue when do unplug balloon device under q35 machine type on win2012R2 guest.
pc+seabios cab NOT reproduce.

After unplug:
1. no device_del in qmp receive;
2. no balloon device list in info qtree;
3. balloon device still exist in guest.

package info:
4.18.0-147.el8.x86_64
qemu-kvm-4.1.0-14.module+el8.1.1+4632+a8269660.x86_64
virtio-win-1.9.9-3.el8.iso

hit similar issue when do unplug virtio-blk device under q35 machine type on win19 guest.

1.unplug virtio-blk device in qmp(only one return message) ;

eg:
{"execute":"device_del","arguments":{"id":"stg3"}}
{"return": {}}
{"timestamp": {"seconds": 1576666642, "microseconds": 95572}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral/stg3/virtio-backend"}}

2.hotplug the deleted  device again;

{"execute":"device_add","arguments":{"driver":"virtio-blk-pci","drive":"drive_stg3","id":"stg3","bus":"pci.6","addr":"0x0"}}
{"error": {"class": "GenericError", "desc": "Duplicate ID 'stg3' for device"}}

Actually,no virtio-blk device(stg3)list in info qtree before hotplug.

package info:
kernel-4.18.0-161.el8.x86_64
qemu-kvm-4.2.0-4.module+el8.2.0+5220+e82621dc.x86_64
virtio-win-prewhql-0.1-174.iso

hit similar issue when do unplug virtio-rng device under q35 machine type on win8-32 guest.

1.unplug virtio-blk device in qmp(only one return message) ;

eg:
{"execute":"device_del","arguments":{"id":"rng0"}}
{"return": {}}
{"timestamp": {"seconds": 1577344703, "microseconds": 925724}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral/rng0/virtio-backend"}}


2.hotplug the deleted  device again;

{"execute": "device_add", "arguments": {"driver": "virtio-rng-pci","rng":"objrng0","id":"rng0","bus":"pci.6"}} 
{"error": {"class": "GenericError", "desc": "Duplicate ID 'rng0' for device"}}


Actually,no virtio-rng device(rng0)list in info qtree before hotplug.

package info:
kernel-4.18.0-161.el8.x86_64
qemu-kvm-4.2.0-4.module+el8.2.0+5220+e82621dc.x86_64
virtio-win-prewhql-0.1-175.iso

(In reply to menli from comment #38)
> hit similar issue when do unplug virtio-rng device under q35 machine type on
> win8-32 guest.
> 
> 1.unplug virtio-blk device in qmp(only one return message) ;

sorry, it should be virtio-rng device.


> 
> eg:
> {"execute":"device_del","arguments":{"id":"rng0"}}
> {"return": {}}
> {"timestamp": {"seconds": 1577344703, "microseconds": 925724}, "event":
> "DEVICE_DELETED", "data": {"path":
> "/machine/peripheral/rng0/virtio-backend"}}
> 
> 
> 2.hotplug the deleted  device again;
> 
> {"execute": "device_add", "arguments": {"driver":
> "virtio-rng-pci","rng":"objrng0","id":"rng0","bus":"pci.6"}} 
> {"error": {"class": "GenericError", "desc": "Duplicate ID 'rng0' for
> device"}}
> 
> 
> Actually,no virtio-rng device(rng0)list in info qtree before hotplug.
> 
> package info:
> kernel-4.18.0-161.el8.x86_64
> qemu-kvm-4.2.0-4.module+el8.2.0+5220+e82621dc.x86_64
> virtio-win-prewhql-0.1-175.iso

(In reply to lijin from comment #35)
> bz1523017, bz1678311, and bz1678290 are quite similar, can we close dup bugs
> and track the similar issues in one bug to make things together?

Sure.

Thanks, Gal.

(In reply to menli from comment #37)
> hit similar issue when do unplug virtio-blk device under q35 machine type on
> win19 guest.

This bug is for pc and acpi hotplug. Please, open a new bug for q35.

Best regards, Julia Suvorova.

Virtio-scsi also has the same issue.

qemu version: qemu-kvm-5.0.0-0.scrmod+el8.3.0+6977+09119430.wrb200610
Guest OS: Windows 2019

Boot a guest:
/usr/libexec/qemu-kvm \
    -name 'avocado-vt-vm1'  \
    -sandbox on  \
    -machine q35 \
    -device pcie-root-port,id=pcie-root-port-0,multifunction=on,bus=pcie.0,addr=0x1,chassis=1 \
    -device pcie-pci-bridge,id=pcie-pci-bridge-0,addr=0x0,bus=pcie-root-port-0  \
    -nodefaults \
    -device VGA,bus=pcie.0,addr=0x2 \
    -m 10240  \
    -smp 12,maxcpus=12,cores=6,threads=1,dies=1,sockets=2  \
    -cpu 'SandyBridge',hv_stimer,hv_synic,hv_vpindex,hv_relaxed,hv_spinlocks=0xfff,hv_vapic,hv_time,hv_frequencies,hv_runtime,hv_tlbflush,hv_reenlightenment,hv_stimer_direct,hv_ipi,+kvm_pv_unhalt \
    -chardev socket,nowait,path=/var/tmp/monitor-qmpmonitor1-20200618-085617-XdQfEHuQ,server,id=qmp_id_qmpmonitor1  \
    -mon chardev=qmp_id_qmpmonitor1,mode=control \
    -chardev socket,nowait,path=/var/tmp/monitor-catch_monitor-20200618-085617-XdQfEHuQ,server,id=qmp_id_catch_monitor  \
    -mon chardev=qmp_id_catch_monitor,mode=control \
    -device pvpanic,ioport=0x505,id=idlqPtNl \
    -chardev socket,nowait,path=/var/tmp/serial-serial0-20200618-085617-XdQfEHuQ,server,id=chardev_serial0 \
    -device isa-serial,id=serial0,chardev=chardev_serial0  \
    -chardev socket,id=seabioslog_id_20200618-085617-XdQfEHuQ,path=/var/tmp/seabios-20200618-085617-XdQfEHuQ,server,nowait \
    -device isa-debugcon,chardev=seabioslog_id_20200618-085617-XdQfEHuQ,iobase=0x402 \
    -device pcie-root-port,id=pcie-root-port-1,port=0x1,addr=0x1.0x1,bus=pcie.0,chassis=2 \
    -device qemu-xhci,id=usb1,bus=pcie-root-port-1,addr=0x0 \
    -device usb-ehci,id=ehci,bus=pcie.0,addr=0x3 \
    -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1 \
    -blockdev node-name=file_image1,driver=file,aio=threads,filename=/home/kvm_autotest_root/images/win2019-64-virtio.qcow2,cache.direct=on,cache.no-flush=off \
    -blockdev node-name=drive_image1,driver=qcow2,cache.direct=on,cache.no-flush=off,file=file_image1 \
    -device pcie-root-port,id=pcie-root-port-2,port=0x2,addr=0x1.0x2,bus=pcie.0,chassis=3 \
    -device virtio-blk-pci,id=image1,drive=drive_image1,bootindex=0,write-cache=on,bus=pcie-root-port-2,addr=0x0 \
    -device pcie-root-port,id=pcie-root-port-3,port=0x3,addr=0x1.0x3,bus=pcie.0,chassis=4 \
    -device virtio-net-pci,mac=9a:2e:58:bf:f1:cf,id=idBOPDl6,netdev=idiVKl70,bus=pcie-root-port-3,addr=0x0  \
    -netdev tap,id=idiVKl70,vhost=on \
    -blockdev node-name=file_cd1,driver=file,read-only=on,aio=threads,filename=/home/kvm_autotest_root/iso/windows/winutils.iso,cache.direct=on,cache.no-flush=off \
    -blockdev node-name=drive_cd1,driver=raw,read-only=on,cache.direct=on,cache.no-flush=off,file=file_cd1 \
    -device ide-cd,id=cd1,drive=drive_cd1,bootindex=1,write-cache=on,bus=ide.0,unit=0  \
    -vnc :10  \
    -rtc base=localtime,clock=host,driftfix=slew  \
    -boot menu=off,order=cdn,once=c,strict=off \
    -enable-kvm \
    -device pcie-root-port,id=pcie_extra_root_port_0,multifunction=on,bus=pcie.0,addr=0x4,chassis=5 \

Create a qcow2 image:
qemu-img create -f qcow2 /home/kvm_autotest_root/images/stg.qcow2 10G


Hotplug then unplug:
[root@hp-dl388g8-16 ~]# nc -U /var/tmp/monitor-qmpmonitor1-20200618-085617-XdQfEHuQ
{"QMP": {"version": {"qemu": {"micro": 50, "minor": 0, "major": 5}, "package": "qemu-kvm-5.0.0-0.scrmod+el8.3.0+6977+09119430.wrb200610"}, "capabilities": ["oob"]}}
{"execute": "qmp_capabilities", "id": "yRSKDtOl"}
{"return": {}, "id": "yRSKDtOl"}
{'execute': 'blockdev-add', 'arguments': {'node-name': 'file_stg', 'driver': 'file', 'aio': 'threads', 'filename': '/home/kvm_autotest_root/images/stg.qcow2', 'cache': {'direct': true, 'no-flush': false}}, 'id': 'BVpMEXJy'}
{"return": {}, "id": "BVpMEXJy"}
{'execute': 'blockdev-add', 'arguments': {'node-name': 'drive_stg', 'driver': 'qcow2', 'cache': {'direct': true, 'no-flush': false}, 'file': 'file_stg'}, 'id': 'fIsU5L6M'}
{"return": {}, "id": "fIsU5L6M"}
{"execute": "device_add", "arguments": {"id": "virtio_scsi_pci1", "driver": "virtio-scsi-pci", "bus": "pcie_extra_root_port_0", "addr": "0x0"}, "id": "E0GPZKDS"}
{"return": {}, "id": "E0GPZKDS"}
{"execute": "device_add", "arguments": {"driver": "scsi-hd", "id": "stg", "bus": "virtio_scsi_pci1.0", "drive": "drive_stg", "write-cache": "on"}, "id": "6eu3wZfZ"}
{"return": {}, "id": "6eu3wZfZ"}
{'execute': 'device_del', 'arguments': {'id': 'stg'}, 'id': 'cNdDWa9Z'}
{"timestamp": {"seconds": 1592489036, "microseconds": 823830}, "event": "DEVICE_DELETED", "data": {"device": "stg", "path": "/machine/peripheral/stg"}}
{"return": {}, "id": "cNdDWa9Z"}
{'execute': 'blockdev-del', 'arguments': {'node-name': 'drive_stg'}, 'id': '22HV7WUT'}
{"return": {}, "id": "22HV7WUT"}
{'execute': 'blockdev-del', 'arguments': {'node-name': 'file_stg'}, 'id': 'eRvTLPON'}
{"return": {}, "id": "eRvTLPON"}
{'execute': 'device_del', 'arguments': {'id': 'virtio_scsi_pci1'}, 'id': 'ZPrMG8Md'}
{"return": {}, "id": "ZPrMG8Md"}
{"timestamp": {"seconds": 1592489053, "microseconds": 911792}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral/virtio_scsi_pci1/virtio-backend"}}
{"timestamp": {"seconds": 1592489053, "microseconds": 964424}, "event": "DEVICE_DELETED", "data": {"device": "virtio_scsi_pci1", "path": "/machine/peripheral/virtio_scsi_pci1"}}

{'execute': 'blockdev-add', 'arguments': {'node-name': 'file_stg', 'driver': 'file', 'aio': 'threads', 'filename': '/home/kvm_autotest_root/images/stg.qcow2', 'cache': {'direct': true, 'no-flush': false}}, 'id': 'BVpMEXJy'}
{"return": {}, "id": "BVpMEXJy"}
{'execute': 'blockdev-add', 'arguments': {'node-name': 'drive_stg', 'driver': 'qcow2', 'cache': {'direct': true, 'no-flush': false}, 'file': 'file_stg'}, 'id': 'fIsU5L6M'}
{"return": {}, "id": "fIsU5L6M"}
{"execute": "device_add", "arguments": {"id": "virtio_scsi_pci1", "driver": "virtio-scsi-pci", "bus": "pcie_extra_root_port_0", "addr": "0x0"}, "id": "E0GPZKDS"}
{"return": {}, "id": "E0GPZKDS"}
{"execute": "device_add", "arguments": {"driver": "scsi-hd", "id": "stg", "bus": "virtio_scsi_pci1.0", "drive": "drive_stg", "write-cache": "on"}, "id": "6eu3wZfZ"}
{"return": {}, "id": "6eu3wZfZ"}
{'execute': 'device_del', 'arguments': {'id': 'stg'}, 'id': 'cNdDWa9Z'}
{"timestamp": {"seconds": 1592489081, "microseconds": 450440}, "event": "DEVICE_DELETED", "data": {"device": "stg", "path": "/machine/peripheral/stg"}}
{"return": {}, "id": "cNdDWa9Z"}
{'execute': 'blockdev-del', 'arguments': {'node-name': 'drive_stg'}, 'id': '22HV7WUT'}
{"return": {}, "id": "22HV7WUT"}
{'execute': 'blockdev-del', 'arguments': {'node-name': 'file_stg'}, 'id': 'eRvTLPON'}
{"return": {}, "id": "eRvTLPON"}
{'execute': 'device_del', 'arguments': {'id': 'virtio_scsi_pci1'}, 'id': 'ZPrMG8Md'}
{"return": {}, "id": "ZPrMG8Md"} ------> No DEVICE_DELETED event for virtio_scsi_pci1 after 30 min.

And failed to hotplug the device again since "Duplicate ID 'virtio_scsi_pci1' for device.
{'execute': 'blockdev-add', 'arguments': {'node-name': 'file_stg', 'driver': 'file', 'aio': 'threads', 'filename': '/home/kvm_autotest_root/images/stg.qcow2', 'cache': {'direct': true, 'no-flush': false}}, 'id': 'BVpMEXJy'}
{"return": {}, "id": "BVpMEXJy"}
{'execute': 'blockdev-add', 'arguments': {'node-name': 'drive_stg', 'driver': 'qcow2', 'cache': {'direct': true, 'no-flush': false}, 'file': 'file_stg'}, 'id': 'fIsU5L6M'}
{"return": {}, "id": "fIsU5L6M"}
{"execute": "device_add", "arguments": {"id": "virtio_scsi_pci1", "driver": "virtio-scsi-pci", "bus": "pcie_extra_root_port_0", "addr": "0x0"}, "id": "E0GPZKDS"}
{"id": "E0GPZKDS", "error": {"class": "GenericError", "desc": "Duplicate ID 'virtio_scsi_pci1' for device"}}

(In reply to Yongxue Hong from comment #45)
> Virtio-scsi also has the same issue.
> 
> qemu version: qemu-kvm-5.0.0-0.scrmod+el8.3.0+6977+09119430.wrb200610
> Guest OS: Windows 2019
> 
> Boot a guest:
> /usr/libexec/qemu-kvm \
>     -name 'avocado-vt-vm1'  \
>     -sandbox on  \
>     -machine q35 \

This bug is for pc machine type, not q35. Please create a new bug for q35, if it doesn't already exist under bug 1744438.

Best regards, Julia Suvorova.

Seems like it wasn't possible to reproduce the issue on pc since comment 1.

Since there is no similar bugs associated with pci hotplug on pc and no
evidence of incorrect QEMU behaviour (conclusion of comment 9 and comment 23),
we can close this one if it is no longer reproducible.

Qing, can you please check if this bug is possible to reproduce with pc machine type?

This issue is not easy to reproduce, but it still exist.
It may be reproduced via repeatly hotplug-unplug case, The failure rate is 10%.


Red Hat Enterprise Linux release 8.3 (Ootpa)
4.18.0-240.el8.x86_64
qemu-kvm-common-4.2.0-34.module+el8.3.0+7976+077be4ec.x86_64
Red Hat Enterprise Linux release 8.2 (Ootpa)
4.18.0-193.el8.x86_64
qemu-kvm-common-4.2.0-29.module+el8.2.1+7297+a825794d.x86_64
virtio-win-prewhql-0.1-189.iso
Guest:win2019

python ConfigTest.py --testcase=block_hotplug.block_virtio.fmt_qcow2.default.with_plug.with_repetition.one_pci.i440fx --iothread_scheme=roundrobin --nr_iothreads=2 --platform=x86_64 --guestname=Win2019 --driveformat=virtio_blk,virtio_scsi --nicmodel=virtio_net --imageformat=qcow2 --machines=i440fx --customsparams="qemu_force_use_drive_expression = no\nimage_aio=threads\ncd_format=ide"  --nrepeat=20

Log:
http://fileshare.englab.nay.redhat.com/pub/section2/images_backup/qbugs/1678290/2020-11-06-0021/07-repeat4.Host_RHEL.m8.u3.product_rhel.qcow2.virtio_blk.up.virtio_net.Guest.Win2019.x86_64.io-github-autotest-qemu.block_hotplug.block_virtio.fmt_qcow2.with_plug.with_repetition.one_pci/

Maybe this issue related to guest. same operation have no issue on Linux guest.

hit the same issue on win10-32 guest

pkg version:
qemu-kvm-5.1.0-15.module+el8.3.1+8772+a3fdeccd.x86_64
kernel-4.18.0-240.el8.x86_64
seabios-1.14.0-1.module+el8.3.0+7638+07cf13d2.x86_64
virtio-win-prewhql-0.1-191.iso

I hit similar issue when do unplug balloon device under q35 machine type on win2012，win8.1-32,win10-32 guest and tried 10 times per guest but couldn't reproduce.

pkg version:
qemu-kvm-5.1.0-15.module+el8.3.1+8772+a3fdeccd.x86_64
kernel-4.18.0-240.el8.x86_64
seabios-1.14.0-1.module+el8.3.0+7638+07cf13d2.x86_64
virtio-win-prewhql-0.1-191.iso

After evaluating this issue, there are no plans to address it further or fix it in an upcoming release.  Therefore, it is being closed.  If plans change such that this issue will be fixed in an upcoming release, then the bug can be reopened.

Hi all,

After confirmed with qingwang, we prefer to reopen this bz. because it's hit lots of times, please let us know if you have any ideas about it.
Thanks
Dehan Meng

q35 issue is tracked by Bug 1856678 - [q35] No "DEVICE_DELETED" event in qmp after "device_del" virtio-blk-pci

This issue is not easy to reproduce, but it still exist.
It may be reproduced via repeatly hotplug-unplug case, The failure rate is 10%.


Red Hat Enterprise Linux release 8.5 Beta (Ootpa)
4.18.0-315.el8.x86_64
qemu-kvm-common-4.2.0-52.module+el8.5.0+11386+ef5875dd.x86_64
edk2-ovmf-20200602gitca407c7246bf-5.el8.noarch
virtio-win-prewhql-0.1-202.iso

Guest:win2019




python ConfigTest.py --testcase=block_hotplug.block_virtio.fmt_qcow2.default.with_plug.with_repetition.one_pci.i440fx --iothread_scheme=roundrobin --nr_iothreads=2 --platform=x86_64 --guestname=Win2019 --driveformat=virtio_blk,virtio_scsi --nicmodel=virtio_net --imageformat=qcow2 --machines=i440fx --customsparams="qemu_force_use_drive_expression = no\nimage_aio=threads\ncd_format=ide"  --nrepeat=20

Log: http://fileshare.englab.nay.redhat.com/pub/section2/images_backup/qbugs/1678290/2021-06-27

Maybe this issue related to guest. same operation have no issue on Linux guest.

After evaluating this issue, there are no plans to address it further or fix it in an upcoming release.  Therefore, it is being closed.  If plans change such that this issue will be fixed in an upcoming release, then the bug can be reopened.

QE agree to close. New bug will be created if hit it again.