Bug 1677105

for machine type:pc, don't have this issue.

Hit this issue by automation. Not hit it on linux guest.


Details:

Host:
kernel-3.10.0-1009.el7.x86_64
qemu-kvm-rhev-2.12.0-23.el7
spice-server-0.14.0-6.el7.x86_64
seabios-bin-1.11.0-2.el7.noarch
seavgabios-bin-1.11.0-2.el7.noarch

Guest:
windows10 x86_64
virtio-win-prewhql-0.1-163.iso


auto cmd lines:
python 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=Win10 --driveformat=virtio_scsi --nicmodel=virtio_net --platform=x86_64 --clone=yes --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_YO9hUp/monitor-qmpmonitor1-20190222-023950-hEeRk4hO,server,nowait \
    -mon chardev=qmp_id_qmpmonitor1,mode=control  \
    -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/avocado_YO9hUp/monitor-catch_monitor-20190222-023950-hEeRk4hO,server,nowait \
    -mon chardev=qmp_id_catch_monitor,mode=control \
    -device pvpanic,ioport=0x505,id=idGIrlXB  \
    -chardev socket,id=serial_id_serial0,path=/var/tmp/avocado_YO9hUp/serial-serial0-20190222-023950-hEeRk4hO,server,nowait \
    -device isa-serial,chardev=serial_id_serial0  \
    -chardev socket,id=seabioslog_id_20190222-023950-hEeRk4hO,path=/var/tmp/avocado_YO9hUp/seabios-20190222-023950-hEeRk4hO,server,nowait \
    -device isa-debugcon,chardev=seabioslog_id_20190222-023950-hEeRk4hO,iobase=0x402 \
    -device nec-usb-xhci,id=usb1,bus=pci.0,addr=0x3 \
    -device virtio-scsi-pci,id=virtio_scsi_pci0,bus=pci.0,addr=0x4 \
    -drive id=drive_image1,if=none,snapshot=off,aio=threads,cache=none,format=qcow2,file=/home/kvm_autotest_root/images/win10-64-virtio-scsi.qcow2 \
    -device scsi-hd,id=image1,drive=drive_image1,bootindex=0 \
    -device virtio-net-pci,mac=9a:30:31:32:33:34,id=idXbpfQY,vectors=4,netdev=id73430R,bus=pci.0,addr=0x5  \
    -netdev tap,id=id73430R,vhost=on,vhostfd=20,fd=19 \
    -m 15360  \
    -smp 12,maxcpus=12,cores=6,threads=1,sockets=2  \
    -cpu 'Westmere',+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 menu=off,strict=off,order=cdn,once=c \
    -enable-kvm \
    -monitor stdio \



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

e.g. (should revice below message)
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:

{"execute": "device_del", "arguments": {"id": "stg1"}, "id": "66pzh8b6"}
{"return": {}, "id": "66pzh8b6"}
{"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 all hit this issue.

(In reply to Xueqiang Wei from comment #4)
> Hit this issue by automation. Not hit it on linux guest.

Are the automation scripts umount the disks before trying to remove them using the "device_del" command? Because the device_del command should fail if the device is in use.

(In reply to Gal Hammer from comment #5)
> (In reply to Xueqiang Wei from comment #4)
> > Hit this issue by automation. Not hit it on linux guest.
> 
> Are the automation scripts umount the disks before trying to remove them
> using the "device_del" command? Because the device_del command should fail
> if the device is in use.


No, in guest don't umount disk before unplug it. I think that's OK. Unplug disk may fail when doing i/o. In this case, unplug disk after the i/o operation has completed. And I confirmed with virtio-win team, they also don't umount disk before unplug it. Is it necessary before unplug disk by "device_del" ?


The difference between linux guest and windows in this case:

linux: unplug disk after dd test

dd if=/dev/vda of=/dev/null bs=1k count=1000 iflag=direct && dd if=/dev/zero of=/dev/vda bs=1k count=1000 oflag=direct
dd if=/dev/vdb of=/dev/null bs=1k count=1000 iflag=direct && dd if=/dev/zero of=/dev/vdb bs=1k count=1000 oflag=direct


windows: unplug disk after iozone test 

D:\Iozone\iozone.exe -azR -r 64k -n 125M -g 512M -M -i 0 -i 1 -b I:\iozone_test -f I:\testfile
D:\Iozone\iozone.exe -azR -r 64k -n 125M -g 512M -M -i 0 -i 1 -b J:\iozone_test -f J:\testfile

Do not umount I and J, then unplug disk by "device_del"

(In reply to Xueqiang Wei from comment #6)
> (In reply to Gal Hammer from comment #5)
> > (In reply to Xueqiang Wei from comment #4)
> > > Hit this issue by automation. Not hit it on linux guest.
> > 
> > Are the automation scripts umount the disks before trying to remove them
> > using the "device_del" command? Because the device_del command should fail
> > if the device is in use.
> 
> 
> No, in guest don't umount disk before unplug it. I think that's OK. Unplug
> disk may fail when doing i/o. In this case, unplug disk after the i/o
> operation has completed. And I confirmed with virtio-win team, they also
> don't umount disk before unplug it. Is it necessary before unplug disk by
> "device_del" ?
> 
> 
> The difference between linux guest and windows in this case:
> 
> linux: unplug disk after dd test
> 
> dd if=/dev/vda of=/dev/null bs=1k count=1000 iflag=direct && dd if=/dev/zero
> of=/dev/vda bs=1k count=1000 oflag=direct
> dd if=/dev/vdb of=/dev/null bs=1k count=1000 iflag=direct && dd if=/dev/zero
> of=/dev/vdb bs=1k count=1000 oflag=direct
> 
> 
> windows: unplug disk after iozone test 
> 
> D:\Iozone\iozone.exe -azR -r 64k -n 125M -g 512M -M -i 0 -i 1 -b
> I:\iozone_test -f I:\testfile
> D:\Iozone\iozone.exe -azR -r 64k -n 125M -g 512M -M -i 0 -i 1 -b
> J:\iozone_test -f J:\testfile
> 
> Do not umount I and J, then unplug disk by "device_del"

So what you describe here are two different tests. On Linux you don't mount the disk and work directly with the block device (e.g. /dev/vda) while on Windows it appears that the disk is mounted (=have an assigned a driver letter) and the test is running on a file.

A PCI device can't be unplugged without the guest operating system approval. So Windows might ignore the device removal request because the disk is still in use. To test that you can try to unplug the device in Linux while the dd test is still running or make sure the disk is umounted (mountvol command, I think) on Windows after the iozone test is completed.

(In reply to Gal Hammer from comment #7)
> (In reply to Xueqiang Wei from comment #6)
> > (In reply to Gal Hammer from comment #5)
> > > (In reply to Xueqiang Wei from comment #4)
> > > > Hit this issue by automation. Not hit it on linux guest.
> > > 
> > > Are the automation scripts umount the disks before trying to remove them
> > > using the "device_del" command? Because the device_del command should fail
> > > if the device is in use.
> > 
> > 
> > No, in guest don't umount disk before unplug it. I think that's OK. Unplug
> > disk may fail when doing i/o. In this case, unplug disk after the i/o
> > operation has completed. And I confirmed with virtio-win team, they also
> > don't umount disk before unplug it. Is it necessary before unplug disk by
> > "device_del" ?
> > 
> > 
> > The difference between linux guest and windows in this case:
> > 
> > linux: unplug disk after dd test
> > 
> > dd if=/dev/vda of=/dev/null bs=1k count=1000 iflag=direct && dd if=/dev/zero
> > of=/dev/vda bs=1k count=1000 oflag=direct
> > dd if=/dev/vdb of=/dev/null bs=1k count=1000 iflag=direct && dd if=/dev/zero
> > of=/dev/vdb bs=1k count=1000 oflag=direct
> > 
> > 
> > windows: unplug disk after iozone test 
> > 
> > D:\Iozone\iozone.exe -azR -r 64k -n 125M -g 512M -M -i 0 -i 1 -b
> > I:\iozone_test -f I:\testfile
> > D:\Iozone\iozone.exe -azR -r 64k -n 125M -g 512M -M -i 0 -i 1 -b
> > J:\iozone_test -f J:\testfile
> > 
> > Do not umount I and J, then unplug disk by "device_del"
> 
> So what you describe here are two different tests. On Linux you don't mount
> the disk and work directly with the block device (e.g. /dev/vda) while on
> Windows it appears that the disk is mounted (=have an assigned a driver
> letter) and the test is running on a file.
> 
> A PCI device can't be unplugged without the guest operating system approval.
> So Windows might ignore the device removal request because the disk is still
> in use. To test that you can try to unplug the device in Linux while the dd
> test is still running or make sure the disk is umounted (mountvol command, I
> think) on Windows after the iozone test is completed.


I will try unplug disk after umounted it on Windows.  I am confused about why unplug virtio-scsi disk without umount disk works well, but unplug virtio-blk disk without umount disk can not work randomly (unplug successfully some times). They should have the same behavior.

https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c3
https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c5

(In reply to Xueqiang Wei from comment #8)

> I will try unplug disk after umounted it on Windows.  I am confused about
> why unplug virtio-scsi disk without umount disk works well, but unplug
> virtio-blk disk without umount disk can not work randomly (unplug
> successfully some times). They should have the same behavior.
> 
> https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c3
> https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c5

Thanks, I'm waiting for updates.

Bug 1523017 claims that both virtio-scsi and virtio-blk might fail when trying to unplug the device. The unplug process depends on the guest operating system and Windows doesn't allow to unplug a device while the device is in use. When the test randomly fails, it seems like a case where the VM wasn't fast enough to complete all pending io requests before it received the unplug request.

(In reply to Gal Hammer from comment #9)
> (In reply to Xueqiang Wei from comment #8)
> 
> > I will try unplug disk after umounted it on Windows.  I am confused about
> > why unplug virtio-scsi disk without umount disk works well, but unplug
> > virtio-blk disk without umount disk can not work randomly (unplug
> > successfully some times). They should have the same behavior.
> > 
> > https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c3
> > https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c5
> 
> Thanks, I'm waiting for updates.
> 
> Bug 1523017 claims that both virtio-scsi and virtio-blk might fail when
> trying to unplug the device. The unplug process depends on the guest
> operating system and Windows doesn't allow to unplug a device while the
> device is in use. When the test randomly fails, it seems like a case where
> the VM wasn't fast enough to complete all pending io requests before it
> received the unplug request.


Unplug disk after umount it on Windows10. also hit this issue.

1. umount disk I, J
 mountvol I: /D
 mountvol J: /D

2. unplug disk stg1, stg0
{'execute': 'device_del', 'arguments': {'id': 'stg1'}
{'execute': 'device_del', 'arguments': {'id': 'stg0'}

after 2,
unplug disk stg1 successfully and receive "DEVICE_DELETED" event
unplug disk stg0 unsuccessfully and not receive "DEVICE_DELETED" event


logs:

07:58:52 INFO | --------umount disk I
07:58:52 DEBUG| Sending command: mountvol I: /D
07:58:52 DEBUG| Sending command: echo %errorlevel%
07:58:53 INFO | --------umount disk J
07:58:53 DEBUG| Sending command: mountvol J: /D
07:58:53 DEBUG| Sending command: echo %errorlevel%
07:58:53 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'device_del'
07:58:53 DEBUG| Send command: {'execute': 'device_del', 'arguments': {'id': 'stg1'}, 'id': 'DJyY0G91'}
07:58:55 DEBUG| STREAM b'IHDR' 16 13
07:58:55 DEBUG| STREAM b'IDAT' 41 1216
07:59:00 DEBUG| STREAM b'IHDR' 16 13
07:59:00 DEBUG| STREAM b'IDAT' 41 1216
07:59:04 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'device_del'
07:59:04 DEBUG| Send command: {'execute': 'device_del', 'arguments': {'id': 'stg0'}, 'id': 'TZNsUHyi'}
08:00:42 ERROR| avocado.core.exceptions.TestFail: Failed to unplug device 'stg0'.Output:
08:00:42 ERROR| {}

(In reply to Xueqiang Wei from comment #10)
> (In reply to Gal Hammer from comment #9)
> > (In reply to Xueqiang Wei from comment #8)
> > 
> > > I will try unplug disk after umounted it on Windows.  I am confused about
> > > why unplug virtio-scsi disk without umount disk works well, but unplug
> > > virtio-blk disk without umount disk can not work randomly (unplug
> > > successfully some times). They should have the same behavior.
> > > 
> > > https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c3
> > > https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c5
> > 
> > Thanks, I'm waiting for updates.
> > 
> > Bug 1523017 claims that both virtio-scsi and virtio-blk might fail when
> > trying to unplug the device. The unplug process depends on the guest
> > operating system and Windows doesn't allow to unplug a device while the
> > device is in use. When the test randomly fails, it seems like a case where
> > the VM wasn't fast enough to complete all pending io requests before it
> > received the unplug request.
> 
> 
> Unplug disk after umount it on Windows10. also hit this issue.
> 
> 1. umount disk I, J
>  mountvol I: /D
>  mountvol J: /D

Can you please try with "mountvol I: /P"?
 
> 2. unplug disk stg1, stg0
> {'execute': 'device_del', 'arguments': {'id': 'stg1'}
> {'execute': 'device_del', 'arguments': {'id': 'stg0'}
> 
> after 2,
> unplug disk stg1 successfully and receive "DEVICE_DELETED" event
> unplug disk stg0 unsuccessfully and not receive "DEVICE_DELETED" event
> 
> 
> logs:
> 
> 07:58:52 INFO | --------umount disk I
> 07:58:52 DEBUG| Sending command: mountvol I: /D
> 07:58:52 DEBUG| Sending command: echo %errorlevel%

Is it possible to see the results of the commands? How can you tell from this log if the mountvol was even executed?

> 07:58:53 INFO | --------umount disk J
> 07:58:53 DEBUG| Sending command: mountvol J: /D
> 07:58:53 DEBUG| Sending command: echo %errorlevel%
> 07:58:53 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command
> 'device_del'
> 07:58:53 DEBUG| Send command: {'execute': 'device_del', 'arguments': {'id':
> 'stg1'}, 'id': 'DJyY0G91'}
> 07:58:55 DEBUG| STREAM b'IHDR' 16 13
> 07:58:55 DEBUG| STREAM b'IDAT' 41 1216
> 07:59:00 DEBUG| STREAM b'IHDR' 16 13
> 07:59:00 DEBUG| STREAM b'IDAT' 41 1216
> 07:59:04 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command
> 'device_del'
> 07:59:04 DEBUG| Send command: {'execute': 'device_del', 'arguments': {'id':
> 'stg0'}, 'id': 'TZNsUHyi'}
> 08:00:42 ERROR| avocado.core.exceptions.TestFail: Failed to unplug device
> 'stg0'.Output:
> 08:00:42 ERROR| {}

 
> Can you please try with "mountvol I: /P"?

try with "mountvol I: /P", also hit this issue.

> Is it possible to see the results of the commands? How can you tell from
> this log if the mountvol was even executed?

Get drive letter before and after unmount disk.
And if command "mountvol" failed, the program will exit and prompt message. 


logs:

03:29:52 DEBUG| Sending mmand: wmic logicaldisk where "drivetype=3" get name
03:29:53 INFO | before unmount disk: 
Name
C:
I:
J:
S:

03:29:53 INFO | --------umount disk I
03:29:53 DEBUG| Sending command: mountvol I: /P
03:29:53 DEBUG| Sending command: echo %errorlevel%
03:29:53 DEBUG| Sending command: wmic logicaldisk where "drivetype=3" get name
03:29:53 INFO | after unmount disk: 
Name
C:
J:
S:

03:29:53 DEBUG| Sending command: wmic logicaldisk where "drivetype=3" get name
03:29:54 INFO | before unmount disk: 
Name
C:
J:
S:

03:29:54 INFO | --------umount disk J
03:29:54 DEBUG| Sending command: mountvol J: /P
03:29:54 DEBUG| Sending command: echo %errorlevel%
03:29:54 DEBUG| Sending command: wmic logicaldisk where "drivetype=3" get name
03:29:55 INFO | after unmount disk: 
Name
C:
S:

03:29:55 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'device_del'
03:29:55 DEBUG| Send command: {'execute': 'device_del', 'arguments': {'id': 'stg1'}, 'id': '6o6Nsy7C'}
03:29:58 DEBUG| STREAM b'IHDR' 16 13
03:29:58 DEBUG| STREAM b'IDAT' 41 1216
03:30:04 DEBUG| STREAM b'IHDR' 16 13
03:30:04 DEBUG| STREAM b'IDAT' 41 1216
03:30:06 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'device_del'
03:30:06 DEBUG| Send command: {'execute': 'device_del', 'arguments': {'id': 'stg0'}, 'id': 'r3UHrxkZ'}
03:30:37 ERROR| avocado.core.exceptions.TestFail: Failed to unplug device 'stg0'.Output:
03:30:37 ERROR| {}

NB: Since Gal got assigned bz 1678290, I've reassigned this and bz 1678311 to him in order to keep the 3 bugs "together" (similarly altered the priority as well).

It seems that the two unrelated(?) commits 3d2fc923ecab and aff39be0ed97 for correct reference counting solve this issue.

Xueqiang? Can you please verify it as well? Thanks.

(In reply to Gal Hammer from comment #15)
> It seems that the two unrelated(?) commits 3d2fc923ecab and aff39be0ed97 for
> correct reference counting solve this issue.
> 
> Xueqiang? Can you please verify it as well? Thanks.


According to https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c1, retested on upstream qemu with commits 3d2fc923ecab and aff39be0ed97, also hit this issue.


Details:

Host:
kernel-4.18.0-85.el8.x86_64
QEMU emulator version 4.0.50 (upstream-474f3938d79ab36b9231c9ad3b5a9314c2aeacde)

it contains below two commits:

commit 3d2fc923ecab576db1b398c565816e54b73f4a2d
Author: Philippe Mathieu-Daudé <philmd>
Date:   Tue May 7 18:34:03 2019 +0200

    hw/virtio: Use object_initialize_child for correct reference counting
    
    As explained in commit aff39be0ed97:
   ......

commit aff39be0ed9753c9c323f64a14f5533dd5c43525
Author: Thomas Huth <thuth>
Date:   Tue Apr 30 21:15:52 2019 +0200

    hw/pci-host: Use object_initialize_child for correct reference counting
    
    Both functions, object_initialize() and object_property_add_child() increase
    the reference counter of the new object, so one of the references has to be
    dropped afterwards to get the reference counting right. Otherwise the child
    object might not be properly cleaned up when the parent gets destroyed.
    Some functions of the pci-host devices miss to drop one of the references.
    Fix it by using object_initialize_child() instead, which takes care of
    calling object_initialize(), object_property_add_child() and object_unref()
    in the right order.
    
    Suggested-by: Eduardo Habkost <ehabkost>
    Message-Id: <20190430191552.4027-1-thuth>
    Reviewed-by: Philippe Mathieu-Daudé <philmd>
    Tested-by: Philippe Mathieu-Daudé <philmd>
    Signed-off-by: Thomas Huth <thuth>


Guest:
win2019 with virtio-win-prewhql-0.1-171.iso



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


logs:

2019-06-24 19:08:37: {"execute": "device_del", "arguments": {"id": "stg1"}, "id": "qXNhVE25"}
2019-06-24 19:08:37: {"return": {}, "id": "qXNhVE25"}
2019-06-24 19:08:38: {"execute": "human-monitor-command", "arguments": {"command-line": "info qtree"}, "id": "uEOnpZrQ"}


stg1 in qtree,

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

Thanks for the testing. I'm not sure but I think my setup doesn't include a scsi-hd device and I just tested for the virtio-scsi pci device unplug. I'll check again and update when I'll have some more information.

Maybe related comment from Vadim here: https://bugzilla.redhat.com/show_bug.cgi?id=1706759#c13

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

Related comment from Markus here: https://bugzilla.redhat.com/show_bug.cgi?id=1678290#c9