Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1713650

Summary: Failed to do block commit to NBD device with BLOCK_JOB_ERROR, error: "Invalid argument"
Product: Red Hat Enterprise Linux Advanced Virtualization Reporter: aihua liang <aliang>
Component: qemu-kvmAssignee: Eric Blake <eblake>
qemu-kvm sub component: Block Jobs QA Contact: aihua liang <aliang>
Status: CLOSED CURRENTRELEASE Docs Contact:
Severity: medium    
Priority: medium CC: coli, juzhang, ngu, qzhang, virt-maint, xutian
Version: 8.1Keywords: Triaged
Target Milestone: rc   
Target Release: 8.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-02-13 02:35:52 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description aihua liang 2019-05-24 11:51:58 UTC
Description of problem:
 [upstream]Failed to do block commit to NBD device with BLOCK_JOB_ERROR, error: "Invalid argument"

Version-Release number of selected component (if applicable):
 kernel version:3.10.0-1044.el7.x86_64
 qemu version: commit 636011255dec55da4cac28240ffcaa2e740f1e81


How reproducible:
 100%

Upstream Env built:
  step1: git clone https://git.qemu.org/git/qemu.git
  step2: cd qemu
  step3: ./configure --target-list=x86_64-softmmu --python=/usr/bin/python2.7
  step4: make
  step5: make install

Steps to Reproduce:
1.(host1)Expose image on NBD Server:
   qemu-nbd -f raw /home/kvm_autotest_root/images/rhel77-64-virtio.qcow2 -t -p 9000

2.(host2)Start guest with qemu cmds:
    /usr/local/bin/qemu-system-x86_64  \
    -name 'avocado-vt-vm1' \
    -machine pc  \
    -nodefaults \
    -device VGA,bus=pci.0,addr=0x2  \
    -chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/monitor-qmpmonitor1-20190123-032240-rOoB4cgD,server,nowait \
    -mon chardev=qmp_id_qmpmonitor1,mode=control  \
    -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/monitor-catch_monitor-20190123-032240-rOoB4cgD,server,nowait \
    -mon chardev=qmp_id_catch_monitor,mode=control \
    -device pvpanic,ioport=0x505,id=id8Ec4Bn  \
    -chardev socket,id=serial_id_serial0,path=/var/tmp/serial-serial0-20190123-032240-rOoB4cgD,server,nowait \
    -device isa-serial,chardev=serial_id_serial0  \
    -chardev socket,id=seabioslog_id_20190123-032240-rOoB4cgD,path=/var/tmp/seabios-20190123-032240-rOoB4cgD,server,nowait \
    -device isa-debugcon,chardev=seabioslog_id_20190123-032240-rOoB4cgD,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 \
    -object iothread,id=iothread0 \
    -drive id=drive_image1,if=none,snapshot=off,aio=threads,cache=none,format=qcow2,file=nbd://10.66.144.83:9000 \
    -device virtio-blk-pci,id=image1,drive=drive_image1,bus=pci.0,iothread=iothread0 \
    -drive id=drive_data1,if=none,snapshot=off,aio=threads,cache=none,format=qcow2,file=/root/test.qcow2 \
    -device virtio-blk-pci,id=data1,drive=drive_data1,bus=pci.0,iothread=iothread0 \
    -device virtio-net-pci,mac=9a:39:3a:3b:3c:3d,id=id1JNQsL,vectors=4,netdev=idVpZZ6A,bus=pci.0  \
    -netdev tap,id=idVpZZ6A,vhost=on \
    -m 8192  \
    -smp 2,maxcpus=2,cores=1,threads=1,sockets=2  \
    -cpu 'Penryn',+kvm_pv_unhalt \
    -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1  \
    -vnc :0  \
    -rtc base=utc,clock=host,driftfix=slew  \
    -boot order=cdn,once=c,menu=off,strict=off \
    -enable-kvm \
    -monitor stdio \
    -qmp tcp:0:3000,server,nowait \

3.(host2)Create 4 snapshots:
  { "execute": "blockdev-snapshot-sync", "arguments": { "device": "drive_image1", "snapshot-file": "/root/sn1", "format": "qcow2" } }
  { "execute": "blockdev-snapshot-sync", "arguments": { "device": "drive_image1", "snapshot-file": "/root/sn2", "format": "qcow2" } }
  { "execute": "blockdev-snapshot-sync", "arguments": { "device": "drive_image1", "snapshot-file": "/root/sn3", "format": "qcow2" } }
  { "execute": "blockdev-snapshot-sync", "arguments": { "device": "drive_image1", "snapshot-file": "/root/sn4", "format": "qcow2" } }

4.In guest, write some data to disk
  (guest)# dd if=/dev/urandom of=test bs=1M count=600

5.(host2)Do block commit from sn4 to base
   {"timestamp": {"seconds": 1558696504, "microseconds": 197027}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "drive_image1"}}
{"timestamp": {"seconds": 1558696504, "microseconds": 197239}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "drive_image1"}}
{"return": {}}
{"timestamp": {"seconds": 1558696514, "microseconds": 620460}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 636546}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 648817}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 652684}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 719120}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 731685}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 746808}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 755355}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 780202}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 792006}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 800947}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 828531}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 844682}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 858137}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696514, "microseconds": 863944}, "event": "BLOCK_JOB_ERROR", "data": {"device": "drive_image1", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1558696516, "microseconds": 26004}, "event": "JOB_STATUS_CHANGE", "data": {"status": "aborting", "id": "drive_image1"}}
{"timestamp": {"seconds": 1558696516, "microseconds": 26306}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "drive_image1", "len": 270204928, "offset": 144113664, "speed": 0, "type": "commit", "error": "Invalid argument"}}
{"timestamp": {"seconds": 1558696516, "microseconds": 26390}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "drive_image1"}}
{"timestamp": {"seconds": 1558696516, "microseconds": 26443}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "drive_image1"}}

Actual results:
 Block commit from sn4 to NBD base failed for invalid arguments.

Expected results:
 Block commit to NBD device should success.

Comment 5 Ademar Reis 2020-02-05 22:58:19 UTC
QEMU has been recently split into sub-components and as a one-time operation to avoid breakage of tools, we are setting the QEMU sub-component of this BZ to "General". Please review and change the sub-component if necessary the next time you review this BZ. Thanks

Comment 7 aihua liang 2020-02-13 02:35:52 UTC
Test on qemu-kvm-4.2.0-8.module+el8.2.0+5607+dc756904, don't hit this issue any more, close it as currentrelease.

Test steps:
  1. Expose image by:
       qemu-nbd -f qcow2 /home/kvm_autotest_root/images/rhel820-64-virtio-scsi.qcow2 -t -p 9000

  2. Start guest with the exposed image.
       /usr/libexec/qemu-kvm \
    -name 'avocado-vt-vm1'  \
    -sandbox on  \
    -machine q35  \
    -nodefaults \
    -device VGA,bus=pcie.0,addr=0x1 \
    -m 14336  \
    -smp 16,maxcpus=16,cores=8,threads=1,dies=1,sockets=2  \
    -cpu 'EPYC',+kvm_pv_unhalt  \
    -chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/monitor-qmpmonitor1-20200203-033416-61dmcn92,server,nowait \
    -mon chardev=qmp_id_qmpmonitor1,mode=control  \
    -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/monitor-catch_monitor-20200203-033416-61dmcn92,server,nowait \
    -mon chardev=qmp_id_catch_monitor,mode=control \
    -device pvpanic,ioport=0x505,id=idy8YPXp \
    -chardev socket,path=/var/tmp/serial-serial0-20200203-033416-61dmcn92,server,nowait,id=chardev_serial0 \
    -device isa-serial,id=serial0,chardev=chardev_serial0  \
    -chardev socket,id=seabioslog_id_20200203-033416-61dmcn92,path=/var/tmp/seabios-20200203-033416-61dmcn92,server,nowait \
    -device isa-debugcon,chardev=seabioslog_id_20200203-033416-61dmcn92,iobase=0x402 \
    -device pcie-root-port,id=pcie.0-root-port-2,slot=2,chassis=2,addr=0x2,bus=pcie.0 \
    -device qemu-xhci,id=usb1,bus=pcie.0-root-port-2,addr=0x0 \
    -device pcie-root-port,id=pcie.0-root-port-3,slot=3,chassis=3,addr=0x3,bus=pcie.0 \
    -blockdev node-name=file_image1,driver=nbd,server.host=10.73.196.71,server.port=9000,server.type=inet,cache.direct=on,cache.no-flush=off \
    -blockdev node-name=drive_image1,driver=raw,file=file_image1 \
    -device virtio-blk-pci,id=image1,drive=drive_image1,write-cache=on,bus=pcie.0-root-port-3 \
    -device pcie-root-port,id=pcie.0-root-port-6,slot=6,chassis=6,addr=0x6,bus=pcie.0 \
    -blockdev node-name=file_data1,driver=file,aio=threads,filename=/home/data.qcow2,cache.direct=on,cache.no-flush=off \
    -blockdev node-name=drive_data1,driver=qcow2,cache.direct=on,cache.no-flush=off,file=file_data1 \
    -device virtio-blk-pci,id=data1,drive=drive_data1,write-cache=on,bus=pcie.0-root-port-6 \
    -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:6c:ca:b7:36:85,id=idz4QyVp,netdev=idNnpx5D,bus=pcie.0-root-port-4,addr=0x0  \
    -netdev tap,id=idNnpx5D,vhost=on \
    -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1  \
    -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,slot=5,chassis=5,addr=0x5,bus=pcie.0 \
    -monitor stdio \
    -qmp tcp:0:3000,server,nowait \

 3. Create snapshot nodes sn1~sn4
     {'execute':'blockdev-create','arguments':{'options': {'driver':'file','filename':'/root/sn$i','size':21474836480},'job-id':'job1'}}
     {'execute':'blockdev-add','arguments':{'driver':'file','node-name':'drive_sn$i','filename':'/root/sn$i'}}
     {'execute':'blockdev-create','arguments':{'options': {'driver': 'qcow2','file':'drive_sn$i','size':21474836480},'job-id':'job2'}}
     {'execute':'blockdev-add','arguments':{'driver':'qcow2','node-name':'sn$i','file':'drive_sn$i'}}
     {'execute':'job-dismiss','arguments':{'id':'job1'}}
     {'execute':'job-dismiss','arguments':{'id':'job2'}}

  4. Do snapshots
      {"execute":"blockdev-snapshot","arguments":{"node":"drive_image1","overlay":"sn1"}}
{"return": {}}
{"execute":"blockdev-snapshot","arguments":{"node":"sn1","overlay":"sn2"}}
{"return": {}}
{"execute":"blockdev-snapshot","arguments":{"node":"sn2","overlay":"sn3"}}
{"return": {}}
{"execute":"blockdev-snapshot","arguments":{"node":"sn3","overlay":"sn4"}}
{"return": {}}

  5. In guest, dd a file
      (guest)# dd if=/dev/urandom of=test bs=1M count=1000

  6. Commit from sn4 to base
      {'execute': 'block-commit', 'arguments': { 'device': 'sn4','job-id':'j1'}}
{"timestamp": {"seconds": 1581560740, "microseconds": 118639}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "j1"}}
{"timestamp": {"seconds": 1581560740, "microseconds": 118821}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "j1"}}
{"return": {}}
{"timestamp": {"seconds": 1581560744, "microseconds": 343922}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "j1"}}
{"timestamp": {"seconds": 1581560744, "microseconds": 344009}, "event": "BLOCK_JOB_READY", "data": {"device": "j1", "len": 1051918336, "offset": 1051918336, "speed": 0, "type": "commit"}}

  7. Complete the block job.
      { "execute": "block-job-complete", "arguments": { "device": "j1" } }
{"return": {}}
{"timestamp": {"seconds": 1581560763, "microseconds": 319531}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "j1"}}
{"timestamp": {"seconds": 1581560763, "microseconds": 319597}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "j1"}}
{"timestamp": {"seconds": 1581560763, "microseconds": 319787}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "j1", "len": 1051918336, "offset": 1051918336, "speed": 0, "type": "commit"}}
{"timestamp": {"seconds": 1581560763, "microseconds": 319844}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "j1"}}
{"timestamp": {"seconds": 1581560763, "microseconds": 319897}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "j1"}}

   8. Shutdown vm, then restart it with cmd in step1.
       file created in step5 exist.