Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1816692

Summary: [incremental_backup] when scratch file has no space during pull-mode backup, the backup job will still run, this will produce a inconsistent backup file
Product: Red Hat Enterprise Linux 8 Reporter: yisun
Component: qemu-kvmAssignee: Virtualization Maintenance <virt-maint>
qemu-kvm sub component: Incremental Live Backup QA Contact: aihua liang <aliang>
Status: CLOSED WONTFIX Docs Contact:
Severity: medium    
Priority: unspecified CC: aliang, coli, jinzhao, juzhang, ngu, pkrempa, virt-maint
Version: ---Keywords: Triaged
Target Milestone: rcFlags: pm-rhel: mirror+
Target Release: 8.6   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2021-09-24 07:26:57 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 yisun 2020-03-24 14:36:03 UTC
Description:
[incremental_backup] when scratch file has no space during pull-mode backup, the backup job will still run, this will produce a inconsistent backup file  

Versions:
qemu-kvm-4.2.0-16.module+el8.2.0+6092+4f2391c1.x86_64
libvirt-6.0.0-14.module+el8.2.0+6069+78a1cb09.x86_64

How reproducible:
100%

Steps:
1. Having a 200M file in vm as /tmp/200M
[root@localhost tmp]# dd if=/dev/urandom of=/tmp/200M bs=1M count=200
200+0 records in
200+0 records out
209715200 bytes (210 MB, 200 MiB) copied, 1.27241 s, 165 MB/s
[root@localhost tmp]# sync

2. Prepare a 100M block device on host, mount it to /mnt
[root@dell-per740xd-11 ~]# lsblk
...
sdb                                8:16   0  100M  0 disk /mnt

3. Prepare vm's backup (pull mode) and checkpoint xml, make sure the scratch file in /mnt 
[root@dell-per740xd-11 inc_bkup]# cat backup_full_pull.xml
<domainbackup mode='pull'>
  <server name="localhost" port="10809"/>
  <disks>
    <disk name='vda' backup='yes' type='file'>
	    <scratch file='/mnt/sratch.vda'/>
    </disk>
  </disks>
</domainbackup>

[root@dell-per740xd-11 inc_bkup]# cat checkpoint_full_pull.xml
<domaincheckpoint>
  <name>check_full</name>
  <disks>
    <disk name='vda' checkpoint='bitmap'/>
  </disks>
</domaincheckpoint>

4. Start the backup job
[root@dell-per740xd-11 inc_bkup]# virsh backup-begin vm1 backup_full_pull.xml checkpoint_full_pull.xml
Backup started

5. Login vm and do another dd job, replace the 200M file with new data
5.1 If we do not set "error_policy='ignore'" in disk driver xml, vm will be paused 
[root@localhost tmp]# dd if=/dev/urandom of=/tmp/200M bs=1M count=200
<==== vm just hangs here due to we can only use at most 100M space in scratch file
5.2 If we set "error_policy='ignore'" in disk driver xml, nothing wrong in vm

6. No matter if we set "error_policy='ignore'", in anther terminal, event captured with a no space error
[root@dell-per740xd-11 ~]# virsh event vm1 --all --loop
event 'io-error' for domain vm1:  () pause
event 'io-error-reason' for domain vm1:  () pause due to enospc
event 'lifecycle' for domain vm1: Suspended I/O Error
event 'io-error' for domain vm1:  () pause
event 'io-error-reason' for domain vm1:  () pause due to enospc
event 'io-error' for domain vm1:  () pause
...

7. But now, the backup job still running
[root@dell-per740xd-11 ~]# virsh domjobinfo vm1
Job type:         Unbounded
Operation:        Backup
Time elapsed:     235369       ms
Temporary disk space use: 83.562 MiB
Temporary disk space total: 10.000 GiB

And we can generate a backup file
[root@dell-per740xd-11 ~]# qemu-img convert -f raw nbd://localhost:10809/vda -O qcow2 vda.full.backup
But actually, the vda.full.backup contains inconsistent data, so it's not a valid backup

Expected result:
If scratch file hit a no space error or any other IO error, we should explicitly fail the pull-mode backup job, otherwise, user may get an invalid backup file.

Comment 1 yisun 2020-03-24 14:37:39 UTC
The disk xml's error policy set as following:
[root@dell-per740xd-11 ~]# virsh dumpxml vm1 | awk '/<disk/,/<\/disk/'
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none' error_policy='ignore'/>   <=================== here
      <source file='/var/lib/libvirt/images/vda.full.backup' index='1'/>
      <backingStore/>
      <target dev='vda' bus='virtio'/>
      <alias name='virtio-disk0'/>
      <address type='pci' domain='0x0000' bus='0x04' slot='0x00' function='0x0'/>
    </disk>

Comment 2 Peter Krempa 2020-03-24 14:51:13 UTC
This might in the end be a qemu bug but I need to investigate whether setting the job error policy will help in this instance.

Comment 3 Peter Krempa 2020-03-24 15:21:35 UTC
The documentation states:

1363 # @on-source-error: the action to take on an error on the source,               
1364 #                   default 'report'.  'stop' and 'enospc' can only be used     
1365 #                   if the block device supports io-status (see BlockInfo).     
1366 #                                                                               
1367 # @on-target-error: the action to take on an error on the target,               
1368 #                   default 'report' (no limitations, since this applies to     
1369 #                   a different block device than @device).                     

[...]

Libvirt doesn't set on-target-error, so the default policy of 'report' should make the job fail.

1388 #                                                                               
1389 # Note: @on-source-error and @on-target-error only affect background            
1390 #       I/O.  If an error occurs during a guest write request, the device's     
1391 #       rerror/werror actions will be used.                                     

Even for guest-originated IO the job should fail if the output data will become corrupt in cases when the user decides to ignore the frontend error.

Moving to qemu.

Comment 4 John Ferlan 2020-03-27 11:51:44 UTC
Moving into 'triaged' backlog for now to go along with a few others that need prioritizing for resolution.

Comment 5 aihua liang 2020-09-15 09:02:37 UTC
Test on qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8, don't hit this issue.

Test Steps:
 1. Start guest with qemu cmds:
     ...
     -blockdev node-name=file_image1,driver=file,aio=threads,filename=/home/kvm_autotest_root/images/rhel830-64-virtio-scsi.qcow2,cache.direct=on,cache.no-flush=off \
    -blockdev node-name=drive_image1,driver=qcow2,cache.direct=on,cache.no-flush=off,file=file_image1 \
    -device virtio-blk-pci,id=image1,drive=drive_image1,write-cache=on,bus=pcie-root-port-2,iothread=iothread0 \
    ...

 2. Start nbd server
    {"execute":"nbd-server-start","arguments":{"addr":{"type":"inet","data":{"host":"10.73.130.203","port":"10809"}}}}

 3. Build full backup channel and scrach file created on an non-enough space
    #qemu-img create -f raw disk.img
    #mkfs.ext4 disk.img
    #mount disk.img /mnt
    #qemu-img create -f qcow2 -b /home/kvm_autotest_root/images/rhel830-64-virtio-scsi.qcow2 -F qcow2 /mnt/scratch.img
     {"execute":"blockdev-add","arguments":{"driver":"qcow2","node-name":"tmp","file":{"driver":"file","filename":"scratch.img"},"backing":"drive_image1"}}
    *****Add a dirty bitmap and do full backup with sync "none"
     { "execute": "transaction", "arguments": { "actions": [ {"type": "blockdev-backup", "data": { "device": "drive_image1", "target": "tmp", "sync": "none", "job-id":"j1" } }, {"type": "block-dirty-bitmap-add", "data": { "node": "drive_image1", "name": "bitmap0" } } ] } }
    *****Expose scratch.img
     {"execute":"nbd-server-add","arguments":{"device":"tmp"}}

  4. Create a target image and do full backup via pull mode
     #qemu-img create -f qcow2 /home/back1.img 20G
     #./copyif2.sh nbd://10.73.130.203:10809/tmp /home/back1.img

  5. After full backup finished, start guest with /home/back1.img
     ...
     -blockdev node-name=file_image1,driver=file,aio=threads,filename=/home/back1.img,cache.direct=on,cache.no-flush=off \
     -blockdev node-name=drive_image1,driver=qcow2,cache.direct=on,cache.no-flush=off,file=file_image1 \
     -device virtio-blk-pci,id=image1,drive=drive_image1,write-cache=on,bus=pcie-root-port-2,iothread=iothread0 \
    ...

In step4, no error reported and in step5, guest can start up successfully.

Note:
  #cat copyif2.sh
    copyif2() {
if test $# -lt 2 || test $# -gt 3; then
  echo 'usage: copyif src dst [bitmap]'
  return 1
fi
if test "$1" != nbd://10.73.130.203:10809/tmp; then
  echo Please fix hard-coded references to one specific source
  return 1
fi
if test -z "$3"; then
  map_from="-f raw $1"
  state=true
else
  map_from="--image-opts driver=nbd,export=tmp,server.type=inet"
  map_from+=",server.host=10.73.130.203,server.port=10809"
  map_from+=",x-dirty-bitmap=qemu:dirty-bitmap:$3"
  state=false
fi
qemu-img info -f raw $1 || return
qemu-img info -f qcow2 $2 || return
ret=0
qemu-img rebase -u -f qcow2 -F raw -b $1 $2
while read line; do
  [[ $line =~ .*start.:.([0-9]*).*length.:.([0-9]*).*data.:.$state.* ]] || continue
  start=${BASH_REMATCH[1]} len=${BASH_REMATCH[2]}
  echo
  echo " $start $len:"
  qemu-io -C -c "r $start $len" -f qcow2 $2
done < <(qemu-img map --output=json $map_from)
qemu-img rebase -u -f qcow2 -b '' $2
if test $ret = 0; then echo 'Success!'; fi
return $ret
}

copyif2 $1 $2 $3

Comment 7 yisun 2020-09-16 05:36:52 UTC
(In reply to aihua liang from comment #5)
> Test on qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8, don't hit this issue.
> 
> Test Steps:
>  1. Start guest with qemu cmds:
>      ...
>      -blockdev
> node-name=file_image1,driver=file,aio=threads,filename=/home/
> kvm_autotest_root/images/rhel830-64-virtio-scsi.qcow2,cache.direct=on,cache.
> no-flush=off \
>     -blockdev
> node-name=drive_image1,driver=qcow2,cache.direct=on,cache.no-flush=off,
> file=file_image1 \
>     -device
> virtio-blk-pci,id=image1,drive=drive_image1,write-cache=on,bus=pcie-root-
> port-2,iothread=iothread0 \
>     ...
> 
>  2. Start nbd server
>    
> {"execute":"nbd-server-start","arguments":{"addr":{"type":"inet","data":
> {"host":"10.73.130.203","port":"10809"}}}}
> 
>  3. Build full backup channel and scrach file created on an non-enough space
>     #qemu-img create -f raw disk.img
>     #mkfs.ext4 disk.img
>     #mount disk.img /mnt
>     #qemu-img create -f qcow2 -b
> /home/kvm_autotest_root/images/rhel830-64-virtio-scsi.qcow2 -F qcow2
> /mnt/scratch.img
>     
> {"execute":"blockdev-add","arguments":{"driver":"qcow2","node-name":"tmp",
> "file":{"driver":"file","filename":"scratch.img"},"backing":"drive_image1"}}
>     *****Add a dirty bitmap and do full backup with sync "none"
>      { "execute": "transaction", "arguments": { "actions": [ {"type":
> "blockdev-backup", "data": { "device": "drive_image1", "target": "tmp",
> "sync": "none", "job-id":"j1" } }, {"type": "block-dirty-bitmap-add",
> "data": { "node": "drive_image1", "name": "bitmap0" } } ] } }
>     *****Expose scratch.img
>      {"execute":"nbd-server-add","arguments":{"device":"tmp"}}
> 
>   4. Create a target image and do full backup via pull mode
>      #qemu-img create -f qcow2 /home/back1.img 20G
>      #./copyif2.sh nbd://10.73.130.203:10809/tmp /home/back1.img
> 
>   5. After full backup finished, start guest with /home/back1.img
>      ...
>      -blockdev
> node-name=file_image1,driver=file,aio=threads,filename=/home/back1.img,cache.
> direct=on,cache.no-flush=off \
>      -blockdev
> node-name=drive_image1,driver=qcow2,cache.direct=on,cache.no-flush=off,
> file=file_image1 \
>      -device
> virtio-blk-pci,id=image1,drive=drive_image1,write-cache=on,bus=pcie-root-
> port-2,iothread=iothread0 \
>     ...
> 
> In step4, no error reported and in step5, guest can start up successfully.
> 
> Note:
>   #cat copyif2.sh
>     copyif2() {
> if test $# -lt 2 || test $# -gt 3; then
>   echo 'usage: copyif src dst [bitmap]'
>   return 1
> fi
> if test "$1" != nbd://10.73.130.203:10809/tmp; then
>   echo Please fix hard-coded references to one specific source
>   return 1
> fi
> if test -z "$3"; then
>   map_from="-f raw $1"
>   state=true
> else
>   map_from="--image-opts driver=nbd,export=tmp,server.type=inet"
>   map_from+=",server.host=10.73.130.203,server.port=10809"
>   map_from+=",x-dirty-bitmap=qemu:dirty-bitmap:$3"
>   state=false
> fi
> qemu-img info -f raw $1 || return
> qemu-img info -f qcow2 $2 || return
> ret=0
> qemu-img rebase -u -f qcow2 -F raw -b $1 $2
> while read line; do
>   [[ $line =~ .*start.:.([0-9]*).*length.:.([0-9]*).*data.:.$state.* ]] ||
> continue
>   start=${BASH_REMATCH[1]} len=${BASH_REMATCH[2]}
>   echo
>   echo " $start $len:"
>   qemu-io -C -c "r $start $len" -f qcow2 $2
> done < <(qemu-img map --output=json $map_from)
> qemu-img rebase -u -f qcow2 -b '' $2
> if test $ret = 0; then echo 'Success!'; fi
> return $ret
> }
> 
> copyif2 $1 $2 $3

In this scenario, is there any step to make sure the space of the scratch file used up? I think we should generate lots of data which is bigger than the scratch file size during the backup task, and this will actually write data to scrtach file to hit the issue.

Comment 8 aihua liang 2020-09-16 09:25:08 UTC
Got the point,retest it on qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8, can reproduce this issue, and even worst, it will hit qemu coredump issue.

Test Steps:
 1. Start guest with qemu cmds:
    ...
    -blockdev node-name=file_image1,driver=file,aio=threads,filename=/home/kvm_autotest_root/images/rhel830-64-virtio-scsi.qcow2,cache.direct=on,cache.no-flush=off \
    -blockdev node-name=drive_image1,driver=qcow2,cache.direct=on,cache.no-flush=off,file=file_image1 \
    -device virtio-blk-pci,id=image1,drive=drive_image1,write-cache=on,bus=pcie-root-port-2,iothread=iothread0 \
   ...

 2. Create a small size image that will be used as storage of scratch file and dd file on it to make less space left on it.
    #qemu-img create -f raw /home/disk.img 500M
    #mkfs.ext4 /home/disk.img
    #mount /home/disk.img /mnt
    #cd /mnt
    #dd if=/dev/urandom of=test bs=1M count=400

 3. Create scratch file
    #qemu-img create -f qcow2 -b /home/kvm_autotest_root/images/rhel830-64-virtio-scsi.qcow2 -F qcow2 /mnt/scratch.img
    Formatting '/mnt/scratch.img', fmt=qcow2 cluster_size=65536 compression_type=zlib size=21474836480 backing_file=/home/kvm_autotest_root/images/rhel830-64-virtio-scsi.qcow2 backing_fmt=qcow2 lazy_refcounts=off refcount_bits=16

 4. Start ndb server, add scratch file, do full backup and expose the full backup node.
     4.1 start ndb server
    {"execute":"nbd-server-start","arguments":{"addr":{"type":"inet","data":{"host":"10.73.130.203","port":"10809"}}}}
{"return": {}}
     4.2 add scratch file
{"execute":"blockdev-add","arguments":{"driver":"qcow2","node-name":"tmp","file":{"driver":"file","filename":"/mnt/scratch.img"},"backing":"drive_image1"}}
{"return": {}}
     4.3 do full backup
{ "execute": "transaction", "arguments": { "actions": [ {"type": "blockdev-backup", "data": { "device": "drive_image1", "target": "tmp", "sync": "none", "job-id":"j1"} }, {"type": "block-dirty-bitmap-add", "data": { "node": "drive_image1", "name": "bitmap0" } } ] } }
{"timestamp": {"seconds": 1600246592, "microseconds": 837396}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "j1"}}
{"timestamp": {"seconds": 1600246592, "microseconds": 837709}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "j1"}}
{"return": {}}
     4.4 expose full backup node
{"execute":"nbd-server-add","arguments":{"device":"tmp"}}
{"return": {}}

 5. Create back1.img in dst, and do pull backup
    #qemu-img create -f qcow2 /home/back1.img 20G
    #./copyif2.sh nbd://10.73.130.203:10809/tmp /home/back1.img
    image: nbd://10.73.130.203:10809/tmp
file format: raw
virtual size: 20 GiB (21474836480 bytes)
disk size: unavailable
image: /home/back1.img
file format: qcow2
virtual size: 20 GiB (21474836480 bytes)
disk size: 196 KiB
cluster_size: 65536
Format specific information:
    compat: 1.1
    compression type: zlib
    lazy refcounts: false
    refcount bits: 16
    corrupt: false

 0 65536:
read 65536/65536 bytes at offset 0
64 KiB, 1 ops; 00.01 sec (6.824 MiB/sec and 109.1815 ops/sec)

 1048576 192151552:
read 192151552/192151552 bytes at offset 1048576
183.250 MiB, 1 ops; 0:00:01.31 (140.136 MiB/sec and 0.7647 ops/sec)

 269484032 170262528:
read 170262528/170262528 bytes at offset 269484032
162.375 MiB, 1 ops; 0:00:01.63 (99.831 MiB/sec and 0.6148 ops/sec)

  6. During pull backup running, dd a big file(larger than 1G) in guest
     (guest)#dd if=/dev/urandom of=test bs=1M count=1500

  7. Check disk.img info
     #qemu-img info /home/disk.img
image: disk.img
file format: raw
virtual size: 500 MiB (524288000 bytes)
disk size: 489 MiB


After step6, 
  1. vm report io-error.
 {"timestamp": {"seconds": 1600246645, "microseconds": 385705}, "event": "BLOCK_IO_ERROR", "data": {"device": "", "nospace": true, "node-name": "#block159", "reason": "No space left on device", "operation": "write", "action": "stop"}}
{"timestamp": {"seconds": 1600246645, "microseconds": 395179}, "event": "BLOCK_IO_ERROR", "data": {"device": "", "nospace": true, "node-name": "#block159", "reason": "No space left on device", "operation": "write", "action": "stop"}}
{"timestamp": {"seconds": 1600246645, "microseconds": 395372}, "event": "BLOCK_IO_ERROR", "data": {"device": "", "nospace": true, "node-name": "#block159", "reason": "No space left on device", "operation": "write", "action": "stop"}}
 2. qemu coredump with info:
    (qemu) aio_co_schedule: Co-routine was already scheduled in 'aio_co_schedule'
bug.txt: line 47: 101280 Aborted                 (core dumped) /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 11264 -smp 2,maxcpus=2,cores=1,threads=1,dies=1,sockets=2 ...

 3. backup pull failed in dst.
    7785676800 637403136:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused

 8424194048 718077952:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused

 9142337536 71499776:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused

 12348030976 819003392:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused

 13173587968 65536:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused

 13173719040 23396352:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused

 13197180928 3206807552:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused

 16910385152 1051328512:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused

 21472608256 131072:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused

 21474770944 65536:
qemu-io: can't open device /home/back1.img: Could not open backing file: Failed to connect socket: Connection refused


Gdb info of coredump as bellow:
  (gdb) bt
#0  0x00007f182755f7ff in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f1827549c35 in __GI_abort () at abort.c:79
#2  0x00007f1827549b09 in __assert_fail_base
    (fmt=0x7f18276afcf0 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x556c18697b8a "is_power_of_2(align)", file=0x556c18697348 "/builddir/build/BUILD/qemu-5.1.0/block/io.c", line=1464, function=<optimized out>) at assert.c:92
#3  0x00007f1827557de6 in __GI___assert_fail
    (assertion=assertion@entry=0x556c18697b8a "is_power_of_2(align)", file=file@entry=0x556c18697348 "/builddir/build/BUILD/qemu-5.1.0/block/io.c", line=line@entry=1464, function=function@entry=0x556c18697ed0 <__PRETTY_FUNCTION__.27260> "bdrv_aligned_preadv") at assert.c:101
#4  0x0000556c18482a5f in bdrv_aligned_preadv
    (child=child@entry=0x556c1970a380, req=req@entry=0x7f182c99f990, offset=<optimized out>, bytes=0, align=<optimized out>, qiov=0x7f182c99fa20, qiov_offset=0, flags=0)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/io.c:1464
#5  0x0000556c18483021 in bdrv_co_preadv_part (child=0x556c1970a380, offset=<optimized out>, bytes=<optimized out>, 
    bytes@entry=16384, qiov=<optimized out>, qiov@entry=0x7f181400d4f8, qiov_offset=<optimized out>, 
    qiov_offset@entry=0, flags=flags@entry=0)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/io.c:1757
#6  0x0000556c1844eec9 in qcow2_co_preadv_task
    (qiov_offset=0, qiov=0x7f181400d4f8, bytes=16384, offset=<optimized out>, file_cluster_offset=<optimized out>, cluster_type=<optimized out>, bs=0x556c19845a10) at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/qcow2.c:2254
#7  0x0000556c1844eec9 in qcow2_co_preadv_task_entry (task=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/qcow2.c:2271
#8  0x0000556c1844cfd5 in qcow2_add_task
    (bs=bs@entry=0x556c19845a10, pool=pool@entry=0x0, func=func@entry=0x556c1844edf0 <qcow2_co_preadv_task_entry>, cluster_type=cluster_type@entry=QCOW2_CLUSTER_NORMAL, file_cluster_offset=2004877312, offset=offset@entry=3955212288, bytes=16384, qiov=0x7f181400d4f8, qiov_offset=0, l2meta=0x0)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/qcow2.c:2211
#9  0x0000556c1844e70d in qcow2_co_preadv_part
    (bs=0x556c19845a10, offset=3955212288, bytes=16384, qiov=0x7f181400d4f8, qiov_offset=0, flags=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/qcow2.c:2310
#10 0x0000556c1847f1c8 in bdrv_driver_preadv
--Type <RET> for more, q to quit, c to continue without paging--
    (bs=bs@entry=0x556c19845a10, offset=offset@entry=3955212288, bytes=bytes@entry=16384, qiov=qiov@entry=0x7f181400d4f8, qiov_offset=qiov_offset@entry=0, flags=0) at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/io.c:1129
#11 0x0000556c18482a86 in bdrv_aligned_preadv
    (child=child@entry=0x556c1983c240, req=req@entry=0x7f182c99fe60, offset=3955212288, bytes=16384, align=1, qiov=0x7f181400d4f8, qiov_offset=0, flags=0) at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/io.c:1515
#12 0x0000556c18483021 in bdrv_co_preadv_part (child=0x556c1983c240, offset=<optimized out>, 
    offset@entry=3955212288, bytes=<optimized out>, bytes@entry=16384, qiov=<optimized out>, 
    qiov@entry=0x7f181400d4f8, qiov_offset=<optimized out>, qiov_offset@entry=0, flags=flags@entry=0)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/io.c:1757
#13 0x0000556c1848309f in bdrv_co_preadv
    (child=<optimized out>, offset=offset@entry=3955212288, bytes=bytes@entry=16384, qiov=qiov@entry=0x7f181400d4f8, flags=flags@entry=0) at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/io.c:1715
#14 0x0000556c184706e7 in blk_do_preadv (blk=0x556c1a91ae90, offset=3955212288, bytes=16384, qiov=0x7f181400d4f8, flags=0)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/block-backend.c:1211
#15 0x0000556c1847079a in blk_aio_read_entry (opaque=0x7f18140101c0)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/block-backend.c:1464
#16 0x0000556c18511ff3 in coroutine_trampoline (i0=<optimized out>, i1=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/util/coroutine-ucontext.c:173
#17 0x00007f18275753d0 in __start_context () at ../sysdeps/unix/sysv/linux/x86_64/__start_context.S:91
#18 0x00007ffed3397c30 in  ()
#19 0x0000000000000000 in  ()

Note: 
  If we have more free space than that I set in my test, we can finish the pull backup with an incomplete backup image as that in sunyi's description.

  Coredump file located at:
   10.73.194.27:/vol/s2coredump/bz1816692/core.qemu-kvm.0.25d3d2d17fce4fcc9f5305deee6423d2.99154.1600245240000000.lz4

Comment 9 aihua liang 2020-09-16 10:05:43 UTC
Sorry, wrong coredump info in comment 8, correct it here.

 Coredump info:
   (qemu) aio_co_schedule: Co-routine was already scheduled in 'aio_co_schedule'
bug.txt: line 47: 104712 Aborted                 (core dumped) /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 11264 -smp 2,maxcpus=2,cores=1,threads=1,dies=1,sockets=2 -cpu 'Penryn',+kvm_pv_unhalt ...

 gdb info:
  (gdb) bt
#0  0x00007fd7761c77ff in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007fd7761b1c35 in __GI_abort () at abort.c:79
#2  0x0000564847ae12b1 in aio_co_schedule (ctx=<optimized out>, co=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/util/async.c:546
#3  0x0000564847a6444d in blk_aio_attached (ctx=0x564848efca70, opaque=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/nbd/server.c:1474
#4  0x0000564847a082d5 in bdrv_attach_aio_context (new_context=0x564848efca70, bs=0x5648490dd400)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block.c:6297
#5  0x0000564847a082d5 in bdrv_set_aio_context_ignore (bs=0x5648490dd400, new_context=0x564848efca70, ignore=0x7fff6bedff20)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block.c:6353
#6  0x0000564847a08176 in bdrv_set_aio_context_ignore
    (bs=0x564848f1da10, new_context=new_context@entry=0x564848efca70, ignore=ignore@entry=0x7fff6bedff20)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block.c:6343
#7  0x0000564847a0834c in bdrv_set_aio_context_ignore
    (bs=bs@entry=0x564848fed360, new_context=new_context@entry=0x564848efca70, ignore=ignore@entry=0x7fff6bedff20)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block.c:6335
#8  0x0000564847a086c3 in bdrv_child_try_set_aio_context
    (bs=bs@entry=0x564848fed360, ctx=0x564848efca70, ignore_child=<optimized out>, errp=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block.c:6450
#9  0x0000564847a3ed4b in blk_do_set_aio_context
    (blk=0x564849ff2e90, new_context=0x564848efca70, update_root_node=update_root_node@entry=true, errp=errp@entry=0x0)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/block-backend.c:2026
#10 0x0000564847a41451 in blk_set_aio_context (blk=<optimized out>, new_context=<optimized out>, errp=errp@entry=0x0)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/block/block-backend.c:2047
#11 0x00005648477d4944 in virtio_blk_data_plane_stop (vdev=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/hw/block/dataplane/virtio-blk.c:300
#12 0x00005648479858d0 in virtio_bus_stop_ioeventfd (bus=0x564849fef638)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/hw/virtio/virtio-bus.c:245
#13 0x00005648477fb28e in virtio_vmstate_change (opaque=0x564849fef6c0, running=0, state=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/hw/virtio/virtio.c:3221
#14 0x000056484783e0ad in vm_state_notify (running=running@entry=0, state=state@entry=RUN_STATE_IO_ERROR)
--Type <RET> for more, q to quit, c to continue without paging--
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/softmmu/vl.c:1287
#15 0x00005648478314b2 in do_vm_stop (state=RUN_STATE_IO_ERROR, send_stop=send_stop@entry=true)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/softmmu/cpus.c:974
#16 0x00005648478319b2 in vm_stop (state=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/softmmu/cpus.c:2071
#17 0x000056484783e851 in main_loop_should_exit ()
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/softmmu/vl.c:1662
#18 0x000056484783e851 in qemu_main_loop ()
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/softmmu/vl.c:1672
#19 0x000056484775ca32 in main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>)
    at /usr/src/debug/qemu-kvm-5.1.0-6.module+el8.3.0+8041+42ff16b8.x86_64/softmmu/main.c:49

 Corefile located at:
  10.73.194.27:/vol/s2coredump/bz1816692/core.qemu-kvm.0.25d3d2d17fce4fcc9f5305deee6423d2.104712.1600250321000000.lz4

Comment 11 Gu Nini 2021-01-12 09:28:21 UTC
I could reproduce the bug on RHELAV 8.4.0 according the steps in comment 8, however, the '"BLOCK_IO_ERROR" ... "No space left on device"' event occurred in qmp even just after step4 and before step5:

{"execute":"qmp_capabilities"}
{"return": {}}
{"timestamp": {"seconds": 1610441180, "microseconds": 540459}, "event": "RTC_CHANGE", "data": {"offset": 1}}
{"execute":"blockdev-add","arguments":{"driver":"file","filename":"/mnt/scratch.img","node-name":"libvirt-3-storage","auto-read-only":true,"discard":"unmap"},"id":"libvirt-411"}
{"return": {}, "id": "libvirt-411"}
{"execute":"blockdev-add","arguments":{"node-name":"tmp","read-only":false,"driver":"qcow2","file":"libvirt-3-storage","backing":"drive_image1"},"id":"libvirt-412"}
{"return": {}, "id": "libvirt-412"}
{ "execute": "transaction", "arguments": { "actions": [ {"type": "blockdev-backup", "data": { "device": "drive_image1", "target": "tmp", "sync": "none", "job-id":"j1" } }, {"type": "block-dirty-bitmap-add", "data": { "node": "drive_image1", "name": "bitmap0" } } ] } }
{"timestamp": {"seconds": 1610441788, "microseconds": 738382}, "event": "JOB_STATUS_CHANGE", "data": {"status": "created", "id": "j1"}}
{"timestamp": {"seconds": 1610441788, "microseconds": 738442}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "j1"}}
{"timestamp": {"seconds": 1610441788, "microseconds": 738469}, "event": "JOB_STATUS_CHANGE", "data": {"status": "paused", "id": "j1"}}
{"timestamp": {"seconds": 1610441788, "microseconds": 738497}, "event": "JOB_STATUS_CHANGE", "data": {"status": "running", "id": "j1"}}
{"return": {}}
{"execute":"nbd-server-start","arguments":{"addr":{"type":"inet","data":{"host":"10.16.214.94","port":"10809"}}}}
{"return": {}}
{"execute":"block-export-add","arguments":{"id": "export0", "node-name": "tmp", "type": "nbd"}}
{"return": {}}
{"timestamp": {"seconds": 1610441876, "microseconds": 510531}, "event": "RTC_CHANGE", "data": {"offset": 1}}
{"timestamp": {"seconds": 1610442061, "microseconds": 213829}, "event": "BLOCK_IO_ERROR", "data": {"device": "", "nospace": true, "node-name": "#block077", "reason": "No space left on device", "operation": "write", "action": "stop"}}
......
{"timestamp": {"seconds": 1610442061, "microseconds": 216143}, "event": "BLOCK_IO_ERROR", "data": {"device": "", "nospace": true, "node-name": "#block077", "reason": "No space left on device", "operation": "write", "action": "stop"}}
{"timestamp": {"seconds": 1610442061, "microseconds": 231027}, "event": "STOP"}


Also please note the qemu core dump in comment 8 should be the same issue of bz1900326 which need iothread enabled, if without iothread, the core dump can't be triggered.


Host kernel: 4.18.0-269.el8.dt3.ppc64le
Guest kernel: 4.18.0-259.el8.ppc64le
Qemu: qemu-kvm-5.2.0-2.module+el8.4.0+9186+ec44380f.ppc64le
SLOF: SLOF-20200717-1.gite18ddad8.module+el8.4.0+8855+a9e237a9.noarch

Comment 13 John Ferlan 2021-09-08 22:02:41 UTC
Bulk update: Move RHEL-AV bugs to RHEL8.

Comment 14 RHEL Program Management 2021-09-24 07:26:57 UTC
After evaluating this issue, there are no plans to address it further or fix it in an upcoming release.  Therefore, it is being closed.  If plans change such that this issue will be fixed in an upcoming release, then the bug can be reopened.

Comment 15 aihua liang 2021-10-13 08:33:06 UTC
Test on qemu-kvm-6.1.0-2.el9, don't hit this issue any more.

Comment 16 aihua liang 2021-10-13 08:34:10 UTC
Test on qemu-kvm-6.1.0-2.el9, don't hit the coredump issue in comment 8 any more.