Bug 1746631

When do commit from sn3 to sn1 without stress, also hit this issue, gdb info:
 1. block commit frm sn3 to sn1
 { "execute": "block-commit", "arguments": { "device": "drive_data1","base":"/home/sn1","top":"/home/sn3","auto-finalize":false,"auto-dismiss":false}}
{"timestamp": {"seconds": 1567049154, "microseconds": 714058}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "drive_data1"}}
{"timestamp": {"seconds": 1567049154, "microseconds": 742259}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "drive_data1"}}
{"return": {}}
{"timestamp": {"seconds": 1567049159, "microseconds": 717591}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "drive_data1"}}
{"timestamp": {"seconds": 1567049159, "microseconds": 717649}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "drive_data1"}}
{"timestamp": {"seconds": 1567049159, "microseconds": 717671}, "event": "BLOCK_JOB_PENDING", "data": {"type": "commit", "id": "drive_data1"}}

  2.Complete the job.
{ "execute": "block-job-complete", "arguments": { "device": "drive_data1"}}
{"error": {"class": "GenericError", "desc": "Job 'drive_data1' in state 'pending' cannot accept command verb 'complete'"}}

 3. finalize the job
{"execute":"block-job-finalize","arguments":{"id":"drive_data1"}}
{"timestamp": {"seconds": 1567049215, "microseconds": 135812}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "drive_data1", "len": 2147483648, "offset": 2147483648, "speed": 0, "type": "commit"}}
{"timestamp": {"seconds": 1567049215, "microseconds": 135894}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "drive_data1"}}
{"return": {}}

4. Dismiss the job.
{"execute":"block-job-dismiss","arguments":{"id":"drive_data1"}}
{"timestamp": {"seconds": 1567049232, "microseconds": 984349}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "drive_data1"}}

Gdb info:
  (gdb) bt
#0  0x000055cf4510492e in bdrv_parent_can_set_aio_context
    (errp=0x0, ignore=0x7ffeeeffd950, ctx=0x55cf4682da20, c=0x7f5c3f44476d <g_hash_table_insert_internal+237>) at block.c:5995
#1  0x000055cf4510492e in bdrv_can_set_aio_context (bs=0x55cf46d20bf0, ctx=0x55cf4682da20, ignore=0x7ffeeeffd950, errp=0x0) at block.c:6030
#2  0x000055cf4510a7ca in child_job_can_set_aio_ctx (c=<optimized out>, ctx=0x55cf4682da20, ignore=0x7ffeeeffd950, errp=0x0) at blockjob.c:152
#3  0x000055cf45104945 in bdrv_parent_can_set_aio_context (errp=0x0, ignore=0x7ffeeeffd950, ctx=0x55cf4682da20, c=0x55cf48275010) at block.c:6001
#4  0x000055cf45104945 in bdrv_can_set_aio_context (bs=0x55cf468ce000, ctx=0x55cf4682da20, ignore=0x7ffeeeffd950, errp=0x0) at block.c:6030
#5  0x000055cf45104945 in bdrv_parent_can_set_aio_context (errp=0x0, ignore=0x7ffeeeffd950, ctx=0x55cf4682da20, c=0x55cf468e8610) at block.c:6001
#6  0x000055cf45104945 in bdrv_can_set_aio_context (bs=0x55cf473e6ef0, ctx=0x55cf4682da20, ignore=0x7ffeeeffd950, errp=0x0) at block.c:6030
#7  0x000055cf4510499a in bdrv_can_set_aio_context (errp=0x0, ignore=0x7ffeeeffd950, ctx=0x55cf4682da20, bs=0x55cf47c61380) at block.c:6035
#8  0x000055cf4510499a in bdrv_can_set_aio_context (bs=0x55cf47c61380, ctx=0x55cf4682da20, ignore=0x7ffeeeffd950, errp=0x0) at block.c:6020
#9  0x000055cf45104b73 in bdrv_child_try_set_aio_context
    (bs=bs@entry=0x55cf47c61380, ctx=0x55cf4682da20, ignore_child=ignore_child@entry=0x0, errp=errp@entry=0x0) at block.c:6050
#10 0x000055cf45104c66 in bdrv_try_set_aio_context (errp=0x0, ctx=<optimized out>, bs=0x55cf47c61380) at block.c:6067
#11 0x000055cf45104c66 in bdrv_replace_child (child=child@entry=0x55cf46dbc7e0, new_bs=new_bs@entry=0x0) at block.c:2338
#12 0x000055cf45104ce7 in bdrv_detach_child (child=0x55cf46dbc7e0) at block.c:2456
#13 0x000055cf45104d14 in bdrv_root_unref_child (child=<optimized out>) at block.c:2467
#14 0x000055cf45104d14 in bdrv_unref_child (parent=<optimized out>, child=<optimized out>) at block.c:2506
#15 0x000055cf45105364 in bdrv_unref_child (child=<optimized out>, parent=0x55cf468373d0) at block.c:4029
#16 0x000055cf45105364 in bdrv_close (bs=0x55cf468373d0) at block.c:4029
#17 0x000055cf45105364 in bdrv_delete (bs=<optimized out>) at block.c:4264
#18 0x000055cf45105364 in bdrv_unref (bs=0x55cf468373d0) at block.c:5598
#19 0x000055cf4510ab4c in block_job_remove_all_bdrv (job=job@entry=0x55cf4682f5e0) at blockjob.c:193
#20 0x000055cf4510ab8d in block_job_free (job=0x55cf4682f5e0) at blockjob.c:87
#21 0x000055cf4510beed in job_unref (job=0x55cf4682f5e0) at job.c:359
#22 0x000055cf4510beed in job_unref (job=0x55cf4682f5e0) at job.c:351
#23 0x000055cf4510c6f2 in job_dismiss (jobptr=jobptr@entry=0x7ffeeeffda70, errp=errp@entry=0x7ffeeeffda98) at job.c:616
#24 0x000055cf44fab991 in qmp_block_job_dismiss (id=<optimized out>, errp=errp@entry=0x7ffeeeffda98) at blockdev.c:4150
#25 0x000055cf450c3153 in qmp_marshal_block_job_dismiss (args=<optimized out>, ret=<optimized out>, errp=0x7ffeeeffdaf8)
    at qapi/qapi-commands-block-core.c:1154
#26 0x000055cf45180ecc in do_qmp_dispatch
    (errp=0x7ffeeeffdaf0, allow_oob=<optimized out>, request=<optimized out>, cmds=0x55cf45a5c7a0 <qmp_commands>) at qapi/qmp-dispatch.c:131
#27 0x000055cf45180ecc in qmp_dispatch (cmds=0x55cf45a5c7a0 <qmp_commands>, request=<optimized out>, allow_oob=<optimized out>)
    at qapi/qmp-dispatch.c:174
#28 0x000055cf450a34f1 in monitor_qmp_dispatch (mon=0x55cf4688c2b0, req=<optimized out>) at monitor/qmp.c:120
#29 0x000055cf450a3b3a in monitor_qmp_bh_dispatcher (data=<optimized out>) at monitor/qmp.c:209
#30 0x000055cf451c7c26 in aio_bh_call (bh=0x55cf467a6b20) at util/async.c:117
--Type <RET> for more, q to quit, c to continue without paging--
#31 0x000055cf451c7c26 in aio_bh_poll (ctx=ctx@entry=0x55cf467a56d0) at util/async.c:117
#32 0x000055cf451cb064 in aio_dispatch (ctx=0x55cf467a56d0) at util/aio-posix.c:459
#33 0x000055cf451c7b02 in aio_ctx_dispatch (source=<optimized out>, callback=<optimized out>, user_data=<optimized out>) at util/async.c:260
#34 0x00007f5c3f45667d in g_main_dispatch (context=0x55cf4682ee70) at gmain.c:3176
#35 0x00007f5c3f45667d in g_main_context_dispatch (context=context@entry=0x55cf4682ee70) at gmain.c:3829
#36 0x000055cf451ca118 in glib_pollfds_poll () at util/main-loop.c:218
#37 0x000055cf451ca118 in os_host_main_loop_wait (timeout=<optimized out>) at util/main-loop.c:241
#38 0x000055cf451ca118 in main_loop_wait (nonblocking=<optimized out>) at util/main-loop.c:517
#39 0x000055cf44fb3169 in main_loop () at vl.c:1809
#40 0x000055cf44e62fd3 in main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>) at vl.c:4506

Also hit this issue when do block stream on system disk.
 base->sn1->sn2->sn3->sn4
 { "execute": "block-stream", "arguments": { "device": "drive_image1"}}

Upstream patch: https://lists.nongnu.org/archive/html/qemu-devel/2019-09/msg02176.html

Test on qemu-kvm-4.1.0-11.module+el8.1.0+4250+4f5fbfdc.x86_64, don't hit this issue any more.

Test steps:
 1.Create a new data disk and start guest with it.
   #qemu-img create -f qcow2 /home/data.qcow2 2G
   /usr/libexec/qemu-kvm \
    -name 'avocado-vt-vm1' \
    -machine q35  \
    -nodefaults \
    -device VGA,bus=pcie.0,addr=0x1  \
    -chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/monitor-qmpmonitor1-20190820-032540-OesJUJdj,server,nowait \
    -mon chardev=qmp_id_qmpmonitor1,mode=control  \
    -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/monitor-catch_monitor-20190820-032540-OesJUJdj,server,nowait \
    -mon chardev=qmp_id_catch_monitor,mode=control \
    -device pvpanic,ioport=0x505,id=idbJPqrG \
    -chardev socket,id=chardev_serial0,server,path=/var/tmp/serial-serial0-20190820-032540-OesJUJdj,nowait \
    -device isa-serial,id=serial0,chardev=chardev_serial0  \
    -chardev socket,id=seabioslog_id_20190820-032540-OesJUJdj,path=/var/tmp/seabios-20190820-032540-OesJUJdj,server,nowait \
    -device isa-debugcon,chardev=seabioslog_id_20190820-032540-OesJUJdj,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 \
    -object iothread,id=iothread0 \
    -object iothread,id=iothread1 \
    -device pcie-root-port,id=pcie.0-root-port-3,slot=3,chassis=3,addr=0x3,bus=pcie.0 \
    -drive id=drive_image1,if=none,snapshot=off,cache=none,format=qcow2,file=/home/kvm_autotest_root/images/rhel810-64-virtio.qcow2 \
    -device virtio-blk-pci,id=image1,drive=drive_image1,bootindex=0,bus=pcie.0-root-port-3,addr=0x0,iothread=iothread0 \
    -device pcie-root-port,id=pcie.0-root-port-6,slot=6,chassis=6,addr=0x6,bus=pcie.0 \
    -drive id=drive_data1,if=none,snapshot=off,cache=none,format=qcow2,file=/home/data.qcow2 \
    -device virtio-blk-pci,id=data1,drive=drive_data1,iothread=iothread1,bus=pcie.0-root-port-6,addr=0x0 \
    -device pcie-root-port,id=pcie.0-root-port-7,slot=7,chassis=7,addr=0x7,bus=pcie.0 \
    -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:19:6a:3c:a6:a5,id=idq14C2Q,netdev=idHzG7Zk,bus=pcie.0-root-port-4,addr=0x0  \
    -netdev tap,id=idHzG7Zk,vhost=on \
    -m 2048  \
    -smp 4,maxcpus=4,cores=2,threads=1,sockets=2  \
    -cpu 'Skylake-Client',+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 \

2. In guest, format data disk
   (guest)#fdisk /dev/vdb
          #mkfs.ext4 /dev/vdb
          #mount /dev/vdb /mnt
          #cd /mnt
3. Create snapshot "/home/sn1"
    {"execute": "blockdev-snapshot-sync", "arguments": { "device": "drive_data1","snapshot-file": "/home/sn1","mode": "absolute-paths","format": "qcow2"}}

4. Create file test on guest.
    (guest)#dd if=/dev/urandom of=test bs=1M count=100

5. Create snapshot "/home/sn2"
    {"execute": "blockdev-snapshot-sync", "arguments": { "device": "drive_data1","snapshot-file": "/home/sn2","mode": "absolute-paths","format": "qcow2"}}

6. Create file test on guest.
    (guest)#dd if=/dev/urandom of=tes bs=1M count=100

7. Create snapshot "/home/sn3"
    {"execute": "blockdev-snapshot-sync", "arguments": { "device": "drive_data1","snapshot-file": "/home/sn3","mode": "absolute-paths","format": "qcow2"}}

8. Create file test on guest.
    (guest)#dd if=/dev/urandom of=te bs=1M count=100

9. Create snapshot "/home/sn4"
    {"execute": "blockdev-snapshot-sync", "arguments": { "device": "drive_data1","snapshot-file": "/home/sn4","mode": "absolute-paths","format": "qcow2"}}

10. Create file test on guest.
    (guest)#dd if=/dev/urandom of=t bs=1M count=100

11. Run stress in guest
    (guest)#stress --cpu 2 --io 2 --vm 2 --vm-bytes 1024

12. Do block commit
    { "execute": "block-commit", "arguments": { "device": "drive_data1","top":"/home/sn4"}}
    {"timestamp": {"seconds": 1567046660, "microseconds": 449603}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "drive_data1"}}
{"timestamp": {"seconds": 1567046660, "microseconds": 452293}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "drive_data1"}}
{"return": {}}
{"timestamp": {"seconds": 1567046672, "microseconds": 114872}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "drive_data1"}}
{"timestamp": {"seconds": 1567046672, "microseconds": 114931}, "event": "BLOCK_JOB_READY", "data": {"device": "drive_data1", "len": 430571520, "offset": 430571520, "speed": 0, "type": "commit"}}

13. Complete the job.
    { "execute": "block-job-complete", "arguments": { "device": "drive_data1"}}
{"return": {}}
{"timestamp": {"seconds": 1568946513, "microseconds": 354026}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "j1"}}
{"timestamp": {"seconds": 1568946513, "microseconds": 354084}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "j1"}}
{"timestamp": {"seconds": 1568946513, "microseconds": 354223}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "j1", "len": 0, "offset": 0, "speed": 0, "type": "commit"}}
{"timestamp": {"seconds": 1568946513, "microseconds": 354278}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "j1"}}
{"timestamp": {"seconds": 1568946513, "microseconds": 354296}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "j1"}}

Will run regression test on drive_mirror and re-test the failed cases on block_stream and live_commit, result will be provided later.

On qemu-kvm-4.1.0-11.module+el8.1.0+4250+4f5fbfdc.x86_64, run regression test on drive_mirror and re-test the failed cases on block_stream and live_commit, don't hit this issue any more, set bug's status to "Verified".

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/RHBA-2019:3723