Bug 2124856

Additional Info:
based on Description env, the memory of vm is 1024
but when I try install vm with -m 4096 in the same host, the vm will migrate successfully

Hi Lei,

I've started working on this. At the moment I fail to reproduce unfortunately, at least on ARM. I am testing at qemu level, using -m 1G and vhost-net. At the moment I try to migrate on the same host. Do you get the error also when migrating on the same host? In case you do, may I have access to your setup?

Thank you in advance

Eric

(In reply to Eric Auger from comment #7)
> Hi Lei,
> 
> I've started working on this. At the moment I fail to reproduce
> unfortunately, at least on ARM. I am testing at qemu level, using -m 1G and
> vhost-net. At the moment I try to migrate on the same host. Do you get the
> error also when migrating on the same host? In case you do, may I have
> access to your setup?
> 
> Thank you in advance
> 
> Eric

hello Eric

I tried to test this bug on QE's env, When the guest using -m 1G, it can not start up. QE not sure is this a new issue, if yes, please let me know, I will file a new bug.

Host ip: 10.73.210.76
Host passwd: redhat
script: /root/src.sh /root/dst.sh

Best Regards
Lei

(In reply to Lei Yang from comment #8)
> (In reply to Eric Auger from comment #7)
> > Hi Lei,
> > 
> > I've started working on this. At the moment I fail to reproduce
> > unfortunately, at least on ARM. I am testing at qemu level, using -m 1G and
> > vhost-net. At the moment I try to migrate on the same host. Do you get the
> > error also when migrating on the same host? In case you do, may I have
> > access to your setup?
> > 
> > Thank you in advance
> > 
> > Eric
> 
> hello Eric
> 
> I tried to test this bug on QE's env, When the guest using -m 1G, it can not
> start up. QE not sure is this a new issue, if yes, please let me know, I
> will file a new bug.
> 
> Host ip: 10.73.210.76
> Host passwd: redhat
> script: /root/src.sh /root/dst.sh
> 
> Best Regards
> Lei

So you mean this is a regression? You were able to run with 1G before. What has changed since your last attempt? Are you running on ARM or x86?

(In reply to Eric Auger from comment #9)
> (In reply to Lei Yang from comment #8)
> > (In reply to Eric Auger from comment #7)
> > > Hi Lei,
> > > 
> > > I've started working on this. At the moment I fail to reproduce
> > > unfortunately, at least on ARM. I am testing at qemu level, using -m 1G and
> > > vhost-net. At the moment I try to migrate on the same host. Do you get the
> > > error also when migrating on the same host? In case you do, may I have
> > > access to your setup?
> > > 
> > > Thank you in advance
> > > 
> > > Eric
> > 
> > hello Eric
> > 
> > I tried to test this bug on QE's env, When the guest using -m 1G, it can not
> > start up. QE not sure is this a new issue, if yes, please let me know, I
> > will file a new bug.
> > 
> > Host ip: 10.73.210.76
> > Host passwd: redhat
> > script: /root/src.sh /root/dst.sh
> > 
> > Best Regards
> > Lei
> 
> So you mean this is a regression? You were able to run with 1G before. What
> has changed since your last attempt? Are you running on ARM or x86?

I am not sure whether is a regression bug. But after testing it can be determined that this is not caused by separate qemu and kernel。 I tried to test it "-m 2G", guest can start up succeed. This makes me have to confirm a question, 1G or 2G whether can meet the minimum memory used by rhel?

Accordnig to this doc [1], the rhel9 required minimum memory is 1.5G. So first of all this bug is not a valid usage, on the other hands, QE tried to test it on the latest version with "-m 1.5", there is no issues any more.

Test Version:
qemu-kvm-7.1.0-4.el9.x86_64
kernel-5.14.0-187.el9.x86_64
edk2-ovmf-20220826gitba0e0e4c6a-1.el9.noarch

qemu cmd:
/usr/libexec/qemu-kvm \
-name 'avocado-vt-vm1'  \
-sandbox on  \
-blockdev node-name=file_ovmf_code,driver=file,filename=/usr/share/OVMF/OVMF_CODE.secboot.fd,auto-read-only=on,discard=unmap \
-blockdev node-name=drive_ovmf_code,driver=raw,read-only=on,file=file_ovmf_code \
-blockdev node-name=file_ovmf_vars,driver=file,filename=/root/avocado/data/avocado-vt/avocado-vt-vm1_rhel920-64-virtio-scsi_qcow2_filesystem_VARS.fd,auto-read-only=on,discard=unmap \
-blockdev node-name=drive_ovmf_vars,driver=raw,read-only=off,file=file_ovmf_vars \
-machine q35,memory-backend=mem-machine_mem,pflash0=drive_ovmf_code,pflash1=drive_ovmf_vars \
-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 \
-device '{"driver":"virtio-iommu","bus":"pcie.0","addr":"0x4"}' \
-m 1536 \
-object '{"qom-type": "memory-backend-ram", "size": 1610612736, "id": "mem-machine_mem"}'  \
-smp 16,maxcpus=16,cores=8,threads=1,dies=1,sockets=2  \
-cpu 'Cascadelake-Server',ss=on,vmx=on,pdcm=on,hypervisor=on,tsc-adjust=on,umip=on,pku=on,md-clear=on,stibp=on,arch-capabilities=on,xsaves=on,ibpb=on,ibrs=on,amd-stibp=on,amd-ssbd=on,rdctl-no=on,ibrs-all=on,skip-l1dfl-vmentry=on,mds-no=on,pschange-mc-no=on,tsx-ctrl=on,hle=off,rtm=off,kvm_pv_unhalt=on \
-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 '{"id": "virtio_scsi_pci0", "driver": "virtio-scsi-pci", "bus": "pcie-root-port-2", "addr": "0x0"}' \
-blockdev '{"node-name": "file_image1", "driver": "file", "auto-read-only": true, "discard": "unmap", "aio": "threads", "filename": "/home/kvm_autotest_root/images/rhel920-64-virtio-scsi.qcow2", "cache": {"direct": true, "no-flush": false}}' \
-blockdev '{"node-name": "drive_image1", "driver": "qcow2", "read-only": false, "cache": {"direct": true, "no-flush": false}, "file": "file_image1"}' \
-device '{"driver": "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:d8:c1:96:c2:8c,id=idepUy49,netdev=id2UOOFL,bus=pcie-root-port-3,addr=0x0  \
-netdev tap,id=id2UOOFL,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:5555,server,nowait \

==>Additional info:
QE also tried to downgrade the qemu to qemu-kvm-7.0.0-12.el9.x86_64, and the other env exactly same as above, guest can live migration successfully.

[1]https://access.redhat.com/articles/rhel-limits#minimum-required-memory-3

Hello Eric

Based on the comment 11, whether continue to debug this bug? If continue, QE will reinstall test host to the rhel9.1, then test it again. If not, maybe this bug should be close as "NOTABUG", since the bug usage method is a invalid case. Please let me know if there are any testing need be done from the QE.

Thanks
Lei

Hi Lei,

I would prefer we try to reproduce the issue again on rhel9.1. 

To summarize, with vhost=on and 1GB guest we got:

qemu-kvm: ../hw/virtio/vhost.c:81: void vhost_dev_sync_region(struct vhost_dev *, MemoryRegionSection *, uint64_t, uint64_t, uint64_t, uint64_t): Assertion `end / VHOST_LOG_CHUNK < dev->log_size' failed.
2022-09-07 09:11:49.022+0000: shutting down, reason=crashed

Without vhost we got:
(qemu) qemu-kvm: virtio_iommu_translate no mapping for 0x34b49002 for sid=1024
qemu-kvm: VQ 0 size 0x100 Guest index 0x0 inconsistent with Host index 0x99a: delta 0xf666
qemu-kvm: VQ 1 size 0x100 Guest index 0x0 inconsistent with Host index 0x584: delta 0xfa7c

If this can be reproduced again, I would be grateful to you if you could let me access the machine.

Thank you in advance

Eric

(In reply to Eric Auger from comment #13)
> Hi Lei,
> 
> I would prefer we try to reproduce the issue again on rhel9.1. 
> 
> To summarize, with vhost=on and 1GB guest we got:
> 
> qemu-kvm: ../hw/virtio/vhost.c:81: void vhost_dev_sync_region(struct
> vhost_dev *, MemoryRegionSection *, uint64_t, uint64_t, uint64_t, uint64_t):
> Assertion `end / VHOST_LOG_CHUNK < dev->log_size' failed.
> 2022-09-07 09:11:49.022+0000: shutting down, reason=crashed
> 
> Without vhost we got:
> (qemu) qemu-kvm: virtio_iommu_translate no mapping for 0x34b49002 for
> sid=1024
> qemu-kvm: VQ 0 size 0x100 Guest index 0x0 inconsistent with Host index
> 0x99a: delta 0xf666
> qemu-kvm: VQ 1 size 0x100 Guest index 0x0 inconsistent with Host index
> 0x584: delta 0xfa7c
> 
> If this can be reproduced again, I would be grateful to you if you could let
> me access the machine.
> 
> Thank you in advance
> 
> Eric

Hello Eric

I can got the above test result in the past, since I can reproduced in the past,which like be mention on Comment 1. However, when I tried to install a machine with rhel9.1 and boot up this guest with 1G memory, which can not boot up successfully. en, I can not sure which component block it, could you please help review it? 

Host IP: 10.73.210.48
Host passwd: kvmautotest
Guest script: /root/src.sh && /root/dst.sh

Thanks
Lei

Hello Eric

Now, QE can reproduced this problem again,QE found that only using "Q35 + Seabios" can start the guest with 1G memory.This is also the reason why it has been unable to start successfully before, because the default ovmf on rhel9 has been used before.

Thanks
Lei

(In reply to Lei Yang from comment #14)
> (In reply to Eric Auger from comment #13)
> > Hi Lei,
> > 
> > I would prefer we try to reproduce the issue again on rhel9.1. 
> > 
> > To summarize, with vhost=on and 1GB guest we got:
> > 
> > qemu-kvm: ../hw/virtio/vhost.c:81: void vhost_dev_sync_region(struct
> > vhost_dev *, MemoryRegionSection *, uint64_t, uint64_t, uint64_t, uint64_t):
> > Assertion `end / VHOST_LOG_CHUNK < dev->log_size' failed.
> > 2022-09-07 09:11:49.022+0000: shutting down, reason=crashed
> > 
> > Without vhost we got:
> > (qemu) qemu-kvm: virtio_iommu_translate no mapping for 0x34b49002 for
> > sid=1024
> > qemu-kvm: VQ 0 size 0x100 Guest index 0x0 inconsistent with Host index
> > 0x99a: delta 0xf666
> > qemu-kvm: VQ 1 size 0x100 Guest index 0x0 inconsistent with Host index
> > 0x584: delta 0xfa7c
> > 
> > If this can be reproduced again, I would be grateful to you if you could let
> > me access the machine.
> > 
> > Thank you in advance
> > 
> > Eric
> 
> Hello Eric
> 
> I can got the above test result in the past, since I can reproduced in the
> past,which like be mention on Comment 1. However, when I tried to install a
> machine with rhel9.1 and boot up this guest with 1G memory, which can not
> boot up successfully. en, I can not sure which component block it, could you
> please help review it? 
> 
> Host IP: 10.73.210.48
> Host passwd: kvmautotest
> Guest script: /root/src.sh && /root/dst.sh
> 
> Thanks
> Lei

Hi Lei, I mistakenly altered the src.sh. Do you have means to restore? What is the root pwd of the guest? Are you using virt-install when installing the guest. Can you paste your cmd line? Thanks. Eric

(In reply to Lei Yang from comment #15)
> Hello Eric
> 
> Now, QE can reproduced this problem again,QE found that only using "Q35 +
> Seabios" can start the guest with 1G memory.This is also the reason why it
> has been unable to start successfully before, because the default ovmf on
> rhel9 has been used before.
> 
> Thanks
> Lei

Can you paste the associated cmd line please. Is it on the same machine?

(In reply to Eric Auger from comment #17)
> (In reply to Lei Yang from comment #15)
> > Hello Eric
> > 
> > Now, QE can reproduced this problem again,QE found that only using "Q35 +
> > Seabios" can start the guest with 1G memory.This is also the reason why it
> > has been unable to start successfully before, because the default ovmf on
> > rhel9 has been used before.
> > 
> > Thanks
> > Lei
> 
> Can you paste the associated cmd line please. Is it on the same machine?

Sure, they are use the same environment. Now the src.sh has been restore. And vm passwd same as host.

qemu cmd:
/usr/libexec/qemu-kvm \
-name 'avocado-vt-vm1'  \
-sandbox on  \
-machine q35,memory-backend=mem-machine_mem \
-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 '{"driver":"virtio-iommu","bus":"pcie.0","addr":"0x4"}' \
-device VGA,bus=pcie.0,addr=0x2 \
-m 1024 \
-object memory-backend-ram,size=1024M,id=mem-machine_mem  \
-smp 6,maxcpus=6,cores=3,threads=1,dies=1,sockets=2  \
-cpu 'Haswell-noTSX-IBRS',vme=on,ss=on,vmx=on,pdcm=on,f16c=on,rdrand=on,hypervisor=on,arat=on,tsc-adjust=on,umip=on,md-clear=on,stibp=on,arch-capabilities=on,ssbd=on,xsaveopt=on,pdpe1gb=on,abm=on,ibpb=on,ibrs=on,amd-stibp=on,amd-ssbd=on,skip-l1dfl-vmentry=on,pschange-mc-no=on,kvm_pv_unhalt=on \
-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/rhel910-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,iommu_platform=on,mac=9a:ac:5a:d7:18:8e,id=id0DVAMO,netdev=id4Im3rr,bus=pcie-root-port-3,addr=0x0  \
-netdev tap,id=id4Im3rr,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:5555,server,nowait \

(In reply to Lei Yang from comment #18)
> (In reply to Eric Auger from comment #17)
> > (In reply to Lei Yang from comment #15)
> > > Hello Eric
> > > 
> > > Now, QE can reproduced this problem again,QE found that only using "Q35 +
> > > Seabios" can start the guest with 1G memory.This is also the reason why it
> > > has been unable to start successfully before, because the default ovmf on
> > > rhel9 has been used before.
> > > 
> > > Thanks
> > > Lei
> > 
> > Can you paste the associated cmd line please. Is it on the same machine?
> 
> Sure, they are use the same environment. Now the src.sh has been restore.
> And vm passwd same as host.
> 
> qemu cmd:
> /usr/libexec/qemu-kvm \
> -name 'avocado-vt-vm1'  \
> -sandbox on  \
> -machine q35,memory-backend=mem-machine_mem \
> -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 '{"driver":"virtio-iommu","bus":"pcie.0","addr":"0x4"}' \
> -device VGA,bus=pcie.0,addr=0x2 \
> -m 1024 \
> -object memory-backend-ram,size=1024M,id=mem-machine_mem  \
> -smp 6,maxcpus=6,cores=3,threads=1,dies=1,sockets=2  \
> -cpu
> 'Haswell-noTSX-IBRS',vme=on,ss=on,vmx=on,pdcm=on,f16c=on,rdrand=on,
> hypervisor=on,arat=on,tsc-adjust=on,umip=on,md-clear=on,stibp=on,arch-
> capabilities=on,ssbd=on,xsaveopt=on,pdpe1gb=on,abm=on,ibpb=on,ibrs=on,amd-
> stibp=on,amd-ssbd=on,skip-l1dfl-vmentry=on,pschange-mc-no=on,
> kvm_pv_unhalt=on \
> -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/rhel910-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,iommu_platform=on,mac=9a:ac:5a:d7:18:8e,id=id0DVAMO,
> netdev=id4Im3rr,bus=pcie-root-port-3,addr=0x0  \
> -netdev tap,id=id4Im3rr,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:5555,server,nowait \

OK Thanks! Working on it today. So I can start the guest successfully with src.sh

Hi Lei, can I have access to the console of this machine. I would like to update the kernel and reboot. I confirm that it is not related to qemu because I hit the same issue with an upstream qemu.

I can reproduce the issue with virtio-iommu and vhost-net. With intel-iommu and without any iommu I do not hit the issue. However I am not sure this is virtio-iommu related.

I observe the following:

Last time vhost_get_log_size() is called it takes into account 2 regions when computing the log_size:
qemu-system-x86_64: vhost_get_log_size region 0 last=0x9ffff updated log_size=0x3
qemu-system-x86_64: vhost_get_log_size region 1 last=0x3fffffff updated log_size=0x1000
so in vhost_migration_log() vhost_get_log_size(dev) returns 0x1000

However memory_region_sync_dirty_bitmap() calls vhost listener->log_sync, it does it for more than 2 MemroyRegionSections:
it does it for mem-machine_mem, vga.vram (several times) and eventually on pc.bios. This latter is reponsible for the assertion:

qemu-system-x86_64: vhost_log_sync calls sync_dirty_map on pc.bios for the full range
qemu-system-x86_64: vhost_sync_dirty_bitmap calls vhost_dev_sync_region on region 0
qemu-system-x86_64: vhost_dev_sync_region end=0x9ffff < start=0xfffc0000
qemu-system-x86_64: vhost_sync_dirty_bitmap calls vhost_dev_sync_region on region 1
qemu-system-x86_64: vhost_dev_sync_region end=0x3fffffff < start=0xfffc0000
qemu-system-x86_64: vhost_sync_dirty_bitmap calls vhost_dev_sync_region on vq 0 <-----
qemu-system-x86_64: vhost_dev_sync_region pc.bios mfirst=0xfffc0000 mlast=0xffffffff rfirst=0xfffff240 rlast=0xfffffa45
qemu-system-x86_64: vhost_dev_sync_region pc.bios end=0xfffffa45 VHOST_LOG_CHUNK=0x40000 end/VHOST_LOG_CHUNK=0x3fff dev->log_size=0x1000
qemu-system-x86_64: ../hw/virtio/vhost.c:85: vhost_dev_sync_region: Assertion `end / VHOST_LOG_CHUNK < dev->log_size' failed.

Looks like the 'end' has not been taken into account in log_size computation.

Jason, any idea?



#5  0x0000555555b03425 in vhost_dev_sync_region
    (dev=dev@entry=0x5555565a9530, section=section@entry=0x7ffeaeffc480, mfirst=mfirst@entry=4294705152, mlast=mlast@entry=4294967295, rfirst=<optimized out>, rlast=<optimized out>)
    at ../hw/virtio/vhost.c:84
#6  0x0000555555b03e09 in vhost_sync_dirty_bitmap (dev=dev@entry=0x5555565a9530, section=section@entry=0x7ffeaeffc480, first=first@entry=0, last=last@entry=18446744073709551615)
    at ../hw/virtio/vhost.c:144
#7  0x0000555555b03fc9 in vhost_log_sync (listener=0x5555565a9538, section=0x7ffeaeffc480) at ../hw/virtio/vhost.c:156
#8  0x0000555555b2f830 in memory_region_sync_dirty_bitmap (mr=mr@entry=0x0) at ../softmmu/memory.c:2174
#9  0x0000555555b34587 in memory_global_dirty_log_sync () at ../softmmu/memory.c:2784
#10 0x0000555555b4a16e in migration_bitmap_sync (rs=rs@entry=0x7ffea4001630) at ../migration/ram.c:1183
#11 0x0000555555b4a94c in migration_bitmap_sync_precopy (rs=rs@entry=0x7ffea4001630) at ../migration/ram.c:1230
#12 0x0000555555b4be62 in ram_init_bitmaps (rs=0x7ffea4001630) at ../migration/ram.c:3077
#13 ram_init_all (rsp=<optimized out>) at ../migration/ram.c:3101
#14 ram_save_setup (f=0x5555568fe1b0, opaque=<optimized out>) at ../migration/ram.c:3214

with intel-iommu, vhost_dev_sync_region is also called on ps-bios MRS but in vhost_dev_sync_region() we enter the
if (end < start) {
    return;
}
so we do not hit the assert.

(In reply to Eric Auger from comment #25)
> I can reproduce the issue with virtio-iommu and vhost-net. With intel-iommu
> and without any iommu I do not hit the issue. However I am not sure this is
> virtio-iommu related.
> 
> I observe the following:
> 
> Last time vhost_get_log_size() is called it takes into account 2 regions
> when computing the log_size:
> qemu-system-x86_64: vhost_get_log_size region 0 last=0x9ffff updated
> log_size=0x3
> qemu-system-x86_64: vhost_get_log_size region 1 last=0x3fffffff updated
> log_size=0x1000
> so in vhost_migration_log() vhost_get_log_size(dev) returns 0x1000
> 
> However memory_region_sync_dirty_bitmap() calls vhost listener->log_sync, it
> does it for more than 2 MemroyRegionSections:
> it does it for mem-machine_mem, vga.vram (several times) and eventually on
> pc.bios. This latter is reponsible for the assertion:
> 
> qemu-system-x86_64: vhost_log_sync calls sync_dirty_map on pc.bios for the
> full range
> qemu-system-x86_64: vhost_sync_dirty_bitmap calls vhost_dev_sync_region on
> region 0
> qemu-system-x86_64: vhost_dev_sync_region end=0x9ffff < start=0xfffc0000
> qemu-system-x86_64: vhost_sync_dirty_bitmap calls vhost_dev_sync_region on
> region 1
> qemu-system-x86_64: vhost_dev_sync_region end=0x3fffffff < start=0xfffc0000
> qemu-system-x86_64: vhost_sync_dirty_bitmap calls vhost_dev_sync_region on
> vq 0 <-----
> qemu-system-x86_64: vhost_dev_sync_region pc.bios mfirst=0xfffc0000
> mlast=0xffffffff rfirst=0xfffff240 rlast=0xfffffa45
> qemu-system-x86_64: vhost_dev_sync_region pc.bios end=0xfffffa45
> VHOST_LOG_CHUNK=0x40000 end/VHOST_LOG_CHUNK=0x3fff dev->log_size=0x1000
> qemu-system-x86_64: ../hw/virtio/vhost.c:85: vhost_dev_sync_region:
> Assertion `end / VHOST_LOG_CHUNK < dev->log_size' failed.
> 
> Looks like the 'end' has not been taken into account in log_size computation.
> 
> Jason, any idea?

Looks like the end here is IOVA not GPA. I suspect it is the root cause and why we see it is out of the range of the log.

The vq->used_phys were set during vhost_virtqueue_start():

    vq->used_phys = a = virtio_queue_get_used_addr(vdev, idx);

When vIOMMU is enabled, it is IOVA (I admit the name is confusing).

So when we sync used ring, we should convert it to GPA. I've draft a patch (I can't reproduce this issue by myself, but the patch pass the migration smoking test).

Lei, please give a try, and in order to not lose any dirty pages I suggest to test (assuming we won't hit the assertion any more):

migration while doing an large file scp to the guest, and compare the md5.

Thanks

> 
> 
> 
> #5  0x0000555555b03425 in vhost_dev_sync_region
>     (dev=dev@entry=0x5555565a9530, section=section@entry=0x7ffeaeffc480,
> mfirst=mfirst@entry=4294705152, mlast=mlast@entry=4294967295,
> rfirst=<optimized out>, rlast=<optimized out>)
>     at ../hw/virtio/vhost.c:84
> #6  0x0000555555b03e09 in vhost_sync_dirty_bitmap
> (dev=dev@entry=0x5555565a9530, section=section@entry=0x7ffeaeffc480,
> first=first@entry=0, last=last@entry=18446744073709551615)
>     at ../hw/virtio/vhost.c:144
> #7  0x0000555555b03fc9 in vhost_log_sync (listener=0x5555565a9538,
> section=0x7ffeaeffc480) at ../hw/virtio/vhost.c:156
> #8  0x0000555555b2f830 in memory_region_sync_dirty_bitmap (mr=mr@entry=0x0)
> at ../softmmu/memory.c:2174
> #9  0x0000555555b34587 in memory_global_dirty_log_sync () at
> ../softmmu/memory.c:2784
> #10 0x0000555555b4a16e in migration_bitmap_sync (rs=rs@entry=0x7ffea4001630)
> at ../migration/ram.c:1183
> #11 0x0000555555b4a94c in migration_bitmap_sync_precopy
> (rs=rs@entry=0x7ffea4001630) at ../migration/ram.c:1230
> #12 0x0000555555b4be62 in ram_init_bitmaps (rs=0x7ffea4001630) at
> ../migration/ram.c:3077
> #13 ram_init_all (rsp=<optimized out>) at ../migration/ram.c:3101
> #14 ram_save_setup (f=0x5555568fe1b0, opaque=<optimized out>) at
> ../migration/ram.c:3214

Hi Jason, thanks for the analysis and the patch. After applying this latter I do not hit the assert. However the migration does not seem to converge but this may link to another setup issue. Lei, please let us know if it removes the assert and if you are able to converge. Maybe I need to change the migration settings on my end ...

Yep, so the migration convergence issue was a problem in the destination script I think. Now I see the migration completing and no assertion. So it looks good from my side.

Hello Eric & Jason

After applied Jason provided patch, I can not reproduced this bug again. The follwoing is my test steps:

==Test Steps：
1. Compile upstream qemu
# git clone git://git.qemu.org/qemu.git
# mkdir build
# vim root/qemu/hw/virtio/vhost.c
# ../configure --target-list=x86_64-softmmu --enable-debug
# make

2. Boot src & dst guest
src:
/root/qemu/build/x86_64-softmmu/qemu-system-x86_64 \
-name 'avocado-vt-vm1'  \
-sandbox on  \
-machine q35,memory-backend=mem-machine_mem \
-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 '{"driver":"virtio-iommu","bus":"pcie.0","addr":"0x4"}' \
-device VGA,bus=pcie.0,addr=0x2 \
-m 1024 \
-object memory-backend-ram,size=1024M,id=mem-machine_mem  \
-smp 6,maxcpus=6,cores=3,threads=1,dies=1,sockets=2  \
-cpu 'Haswell-noTSX-IBRS',vme=on,ss=on,vmx=on,pdcm=on,f16c=on,rdrand=on,hypervisor=on,arat=on,tsc-adjust=on,umip=on,md-clear=on,stibp=on,arch-capabilities=on,ssbd=on,xsaveopt=on,pdpe1gb=on,abm=on,ibpb=on,ibrs=on,amd-stibp=on,amd-ssbd=on,skip-l1dfl-vmentry=on,pschange-mc-no=on,kvm_pv_unhalt=on \
-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/rhel910-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,iommu_platform=on,mac=9a:ac:5a:d7:18:8e,id=id0DVAMO,netdev=id4Im3rr,bus=pcie-root-port-3,addr=0x0  \
-netdev tap,id=id4Im3rr,vhost=on,script=/etc/qemu-ifup,downscript=/etc/qemu-ifdown \
-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:5555,server,nowait \

dst:
-qmp tcp:0:5556,server,nowait \
-incoming defer 

3.Create large file and check the md5 value
# dd if=/dev/zero of=/root/large_file count=8000 bs=1M
8000+0 records in
8000+0 records out
8388608000 bytes (8.4 GB, 7.8 GiB) copied, 18.2483 s, 460 MB/s
[root@dell-per730-29 ~]# md5sum large_file 
1760505701fd1bbcece9e4038f29fb0d  large_file

4.migration while doing an large file scp to the guest
host:
# scp large_file  root.210.221:/root
root.210.221's password: 
large_file                                                         100% 8000MB  41.0MB/s   03:15  
 
src:
$ telnet 10.73.210.48 5555
Trying 10.73.210.48...
Connected to 10.73.210.48.
Escape character is '^]'.
{"QMP": {"version": {"qemu": {"micro": 91, "minor": 1, "major": 7}, "package": "v7.2.0-rc1-7-ga082fab9d2-dirty"}, "capabilities": ["oob"]}}
{'execute': 'qmp_capabilities'}
{"return": {}}
{'execute': 'migrate', 'arguments': {'uri': 'tcp:localhost:5272', 'blk': false, 'inc': false}}
{"return": {}}
{"execute":"query-migrate"}
{"return": {"expected-downtime": 300, "status": "active", "setup-time": 3, "total-time": 1522, "ram": {"total": 1091379200, "postcopy-requests": 0, "dirty-sync-count": 1, "multifd-bytes": 0, "pages-per-second": 41930, "downtime-bytes": 0, "page-size": 4096, "remaining": 825643008, "postcopy-bytes": 0, "mbps": 1073.9448, "transferred": 214781202, "dirty-sync-missed-zero-copy": 0, "precopy-bytes": 214781202, "duplicate": 12570, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 214249472, "normal": 52307}}}
{"execute":"query-migrate"}
{"return": {"expected-downtime": 435, "status": "active", "setup-time": 3, "total-time": 6124, "ram": {"total": 1091379200, "postcopy-requests": 0, "dirty-sync-count": 3, "multifd-bytes": 0, "pages-per-second": 35420, "downtime-bytes": 0, "page-size": 4096, "remaining": 28213248, "postcopy-bytes": 0, "mbps": 1073.80368, "transferred": 832284109, "dirty-sync-missed-zero-copy": 0, "precopy-bytes": 832284109, "duplicate": 117240, "dirty-pages-rate": 8928, "skipped": 0, "normal-bytes": 829607936, "normal": 202541}}}
{"timestamp": {"seconds": 1669020533, "microseconds": 68338}, "event": "STOP"}
{"execute":"query-migrate"}
{"return": {"status": "completed", "setup-time": 3, "downtime": 60, "total-time": 6365, "ram": {"total": 1091379200, "postcopy-requests": 0, "dirty-sync-count": 6, "multifd-bytes": 0, "pages-per-second": 109590, "downtime-bytes": 18195138, "page-size": 4096, "remaining": 0, "postcopy-bytes": 0, "mbps": 1086.7500458975164, "transferred": 863903016, "dirty-sync-missed-zero-copy": 0, "precopy-bytes": 845707878, "duplicate": 126091, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 861085696, "normal": 210226}}}

dst:
$ telnet 10.73.210.48 5556
Trying 10.73.210.48...
Connected to 10.73.210.48.
Escape character is '^]'.
{"QMP": {"version": {"qemu": {"micro": 91, "minor": 1, "major": 7}, "package": "v7.2.0-rc1-7-ga082fab9d2-dirty"}, "capabilities": ["oob"]}}
{'execute': 'qmp_capabilities'}
{"return": {}}
{'execute': 'migrate-incoming', 'arguments': {'uri': 'tcp:[::]:5272'}}
{"timestamp": {"seconds": 1669020520, "microseconds": 631386}, "event": "MIGRATION", "data": {"status": "setup"}}
{"return": {}}
{"timestamp": {"seconds": 1669020533, "microseconds": 179083}, "event": "RESUME"}

5.After migration and scp completed, then chenck the file md5 value inside guest
# md5sum large_file 
1760505701fd1bbcece9e4038f29fb0d  large_file

Thanks
Lei

Hi Lei, Jason, 

Excellent. So I guess the next step is for Jason to send his PATCH upstream for qemu 8.0 (I don't think this is candidate for 7.2.0 rc unfortunately) and then to backport the patch...

Thanks

Eric

(In reply to Eric Auger from comment #32)
> Hi Lei, Jason, 
> 
> Excellent. So I guess the next step is for Jason to send his PATCH upstream
> for qemu 8.0 (I don't think this is candidate for 7.2.0 rc unfortunately)
> and then to backport the patch...
> 
> Thanks
> 
> Eric

Right, I've sent the patch. But I'm not sure if it can go for 7.2 or not. Let's see.

Thanks

Hi Lei:

Here's an updated version of this patch, it passes my migration smoking test. Please test to see if it works for you.

Thanks

(In reply to jason wang from comment #34)
> Hi Lei:
> 
> Here's an updated version of this patch, it passes my migration smoking
> test. Please test to see if it works for you.
> 
> Thanks

Hi Jason

QE applied this patch and do the same test as Comment 31.It also works well.

Best Regards
Lei

Jason sent "[PATCH for 7.2? V2] vhost: fix vq dirty bitmap syncing when vIOMMU is enabled" upstream

(In reply to Eric Auger from comment #37)
> Jason sent "[PATCH for 7.2? V2] vhost: fix vq dirty bitmap syncing when
> vIOMMU is enabled" upstream

V3: https://patchew.org/QEMU/20221216033552.77087-1-jasowang@redhat.com/

Patch is now merged upstream but not in 7.2:

https://git.qemu.org/?p=qemu.git;a=commit;h=345cc1cbcbce2bab00abc2b88338d7d89c702d6b

Based on Comment 42, move 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 (Moderate: qemu-kvm security, 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/RHSA-2023:2162