There are many ways to attach a CD image from ISO domain to VM: from admin portal, user portal, remote-viewer, rest-api, etc... RHEL VMs sometime cannot correctly process second/third/... cd change. ovirt-engine-4.1.1.2-0.1.el7.noarch How reproducible: 30% Steps to Reproduce: 1. Connect to RHEL VM with remote-viewer. 2. Attach to VM any CD from ISO domain. 3. Make sure you can use attached CD. 4. Change CD from web-portal or remote-viewer. RHEL displays contents for old CD. As well as, there is more serious problem: oVirt disconnects CD from VM for "Eject" selection, but Gnome continue displays CD as attached.
Created attachment 1259227 [details] ovirt log while changing CD
Created attachment 1259228 [details] CD contents As you can see, there is attached CD with Guest-Tools-4.1-3. But it displays some Chinese characters for this CD.
Created attachment 1259244 [details] attached CD with RHV guest tools on RHEL74 guest
CD eject on real hardware produces next udev events: # udevadm monitor KERNEL[87037.919843] change /devices/pci0000:00/0000:00:17.0/ata3/host2/target2:0:0/2:0:0:0/block/sr0 (block) UDEV [87041.790090] change /devices/pci0000:00/0000:00:17.0/ata3/host2/target2:0:0/2:0:0:0/block/sr0 (block) KERNEL[87041.800709] change /devices/pci0000:00/0000:00:17.0/ata3/host2/target2:0:0/2:0:0:0/block/sr0 (block) UDEV [87041.887042] change /devices/pci0000:00/0000:00:17.0/ata3/host2/target2:0:0/2:0:0:0/block/sr0 (block) VM for CD eject shows nothing for: # udevadm monitor Moreover, as CD was ejected udev thinks that CD is present: # udevadm info -e | grep -i MEDIA E: ID_CDROM_MEDIA=1 E: ID_CDROM_MEDIA_CD=1 E: ID_CDROM_MEDIA_SESSION_COUNT=1 E: ID_CDROM_MEDIA_TRACK_COUNT=1 E: ID_CDROM_MEDIA_TRACK_COUNT_DATA=1
I think a VDSM log is more relevant here, to ensure the CD was ejected / attached. Are you sure it's not a RHEL bug?
Created attachment 1259585 [details] Log from vdsm actions: 1. Attach "RHEV-toolsSetup_4.1_3.iso" 2. Detach it 3. Attach "RHEV-toolsSetup_4.0_6.iso" 2. Detach it There is no "eject" action. UDEV thinks that CD is attached. Why would it be RHEL bug?
Are you sure? From your VDSM log: Insert 4.1.3 ISO: 2017-03-03 17:14:43,796+0100 INFO (jsonrpc/5) [vdsm.api] START changeCD args=(<virt.vm.Vm object at 0x3be27d0>, {u'path': u'/rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9-03b6c2c93fba/images/ 11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.1_3.iso', u'iface': u'ide', u'index': u'2'}) kwargs={} (api:37) Done: 2017-03-03 17:14:43,818+0100 INFO (jsonrpc/5) [vdsm.api] FINISH changeCD return={'status': {'message': 'Done', 'code': 0}, 'vmList': {'cdrom': u'/rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9 -03b6c2c93fba/images/11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.1_3.iso' Eject: 2017-03-03 17:14:48,067+0100 INFO (jsonrpc/7) [vdsm.api] START changeCD args=(<virt.vm.Vm object at 0x3be27d0>, {u'path': u'', u'iface': u'ide', u'index': u'2'}) kwargs={} (api:37) 2017-03-03 17:14:48,068+0100 INFO (jsonrpc/7) [vds] prepared volume path: (clientIF:374) 2017-03-03 17:14:48,075+0100 INFO (jsonrpc/7) [vdsm.api] FINISH changeCD return={'status': {'message': 'Done', 'code': 0}, 'vmList': {'cdrom': u'', Insert 4.0.6 ISO: 2017-03-03 17:14:52,259+0100 INFO (jsonrpc/2) [vdsm.api] START changeCD args=(<virt.vm.Vm object at 0x3be27d0>, {u'path': u'/rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9-03b6c2c93fba/images/11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.0_6.iso', u'iface': u'ide', u'index': u'2'}) kwargs={} (api:37) 2017-03-03 17:14:52,261+0100 INFO (jsonrpc/2) [vds] prepared volume path: /rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9-03b6c2c93fba/images/11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.0_6.iso (clientIF:374) 2017-03-03 17:14:52,277+0100 INFO (jsonrpc/2) [vdsm.api] FINISH changeCD return={'status': {'message': 'Done', 'code': 0}, 'vmList': {'cdrom': u'/rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9-03b6c2c93fba/images/11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.0_6.iso', Eject: 2017-03-03 17:14:55,429+0100 INFO (jsonrpc/6) [vdsm.api] START changeCD args=(<virt.vm.Vm object at 0x3be27d0>, {u'path': u'', u'iface': u'ide', u'index': u'2'}) kwargs={} (api:37) 2017-03-03 17:14:55,430+0100 INFO (jsonrpc/6) [vds] prepared volume path: (clientIF:374) 2017-03-03 17:14:55,437+0100 INFO (jsonrpc/6) [vdsm.api] FINISH changeCD return={'status': {'message': 'Done', 'code': 0}, 'vmList': {'cdrom': u'',
Yes, I am. Please run on RHEL guest: # udevadm monitor Eject CD. There will be no event for eject. Guest doesn't know that CD was ejected.
(In reply to Andrei Stepanov from comment #8) > Yes, I am. > > Please run on RHEL guest: > > # udevadm monitor > > Eject CD. There will be no event for eject. Guest doesn't know that CD was > ejected. OK, so now, please enable libvirt in debug - let's make sure the event reaches libvirt (perhaps it's already in libvirt's qemu logs? Check first). VDSM does it job here - so it's the next layer.
diff -uN cd.txt ejected.txt --- cd.txt 2017-03-03 18:04:40.751496759 +0100 +++ ejected.txt 2017-03-03 18:04:53.541666651 +0100 @@ -49,11 +49,8 @@ <emulator>/usr/libexec/qemu-kvm</emulator> <disk type='file' device='cdrom'> <driver name='qemu' type='raw'/> - <source file='/rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9-03b6c2c93fba/images/11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.1_3.iso'> - <seclabel model='selinux' labelskip='yes'/> - </source> <backingStore/> - <target dev='hdc' bus='ide'/> + <target dev='hdc' bus='ide' tray='open'/> <readonly/> <alias name='ide0-1-0'/> <address type='drive' controller='0' bus='1' target='0' unit='0'/>
[root@hyper04 ~]# virsh qemu-monitor-command --hmp POOL-RHEL-7.4-20170227.n.0-2 'info block -n -v' > cd1.txt test [root@hyper04 ~]# virsh qemu-monitor-command --hmp POOL-RHEL-7.4-20170227.n.0-2 'info block -n -v' > eject1.txt test [root@hyper04 ~]# diff -uN cd1.txt eject1.txt --- cd1.txt 2017-03-03 18:15:49.334337089 +0100 +++ eject1.txt 2017-03-03 18:16:08.032584126 +0100 @@ -1,22 +1,4 @@ -Please enter your authentication name: Please enter your password: #block2949: /rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9-03b6c2c93fba/images/11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.1_3.iso (raw, read-only) - Cache mode: writeback - -Images: -image: /rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9-03b6c2c93fba/images/11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.1_3.iso -file format: raw -virtual size: 508M (532215808 bytes) -disk size: 508M - -#block2840: /rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9-03b6c2c93fba/images/11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.1_3.iso (file, read-only) - Cache mode: writeback - -Images: -image: /rhev/data-center/mnt/10.34.73.3:_nfs_iso/b85e609a-c9dc-4d14-bfd9-03b6c2c93fba/images/11111111-1111-1111-1111-111111111111/RHEV-toolsSetup_4.1_3.iso -file format: file -virtual size: 508M (532215808 bytes) -disk size: 508M - -#block510: /rhev/data-center/00000001-0001-0001-0001-000000000311/325d0826-e9a1-470a-a5f5-3253e3e2f8c1/images/9f5003a8-88ca-4f4b-9047-85f097cdea6b/13fa3f2b-009e-4a99-8d99-f9eb5a1d795e (qcow2, read-only) +Please enter your authentication name: Please enter your password: #block510: /rhev/data-center/00000001-0001-0001-0001-000000000311/325d0826-e9a1-470a-a5f5-3253e3e2f8c1/images/9f5003a8-88ca-4f4b-9047-85f097cdea6b/13fa3f2b-009e-4a99-8d99-f9eb5a1d795e (qcow2, read-only) Cache mode: writeback, direct Images:
So even libvirt seems to be doing its work. Good - so now, you are left with 2 components - qemu-kvm or the platform itself. Neither are RHV. I'd start with libvirt in debug to try and see the QMP events from qemu-kvm first.
Yaniv Kaul: could you please provide me a command? By the way, I am sure that bug doesn't require any special setup. It is easy reproduce on any RHV installation. There is no event for CD eject in udev.
(In reply to Andrei Stepanov from comment #13) > Yaniv Kaul: could you please provide me a command? Setting NEEDINFO to RHV QE, who can assist here. > > By the way, I am sure that bug doesn't require any special setup. > It is easy reproduce on any RHV installation. you are probably right. > > There is no event for CD eject in udev.
virsh reports cd as changed/ejected correctly Inside RHEL host it's changed as well. When I umount it after checking content, change cd and mount again, new cd is mounted. When I don't umount the cd and change/eject cd, I can see the content (but can't access it) of the old one, I'm able to mount new one and access it, umount on the old one works as well. This might be some issue in gnome itself, definitely not in RHEL or RHV
So please move from RHV
is it not the same as https://bugzilla.redhat.com/show_bug.cgi?id=1426724 ?
> Tomas Jelinek 2017-03-08 04:40:59 EST > is it not the same as https://bugzilla.redhat.com/show_bug.cgi?id=1426724 ? It is a different bug. > Yaniv Kaul 2017-03-08 04:33:29 EST > So please move from RHV. Do you have a hint which product should I choose? qemu / kernel / systemd-udev ?
You mentioned having gnome, so I would try that product. Since I have RHEL 7.3 without desktop environment where everything works as expected.
Petr Matyáš > You mentioned having gnome, so I would try that product. Since I have RHEL 7.3 without desktop environment where everything works as expected. can you confirm that: # udevadm monitor shows events for CD-eject action? udev must show/register events for CD-eject action.
On another look I found out that udevadm monitor doesn't register eject cd, only change cd. However the ejected cd is not usable so this should mean a bug in udev.
This bug is reproducible for RHEL6 guest. RHEL6 doesn't have /usr/lib/systemd/systemd-udevd. I would try to move this bug to qemu.
(In reply to Andrei Stepanov from comment #22) > This bug is reproducible for RHEL6 guest. RHEL6 doesn't have > /usr/lib/systemd/systemd-udevd. I would try to move this bug to qemu. Hi Andrei, KVM QE plan to reproduce this bug. Could you please provide qemu-kvm and libvirt versions? And also upload cd.txt and eject.txt which mentioned in comment 10? Thanks.
qemu-kvm-rhev-2.6.0-28.el7_3.6.x86_64 libvirt-daemon-2.0.0-10.el7_3.5.x86_64
Created attachment 1261875 [details] cd.txt from comment 10
Created attachment 1261876 [details] ejected.txt which was mentioned in comment 10
Reassigning to John Snow, but waiting for QE to reproduce before taking any further steps (comment #24).
(In reply to Petr Matyáš from comment #15) > virsh reports cd as changed/ejected correctly > > Inside RHEL host it's changed as well. > When I umount it after checking content, change cd and mount again, new cd > is mounted. > When I don't umount the cd and change/eject cd, I can see the content (but > can't access it) of the old one, I'm able to mount new one and access it, > umount on the old one works as well. > > This might be some issue in gnome itself, definitely not in RHEL or RHV Based on comment 20 ~ 22, using latest RHEL.6 guest for testing to rule out the possibility of udev problem. QE failed to reproduce this bug on qemu side: qemu-kvm-rhev-2.6.0-28.el7_3.6.x86_64 steps and results are same as comment 15. check cdrom content -> unmount cdrom -> change cd -> mount new cd -> new cd content is right check cdrom content -> (no unmount) change cd -> can not see the content of new cd QMP event for change operation is normal: {"execute":"change","arguments":{"device":"cdrom1","target":"/root/orig.iso"}} {"timestamp": {"seconds": 1490168603, "microseconds": 192832}, "event": "DEVICE_TRAY_MOVED", "data": {"device": "cdrom1", "tray-open": true}} {"timestamp": {"seconds": 1490168603, "microseconds": 192945}, "event": "DEVICE_TRAY_MOVED", "data": {"device": "cdrom1", "tray-open": false}} {"return": {}} before change: # lsof -p 12452 | grep -i iso qemu-kvm 12452 root 19r REG 253,0 3253731328 104184535 /root/orig.iso after change: # lsof -p 12452 | grep -i iso qemu-kvm 12452 root 35r REG 253,0 3793747968 104184533 /root/new.iso Hi John and Ademar, Do you have any ideas or suggestions for this issue? Thanks.
(In reply to CongLi from comment #29) > (In reply to Petr Matyáš from comment #15) > > virsh reports cd as changed/ejected correctly > > > > Inside RHEL host it's changed as well. > > When I umount it after checking content, change cd and mount again, new cd > > is mounted. > > When I don't umount the cd and change/eject cd, I can see the content (but > > can't access it) of the old one, I'm able to mount new one and access it, > > umount on the old one works as well. > > > > This might be some issue in gnome itself, definitely not in RHEL or RHV > > Based on comment 20 ~ 22, using latest RHEL.6 guest for testing to rule out > the possibility of udev problem. > > QE failed to reproduce this bug on qemu side: > qemu-kvm-rhev-2.6.0-28.el7_3.6.x86_64 did not reproduce this bug for more than 20 times
CongLi: I have no advice or suggestions just yet, I still don't understand the problem. Andrei: So if I am understanding correctly, under the original report for this problem, Gnome displays the wrong contents for the CD after a change, but what about the commandline interface? Is that wrong too, or is it just the GUI? In each case, when you are seeing the wrong contents of a CDROM, can you run md5sum in the commandline to force a read and see what happens? --js
(In reply to John Snow from comment #31) First of all, this bug is not about Gnome. Gnome represents state of udisks2 <-> udev. Second, this bug is about oVirt. More precisely this bug is about "CD-eject" in oVirt. oVirt is multi-layered product. As a result, I am not sure which product to chose for this bug. It could be any component on host side: ovirt, libvirt, qemu, etc. This bug should be tested/verified/reproduced on oVirt. > Andrei: So if I am understanding correctly, under the original report for > this problem, Gnome displays the wrong contents for the CD after a change, > but what about the commandline interface? Is that wrong too, or is it just > the GUI? > > In each case, when you are seeing the wrong contents of a CDROM, can you run > md5sum in the commandline to force a read and see what happens? 1. Boot RHEL7 VM. 2. # udevadm info /dev/sr0: E: ID_CDROM=1 E: ID_CDROM_DVD=1 E: ID_CDROM_MRW=1 E: ID_CDROM_MRW_W=1 3. Attach CD to the VM. 4. # udevadm info /dev/sr0: E: ID_CDROM=1 E: ID_CDROM_DVD=1 E: ID_CDROM_MEDIA=1 E: ID_CDROM_MEDIA_CD=1 E: ID_CDROM_MEDIA_SESSION_COUNT=1 E: ID_CDROM_MEDIA_TRACK_COUNT=1 E: ID_CDROM_MEDIA_TRACK_COUNT_DATA=1 E: ID_CDROM_MRW=1 E: ID_CDROM_MRW_W=1 5. # mount | grep sr0 /dev/sr0 on /run/media/test/RHEV-WGT-4.1-4 type iso9660 (ro,nosuid,nodev,relatime,uid=1000,gid=1000,iocharset=utf8,mode=0400,dmode=0500,uhelper=udisks2) 6. # md5sum /run/media/test/RHEV-WGT-4.1-4/RHEV-toolsSetup.exe 50afea8966df3dca5cd68b2a753279fb /run/media/test/RHEV-WGT-4.1-4/RHEV-toolsSetup.exe 7. Detach CD. 8. # udevadm info /dev/sr0: E: ID_CDROM=1 E: ID_CDROM_DVD=1 E: ID_CDROM_MEDIA=1 E: ID_CDROM_MEDIA_CD=1 E: ID_CDROM_MEDIA_SESSION_COUNT=1 E: ID_CDROM_MEDIA_TRACK_COUNT=1 E: ID_CDROM_MEDIA_TRACK_COUNT_DATA=1 E: ID_CDROM_MRW=1 E: ID_CDROM_MRW_W=1 (Please make a notice, that CD has been ejected, but VM thinks it is present). 9. # mount | grep sr0 /dev/sr0 on /run/media/test/RHEV-WGT-4.1-4 type iso9660 (ro,nosuid,nodev,relatime,uid=1000,gid=1000,iocharset=utf8,mode=0400,dmode=0500,uhelper=udisks2) 10. # echo 3 > /proc/sys/vm/drop_caches # (without this MD5 sum is the same.) # md5sum /run/media/test/RHEV-WGT-4.1-4/RHEV-toolsSetup.exe md5sum: /run/media/test/RHEV-WGT-4.1-4/RHEV-toolsSetup.exe: Input/output error 11. dmesg has: [ 1949.391003] bash (1984): drop_caches: 3 [ 1951.562760] sr 2:0:0:0: [sr0] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 1951.563593] sr 2:0:0:0: [sr0] Sense Key : Not Ready [current] [ 1951.564182] sr 2:0:0:0: [sr0] Add. Sense: Medium not present [ 1951.564782] sr 2:0:0:0: [sr0] CDB: Read(10) 28 00 00 00 1e 87 00 00 20 00 [ 1951.565484] blk_update_request: I/O error, dev sr0, sector 31260 [ 1951.576757] sr 2:0:0:0: [sr0] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [ 1951.577577] sr 2:0:0:0: [sr0] Sense Key : Not Ready [current] [ 1951.578157] sr 2:0:0:0: [sr0] Add. Sense: Medium not present [ 1951.578747] sr 2:0:0:0: [sr0] CDB: Read(10) 28 00 00 00 1e 87 00 00 02 00 [ 1951.579449] blk_update_request: I/O error, dev sr0, sector 31260
(In reply to Andrei Stepanov from comment #32) > (In reply to John Snow from comment #31) > > First of all, this bug is not about Gnome. Gnome represents state of udisks2 > <-> udev. > > Second, this bug is about oVirt. More precisely this bug is about "CD-eject" > in oVirt. oVirt is multi-layered product. As a result, I am not sure which > product to chose for this bug. It could be any component on host side: > ovirt, libvirt, qemu, etc. This bug should be tested/verified/reproduced on > oVirt. > Well, maybe it's about oVirt. At the moment it's assigned to me, a QEMU engineer, so I'm trying to understand the visible behavior. > > Andrei: So if I am understanding correctly, under the original report for > > this problem, Gnome displays the wrong contents for the CD after a change, > > but what about the commandline interface? Is that wrong too, or is it just > > the GUI? > > > > In each case, when you are seeing the wrong contents of a CDROM, can you run > > md5sum in the commandline to force a read and see what happens? > > 1. Boot RHEL7 VM. > > 2. # udevadm info /dev/sr0: > E: ID_CDROM=1 > E: ID_CDROM_DVD=1 > E: ID_CDROM_MRW=1 > E: ID_CDROM_MRW_W=1 > > 3. Attach CD to the VM. > > 4. # udevadm info /dev/sr0: > E: ID_CDROM=1 > E: ID_CDROM_DVD=1 > E: ID_CDROM_MEDIA=1 > E: ID_CDROM_MEDIA_CD=1 > E: ID_CDROM_MEDIA_SESSION_COUNT=1 > E: ID_CDROM_MEDIA_TRACK_COUNT=1 > E: ID_CDROM_MEDIA_TRACK_COUNT_DATA=1 > E: ID_CDROM_MRW=1 > E: ID_CDROM_MRW_W=1 > > 5. # mount | grep sr0 > /dev/sr0 on /run/media/test/RHEV-WGT-4.1-4 type iso9660 > (ro,nosuid,nodev,relatime,uid=1000,gid=1000,iocharset=utf8,mode=0400, > dmode=0500,uhelper=udisks2) > > 6. # md5sum /run/media/test/RHEV-WGT-4.1-4/RHEV-toolsSetup.exe > 50afea8966df3dca5cd68b2a753279fb > /run/media/test/RHEV-WGT-4.1-4/RHEV-toolsSetup.exe > > 7. Detach CD. > Can libvirt folks help me translate oVirtese --> Libertese --> QEMUese? How is the CDROM being ejected here from the QMP perspective? Being able to reproduce the behavior without libvirt would of course be a tremendous asset here. > 8. # udevadm info /dev/sr0: > E: ID_CDROM=1 > E: ID_CDROM_DVD=1 > E: ID_CDROM_MEDIA=1 > E: ID_CDROM_MEDIA_CD=1 > E: ID_CDROM_MEDIA_SESSION_COUNT=1 > E: ID_CDROM_MEDIA_TRACK_COUNT=1 > E: ID_CDROM_MEDIA_TRACK_COUNT_DATA=1 > E: ID_CDROM_MRW=1 > E: ID_CDROM_MRW_W=1 > > (Please make a notice, that CD has been ejected, but VM thinks it is > present). > > 9. # mount | grep sr0 > /dev/sr0 on /run/media/test/RHEV-WGT-4.1-4 type iso9660 > (ro,nosuid,nodev,relatime,uid=1000,gid=1000,iocharset=utf8,mode=0400, > dmode=0500,uhelper=udisks2) > > 10. > # echo 3 > /proc/sys/vm/drop_caches # (without this MD5 sum is the same.) > # md5sum /run/media/test/RHEV-WGT-4.1-4/RHEV-toolsSetup.exe > md5sum: /run/media/test/RHEV-WGT-4.1-4/RHEV-toolsSetup.exe: Input/output > error > > 11. dmesg has: > > [ 1949.391003] bash (1984): drop_caches: 3 > [ 1951.562760] sr 2:0:0:0: [sr0] FAILED Result: hostbyte=DID_OK > driverbyte=DRIVER_SENSE > [ 1951.563593] sr 2:0:0:0: [sr0] Sense Key : Not Ready [current] > [ 1951.564182] sr 2:0:0:0: [sr0] Add. Sense: Medium not present > [ 1951.564782] sr 2:0:0:0: [sr0] CDB: Read(10) 28 00 00 00 1e 87 00 00 20 00 > [ 1951.565484] blk_update_request: I/O error, dev sr0, sector 31260 > [ 1951.576757] sr 2:0:0:0: [sr0] FAILED Result: hostbyte=DID_OK > driverbyte=DRIVER_SENSE > [ 1951.577577] sr 2:0:0:0: [sr0] Sense Key : Not Ready [current] > [ 1951.578157] sr 2:0:0:0: [sr0] Add. Sense: Medium not present > [ 1951.578747] sr 2:0:0:0: [sr0] CDB: Read(10) 28 00 00 00 1e 87 00 00 02 00 > [ 1951.579449] blk_update_request: I/O error, dev sr0, sector 31260 OK. looks like the CDROM has been ejected, but the guest failed to notice. Looks like the equivalent of a forced eject. (The VM equivalent of jamming a paperclip in the CDROM tray...) Two thoughts: (1) If libvirt is using a normal eject routine and this eject is occurring without the guest's cooperation, that's a bit of a problem for QEMU. (2) If libvirt is using a force-eject mechanism, the bug is in libvirt or above. Yaniv, can you assist in determining the libvirt->QMP calls made by oVirt in this case? My oVirt knowledge is a bit limited. What would strictly be the most helpful is a log of the QMP transactions during the CDROM change.
Michal - can you assist John here and refer to the exact commands? Andrei running libvirt in debug mode should also help, I reckon.
Created attachment 1266706 [details] libvirtd log of eject CD action
Indeed, it's (2): force-eject. I can see that Vdsm calls virDomainUpdateDeviceFlags with VIR_DOMAIN_DEVICE_MODIFY_FORCE flag, so it's intentional (although not necessarily correct).
OK, in this case I'm moving it back up to RHV/oVirt. Please correct the product/component as needed, thank you. The way force-eject works should be analogous to the way it works for physical devices; if you engage the emergency release mechanism with a paperclip. The ATAPI device does not generate an interrupt or event notifying the guest that there has been a tray event, as the device was in a state that did not permit such events. Not a QEMU bug, thanks!
Thank you for explanation. If I change CD ejection to non-forced in Vdsm, it works fine. Let's fix it there (we may still want to have means to force-eject the CD).
(In reply to Milan Zamazal from comment #38) > Thank you for explanation. If I change CD ejection to non-forced in Vdsm, it > works fine. Let's fix it there (we may still want to have means to > force-eject the CD). Milan - I'd be surprised if there was no good reason why we've force-ejected it so far. I'm also a bit surprised no one has complained about this issue thus far - perhaps a change in behavior on libvirt side?
Hard to say -- the forcing flag has been in Vdsm since Tabula Rasa. I can't see any obvious change in libvirt, but that doesn't mean there is not any. Maybe the forcing flag has some purpose when changing CDs (the call is the same as for ejection). In any case, the currently observed libvirt behavior with ejection makes sense.
*** Bug 1347164 has been marked as a duplicate of this bug. ***
*** Bug 1439603 has been marked as a duplicate of this bug. ***
The reason for force-ejection was apparently https://bugzilla.redhat.com/626334. We believe there is no valid reason to force eject CD by default anymore, so I created fix for that. A different situation is with change CD. I played with it in a RHEL guest OS. As long as nothing accesses the CD at the time it is changed, it seems to work without much trouble in any case. But if something accesses the CD then wild things may happen in both cases. I can't say that "clean" change is superior to forced change or vice versa. In such a situation it's probably safer to retain the current behavior, so I kept the force flag when changing CDs.
I think the safest way of dealing with changing CDs in case of problems is to eject a CD and only then to insert another one, similarly how one would handle a physical CD-ROM drive. I mentioned that in the doc text.
When verifying the bug, please check that: - A CD can be ejected under various circumstances, e.g. when a guest OS process is in the directory and/or some process accesses the files on the CD. - Nothing clearly wrong happens in the guest OS after the CD has been ejected. For instance, previously a cached CD content could be displayed after ejection and IO errors were reported when trying to access the displayed files. - Another CD can be inserted after the ejection and its content can be accessed normally.
Verified on 4.1.2-2 with guest on latest RHEL 7.3
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHEA-2017:1281