Bug 1920415 - Block mirror to non-enough space storage will raise unexpected error message
Summary: Block mirror to non-enough space storage will raise unexpected error message
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux Advanced Virtualization
Classification: Red Hat
Component: qemu-kvm
Version: 8.4
Hardware: x86_64
OS: Linux
medium
medium
Target Milestone: rc
: 8.4
Assignee: Stefano Garzarella
QA Contact: aihua liang
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-01-26 09:42 UTC by leidwang@redhat.com
Modified: 2021-11-16 08:09 UTC (History)
9 users (show)

Fixed In Version: qemu-kvm-6.0.0-16.module+el8.5.0+10848+2dccc46d
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2021-11-16 07:51:32 UTC
Type: ---
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2021:4684 0 None None None 2021-11-16 07:51:58 UTC

Description leidwang@redhat.com 2021-01-26 09:42:34 UTC
Description of problem:
Do 'blockdev_mirror' to non-enough space storage, will raise EINVAL, but not ENOSPC.

Version-Release number of selected component (if applicable):
kernel-4.18.0-275.el8.dt3.x86_64
qemu-kvm-5.2.0-3.module+el8.4.0+9499+42e58f08.x86_64

How reproducible:
100%

Steps to Reproduce:
1.boot up a guest

...
-blockdev node-name=file_src1,driver=file,auto-read-only=on,discard=unmap,aio=threads,filename=/home/sr1.qcow2,cache.direct=on,cache.no-flush=off \
-blockdev node-name=drive_src1,driver=qcow2,read-only=off,cache.direct=on,cache.no-flush=off,file=file_src1 \
-device scsi-hd,id=src1,drive=drive_src1,write-cache=on \
...

2.mirror disk to ceph

{"execute":"qmp_capabilities"}
{"return": {}}
{'execute':'blockdev-create','arguments':{'options': {'driver':'rbd','location':{'pool':'rbd','image':'ffullbackup1.raw','server':[{'host':'10.73.114.12','port':'0'}]},'size':2147483648},'job-id':'job1'}}
{"timestamp": {"seconds": 1611564071, "microseconds": 985018}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "job1"}}
{"timestamp": {"seconds": 1611564071, "microseconds": 985137}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "job1"}}
{"return": {}}
{"timestamp": {"seconds": 1611564072, "microseconds": 213510}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "job1"}}
{"timestamp": {"seconds": 1611564072, "microseconds": 213599}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "job1"}}
{"timestamp": {"seconds": 1611564072, "microseconds": 213662}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "job1"}}
{"timestamp": {"seconds": 1611564078, "microseconds": 944480}, "event": "NIC_RX_FILTER_CHANGED", "data": {"name": "id6B53Fa", "path": "/machine/peripheral/id6B53Fa/virtio-backend"}}
{'execute':'blockdev-add','arguments':{'driver':'rbd','pool':'rbd','image':'ffullbackup1.raw','server':[{'host':'10.73.114.12','port':'0'}],'node-name':'fullbackup1'}}
{"return": {}}
{'execute':'blockdev-add','arguments':{'driver':'raw','node-name':'fbk1','file':'fullbackup1'}}
{"return": {}}
{'execute':'job-dismiss','arguments':{'id':'job1'}}
{"timestamp": {"seconds": 1611564111, "microseconds": 922280}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "job1"}}
{"return": {}}
{ "execute": "blockdev-mirror", "arguments": { "sync": "full", "device": "drive_src1", "target": "fbk1", "job-id": "j1" }}
{"timestamp": {"seconds": 1611564141, "microseconds": 208801}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "j1"}}
{"timestamp": {"seconds": 1611564141, "microseconds": 209001}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "j1"}}
{"return": {}}
{"timestamp": {"seconds": 1611564141, "microseconds": 209144}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "j1"}}
{"timestamp": {"seconds": 1611564141, "microseconds": 209257}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "j1", "len": 0, "offset": 0, "speed": 0, "type": "mirror", "error": "Invalid argument"}}
{"timestamp": {"seconds": 1611564141, "microseconds": 209340}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "j1"}}
{"timestamp": {"seconds": 1611564141, "microseconds": 209398}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "j1"}}
{"timestamp": {"seconds": 1611564739, "microseconds": 391479}, "event": "SHUTDOWN", "data": {"guest": false, "reason": "host-qmp-quit"}


Actual results:

{"timestamp": {"seconds": 1611564141, "microseconds": 209257}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "j1", "len": 0, "offset": 0, "speed": 0, "type": "mirror", "error": "Invalid argument"}}

Expected results:

{"timestamp": {"seconds": 1577631160, "microseconds": 88742}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "j1", "len": 2147483648, "offset": 641728512, "speed": 0, "type": "mirror", "error": "No space left on device"}}

Additional info:
# qemu-img info /home/sr1.qcow2 
image: /home/sr1.qcow2
file format: qcow2
virtual size: 3 GiB (3221225472 bytes)
disk size: 196 KiB
cluster_size: 65536
Format specific information:
    compat: 1.1
    lazy refcounts: false
    refcount bits: 16
    corrupt: false

# qemu-img info rbd:rbd/ffullbackup1.raw
image: json:{"driver": "raw", "file": {"pool": "rbd", "image": "ffullbackup1.raw", "driver": "rbd"}}
file format: raw
virtual size: 2 GiB (2147483648 bytes)
disk size: unavailable
cluster_size: 4194304

Comment 2 zhenchao 2021-02-05 02:51:57 UTC
This issue can be reproduced on local fs too:

qemu-kvm-5.2.0-3.module+el8.4.0+9499+42e58f08.x86_64
4.18.0-201.el8.x86_64


                              mirror to 
local data image (2G, qcow2)  ========>  local mirror image (1G, qcow2)

cmd: 
{"execute": "blockdev-mirror", "arguments": {"sync": "full", "on-source-error": "stop", "on-target-error": "stop", "device": "drive_data1", "target": "drive_mirror1", "job-id": "drive_data1_IyE3"}, "id": "5dHQpEh0"}

events:
{"timestamp": {"seconds": 1612492414, "microseconds": 442317}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "drive_data1_IyE3"}}
{"timestamp": {"seconds": 1612492414, "microseconds": 442484}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "drive_data1_IyE3"}}
{"return": {}, "id": "5dHQpEh0"}
{"timestamp": {"seconds": 1612492414, "microseconds": 442671}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "drive_data1_IyE3"}}
{"timestamp": {"seconds": 1612492414, "microseconds": 442807}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "drive_data1_IyE3", "len": 0, "offset": 0, "speed": 0, "type": "mirror", "error": "Invalid argument"}}

Comment 3 Stefano Garzarella 2021-02-17 16:13:36 UTC
(In reply to zhenchao from comment #2)
> This issue can be reproduced on local fs too:
> 
> qemu-kvm-5.2.0-3.module+el8.4.0+9499+42e58f08.x86_64
> 4.18.0-201.el8.x86_64
> 
> 
>                               mirror to 
> local data image (2G, qcow2)  ========>  local mirror image (1G, qcow2)
> 

So it seems not related to rbd, but to block layer in general.

I'll try to take a look.

Comment 4 Stefano Garzarella 2021-02-23 09:07:42 UTC
The following commit introduced the -EINVAL return value when source and target size don't match in the mirror job.
I'm not sure if we should return -ENOSPC if target_size < source_size, since the correct condition would be target_size == source_size as explained in the commit message.


commit e83dd6808c6e0975970f37b49b27cc37bb54eea8
Author: Kevin Wolf <kwolf>
Date:   Mon May 11 15:58:24 2020 +0200

    mirror: Make sure that source and target size match
    
    If the target is shorter than the source, mirror would copy data until
    it reaches the end of the target and then fail with an I/O error when
    trying to write past the end.
    
    If the target is longer than the source, the mirror job would complete
    successfully, but the target wouldn't actually be an accurate copy of
    the source image (it would contain some additional garbage at the end).
    
    Fix this by checking that both images have the same size when the job
    starts.
    
    Signed-off-by: Kevin Wolf <kwolf>
    Reviewed-by: Eric Blake <eblake>
    Message-Id: <20200511135825.219437-4-kwolf>
    Reviewed-by: Max Reitz <mreitz>
    Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov>
    Signed-off-by: Kevin Wolf <kwolf>

Comment 5 Stefano Garzarella 2021-02-23 09:32:32 UTC
As Kevin suggested, we will report a more accurate error instead of "Invalid argument":

{"device": "j1", "len": 0, "offset": 0, "speed": 0, "type": "mirror", "error": "Source and target image have different sizes"}}

Comment 6 Stefano Garzarella 2021-02-23 14:18:21 UTC
Patch proposed upstream: https://lists.gnu.org/archive/html/qemu-devel/2021-02/msg07256.html

Comment 7 Stefano Garzarella 2021-03-11 15:00:15 UTC
Patch merged upstream: https://gitlab.com/qemu-project/qemu/-/commit/3b6ad6230e902168f63315e47933025b016f546e

Comment 12 aihua liang 2021-05-13 08:32:39 UTC
Test on qemu-kvm-6.0.0-16.module+el8.5.0+10848+2dccc46d, the bug is resolved and act as expected.

Test Env:
 kernel version:4.18.0-305.1.el8.x86_64
 qemu-kvm version:qemu-kvm-6.0.0-16.module+el8.5.0+10848+2dccc46d

Test Steps:
 1.Start guest with qemu cmds:
    /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 30720  \
    -smp 10,maxcpus=10,cores=5,threads=1,dies=1,sockets=2  \
    -cpu 'Cascadelake-Server-noTSX',+kvm_pv_unhalt \
    -chardev socket,server=on,path=/tmp/monitor-qmpmonitor1-20210512-234257-mOeaMK07,id=qmp_id_qmpmonitor1,wait=off  \
    -mon chardev=qmp_id_qmpmonitor1,mode=control \
    -chardev socket,server=on,path=/tmp/monitor-catch_monitor-20210512-234257-mOeaMK07,id=qmp_id_catch_monitor,wait=off  \
    -mon chardev=qmp_id_catch_monitor,mode=control \
    -device pvpanic,ioport=0x505,id=idXTMc9z \
    -chardev socket,server=on,path=/tmp/serial-serial0-20210512-234257-mOeaMK07,id=chardev_serial0,wait=off \
    -device isa-serial,id=serial0,chardev=chardev_serial0  \
    -chardev socket,id=seabioslog_id_20210512-234257-mOeaMK07,path=/tmp/seabios-20210512-234257-mOeaMK07,server=on,wait=off \
    -device isa-debugcon,chardev=seabioslog_id_20210512-234257-mOeaMK07,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-tablet,id=usb-tablet1,bus=usb1.0,port=1 \
    -device pcie-root-port,id=pcie-root-port-2,port=0x2,addr=0x1.0x2,bus=pcie.0,chassis=3 \
    -device virtio-scsi-pci,id=virtio_scsi_pci0,bus=pcie-root-port-2,addr=0x0 \
    -blockdev node-name=file_image1,driver=file,auto-read-only=on,discard=unmap,aio=threads,filename=/home/kvm_autotest_root/images/rhel850-64-virtio-scsi.qcow2,cache.direct=on,cache.no-flush=off \
    -blockdev node-name=drive_image1,driver=qcow2,read-only=off,cache.direct=on,cache.no-flush=off,file=file_image1 \
    -device scsi-hd,id=image1,drive=drive_image1,write-cache=on \
    -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:bb:ed:35:8d:44,id=idSFYXRM,netdev=id47qtZ5,bus=pcie-root-port-3,addr=0x0  \
    -netdev tap,id=id47qtZ5,vhost=on  \
    -vnc :0  \
    -rtc base=utc,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=0x3,chassis=5 \
    -monitor stdio \
    -qmp tcp:0:3000,server,nowait \

 2. Create target mirror node with small size.
    {'execute':'blockdev-create','arguments':{'options': {'driver':'file','filename':'/root/sn1','size':3221225472},'job-id':'job1'}}
    {'execute':'blockdev-add','arguments':{'driver':'file','node-name':'drive_sn1','filename':'/root/sn1'}}
    {'execute':'blockdev-create','arguments':{'options': {'cluster-size':4096, 'driver': 'qcow2','file':'drive_sn1','size':3221225472},'job-id':'job2'}}
    {'execute':'blockdev-add','arguments':{'driver':'qcow2','node-name':'sn1','file':'drive_sn1'}}
    {'execute':'job-dismiss','arguments':{'id':'job1'}}
    {'execute':'job-dismiss','arguments':{'id':'job2'}}

 3. Do mirror from src to target.
    {"execute": "blockdev-mirror", "arguments": {"sync": "full", "device": "drive_image1","target": "sn1","job-id": "j1"}}
{"timestamp": {"seconds": 1620894416, "microseconds": 533693}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "j1"}}
{"timestamp": {"seconds": 1620894416, "microseconds": 533816}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "j1"}}
{"return": {}}
{"timestamp": {"seconds": 1620894416, "microseconds": 533877}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "j1"}}
{"timestamp": {"seconds": 1620894416, "microseconds": 533918}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "j1", "len": 0, "offset": 0, "speed": 0, "type": "mirror", "error": "Source and target image have different sizes"}}
{"timestamp": {"seconds": 1620894416, "microseconds": 533951}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "j1"}}
{"timestamp": {"seconds": 1620894416, "microseconds": 533974}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "j1"}}

 After step3, mirror failed with error msg:
   "error": "Source and target image have different sizes"

Comment 13 aihua liang 2021-05-13 08:33:25 UTC
As comment12, set bug's status to "Verified".

Comment 15 errata-xmlrpc 2021-11-16 07:51:32 UTC
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 (virt:av bug fix and enhancement update), 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/RHBA-2021:4684


Note You need to log in before you can comment on or make changes to this bug.