Bug 1257119

Created attachment 1067218 [details]
for raw option

virsh blockcopy virt-tests-vm1 vda /dev/sdc  --raw --blockdev
See libvirtd.log.1

Below is the steps to set up the iscsi environment.

Setup iscsi environment:

1. # dd if=/dev/zero of=/tmp/blockdev-iscsi count=10240 bs=1024K
2. # setenforce 0
3. # targetcli /backstores/fileio/ create device.blockdev-iscsi  /tmp/blockdev-iscsi'
4. # targetcli /iscsi/ create iqn.2015-08.com.virttest:blockdev-iscsi.target'
5. # targetcli /iscsi/iqn.2015-08.com.virttest:blockdev-iscsi.target/tpg1/portals ls'
6. # targetcli /iscsi/iqn.2015-08.com.virttest:blockdev-iscsi.target/tpg1/luns/ create /backstores/fileio/device.blockdev-iscsi'
7. # firewall-cmd --state'
Make sure it is not running.
8. # setenforce 1
9. # targetcli /iscsi/iqn.2015-08.com.virttest:blockdev-iscsi.target/tpg1/ set attribute authentication=0 demo_mode_write_protect=0 generate_node_acls=1 cache_dynamic_acls=1
Define access rights:
Parameter demo_mode_write_protect is now '0'.
Parameter authentication is now '0'.
Parameter generate_node_acls is now '1'.
Parameter cache_dynamic_acls is now '1'.

10. # targetcli / saveconfig
 Last 10 configs saved in /etc/target/backup.
 Configuration saved to /etc/target/saveconfig.json

11. Try to update iscsi initiatorname
# mv /etc/iscsi/initiatorname.iscsi /etc/iscsi/initiatorname.iscsi-virt
12. # service iscsid restart
13. # iscsiadm --mode node --login --targetname iqn.2015-08.com.virttest:blockdev-iscsi.target --portal 127.0.0.1
14. Searching iscsi device name
# iscsiadm -m session -P 3
                ************************
                Attached SCSI devices:
                ************************
                Host Number: 9        State: running
                scsi9 Channel 00 Id 0 Lun: 0
                        Attached scsi disk sdc                State: running

15. Create another iscsi disk using step 1 ~ step 10 with 'emulated-iscsi' instead of  'blockdev-iscsi'
16. # qemu-img convert -f qcow2 -O qcow2 /var/lib/virt_test/images/jeos-19-64.qcow2 /tmp/emulated-iscsi

Could this be the qemu bug fixed upstream by:

commit e424aff5f307227b1c2512bbb8ece891bb895cef
Author: Kevin Wolf <kwolf>
Date:   Thu Aug 13 10:41:50 2015 +0200

mirror: Fix coroutine reentrance

Meanwhile, I'm trying to reproduce locally.

It cannot be reproduced if iscsi server is created by tgtd on rhel6. It can be reproduced if iscsi server is created by targetcli on rhel7.

Just test with qemu-kvm directly, hit block job error twice, but not sure it's the same problem.

Host:
3.10.0-314.el7.x86_64
qemu-kvm-rhev-2.3.0-22.el7.x86_64

Steps for reproduce:
1. Boot vm with libiscsi disk.
-drive file=iscsi://10.66.9.236/iqn.2003-01.org.linux-iscsi.dhcp-9-236.x8664:sn.aba7fca8bbd3/0,if=none,id=drive-scsi-disk,format=qcow2,cache=none,werror=stop,rerror=stop \
-device virtio-scsi-pci,id=scsi0 \
-device scsi-hd,drive=drive-scsi-disk,bus=scsi0.0,scsi-id=0,lun=0,id=scsi-disk,bootindex=1 \

2. Do block mirror.
{ "execute": "drive-mirror", "arguments": { "device": "drive-scsi-disk", "target": "/home/snapshot1", "format": "raw","mode": "absolute-paths", "sync": "full"}}
{"return": {}}
{"timestamp": {"seconds": 1441699467, "microseconds": 93838}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive-scsi-disk", "operation": "read", "action": "report"}}
{"timestamp": {"seconds": 1441699467, "microseconds": 186866}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "drive-scsi-disk", "len": 10256711680, "offset": 774832128, "speed": 0, "type": "mirror", "error": "Input/output error"}}
{ "execute" : "query-block-jobs", "arguments" : {} }
{"return": []}

Also got error message from hmp:

(qemu) qemu-kvm: iSCSI Failure: SENSE KEY:NOT READY(2) ASCQ:(null)(0x0800)

(In reply to Eric Blake from comment #4)
> Could this be the qemu bug fixed upstream by:
> 
> commit e424aff5f307227b1c2512bbb8ece891bb895cef
> Author: Kevin Wolf <kwolf>
> Date:   Thu Aug 13 10:41:50 2015 +0200
> 
> mirror: Fix coroutine reentrance

Unlikely. The bug fixed by that commit is a qemu crash (failing assertion),
whereas this one seems to be a block job failing with -EINVAL if I'm reading the
logged BLOCK_JOB_COMPLETED event correctly; more precisely it seems to be a
failed read from the source according to the BLOCK_JOB_ERROR event.

I'm not sure how to read the libvirt logs correctly, but it seems to be talking
about removing a device before the error occurs. Might this be related?

2015-08-26 10:18:53.819+0000: 25723: debug : udevEventHandleCallback:1543 : udev action: 'remove'
2015-08-26 10:18:53.819+0000: 25723: debug : udevRemoveOneDevice:1314 : Failed to find device to remove that has udev name '/sys/devices/platform/host9/session9/target9:0:0/9:0:0:0/block/sdc/sdc1'

Eric and Kevin,
This bug is not same as Bug 1251487 - qemu core dump when do drive mirror. I can still reproduce this one with latest qemu-kvm-rhev-2.3.0-22.el7 in which patch *mirror: Fix coroutine reentrance* has been backported

(In reply to mazhang from comment #6)
> Just test with qemu-kvm directly, hit block job error twice, but not sure
> it's the same problem.
> 
> Host:
> 3.10.0-314.el7.x86_64
> qemu-kvm-rhev-2.3.0-22.el7.x86_64
> 
> Steps for reproduce:
> 1. Boot vm with libiscsi disk.
> -drive
> file=iscsi://10.66.9.236/iqn.2003-01.org.linux-iscsi.dhcp-9-236.x8664:sn.
> aba7fca8bbd3/0,if=none,id=drive-scsi-disk,format=qcow2,cache=none,
> werror=stop,rerror=stop \
> -device virtio-scsi-pci,id=scsi0 \
> -device
> scsi-hd,drive=drive-scsi-disk,bus=scsi0.0,scsi-id=0,lun=0,id=scsi-disk,
> bootindex=1 \
> 
> 2. Do block mirror.
> { "execute": "drive-mirror", "arguments": { "device": "drive-scsi-disk",
> "target": "/home/snapshot1", "format": "raw","mode": "absolute-paths",
> "sync": "full"}}
> {"return": {}}
> {"timestamp": {"seconds": 1441699467, "microseconds": 93838}, "event":
> "BLOCK_JOB_ERROR", "data": {"device": "drive-scsi-disk", "operation":
> "read", "action": "report"}}
> {"timestamp": {"seconds": 1441699467, "microseconds": 186866}, "event":
> "BLOCK_JOB_COMPLETED", "data": {"device": "drive-scsi-disk", "len":
> 10256711680, "offset": 774832128, "speed": 0, "type": "mirror", "error":
> "Input/output error"}}
> { "execute" : "query-block-jobs", "arguments" : {} }
> {"return": []}
> 
> Also got error message from hmp:
> 
> (qemu) qemu-kvm: iSCSI Failure: SENSE KEY:NOT READY(2) ASCQ:(null)(0x0800)

I can't make sure it's the same problem, so file a new bug 1261701 to trace it.

(In reply to Kevin Wolf from comment #8)
> I'm not sure how to read the libvirt logs correctly, but it seems to be
> talking
> about removing a device before the error occurs. Might this be related?
> 
> 2015-08-26 10:18:53.819+0000: 25723: debug : udevEventHandleCallback:1543 :
> udev action: 'remove'
> 2015-08-26 10:18:53.819+0000: 25723: debug : udevRemoveOneDevice:1314 :
> Failed to find device to remove that has udev name
> '/sys/devices/platform/host9/session9/target9:0:0/9:0:0:0/block/sdc/sdc1'

Eric?

Setting an exception flag as it may lead to data corruption.

The problem manifests itself very similarly to the scsi-hd issue that was reported later here and was filed separately as https://bugzilla.redhat.com/show_bug.cgi?id=1261701

I'll close this as duplicate of the qemu bug, since it looks like a issue in the iSCSI backend of qemu. If it's deemed that this operation should be forbidden this bug can be reopened or the qemu bug can be moved to libvirt.

*** This bug has been marked as a duplicate of bug 1261701 ***