Bug 2160929

Summary: Cancel migration sometimes hang in cancelling status with multifd (or zerocopy) enabled and many multifd channels
Product: Red Hat Enterprise Linux 9 Reporter: Li Xiaohui <xiaohli>
Component: qemu-kvmAssignee: Juan Quintela <quintela>
qemu-kvm sub component: Live Migration QA Contact: Li Xiaohui <xiaohli>
Status: CLOSED MIGRATED Docs Contact:
Severity: medium    
Priority: medium CC: chayang, coli, jinzhao, juzhang, leobras, lijin, mdean, nilal, peterx, quintela, smitterl, virt-maint, yafu, yihyu, zhenyzha, zhguo
Version: 9.2Keywords: MigratedToJIRA, Triaged
Target Milestone: rcFlags: pm-rhel: mirror+
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-09-22 17:37:16 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 2167657    

Description Li Xiaohui 2023-01-14 13:40:27 UTC
Description of problem:
Do zerocopy and multifd migration, during migration is active, cancel migration, sometimes it fails to cancel migration, hang in cancelling status


Version-Release number of selected component (if applicable):
hosts info: kernel-5.14.0-226.el9.aarch64 && qemu-kvm-7.2.0-2.el9.aarch64
guest info: kernel-4.18.0-447.el8.aarch64


How reproducible:
1/50


Steps to Reproduce:
1.Boot a guest on the source host with qemu command lines [1]
2.Boot the guest on the destination host with same qemu cmd with [1] but append '-incoming defer'
3.Enable multifd on the src and dst host, enable zero copy on the src host, set multifd channel to 4 on the src and dst host
4.Set migration incoming on the dst host, start to migration from the src to dst host
5.During migration is active, cancel migration

The auto log as below, 10.19.241.172 is the src host, 10.19.241.174 is the dst host:
2023-01-13-06:00:23: Host(10.19.241.174) Sending qmp command   : {"execute": "migrate-incoming", "arguments": {"uri": "tcp:[::]:4000"}, "id": "qBJcl14d"}
2023-01-13-06:00:24: Host(10.19.241.174) Responding qmp command: {"return": {}, "id": "qBJcl14d"}
2023-01-13-06:00:24: Host(10.19.241.172) Sending qmp command   : {"execute": "migrate", "arguments": {"uri": "tcp:10.19.241.174:4000", "blk": false, "inc": false, "detach": true, "resume": false}, "id": "IQA7fhXl"}
2023-01-13-06:00:24: Host(10.19.241.172) Responding qmp command: {"return": {}, "id": "IQA7fhXl"}
2023-01-13-06:00:24: Host(10.19.241.172) Sending qmp command   : {"execute": "query-migrate", "id": "iVo7Bktc"}
2023-01-13-06:00:24: Host(10.19.241.172) Responding qmp command: {"return": {"status": "setup"}, "id": "iVo7Bktc"}
2023-01-13-06:00:29: Host(10.19.241.172) Sending qmp command   : {"execute": "query-migrate", "id": "NeeVUFkq"}
2023-01-13-06:00:29: Host(10.19.241.172) Responding qmp command: {"return": {"expected-downtime": 300, "status": "active", "setup-time": 4, "total-time": 5012, "ram": {"total": 4429328384, "postcopy-requests": 0, "dirty-sync-count": 1, "multifd-bytes": 571058432, "pages-per-second": 773219, "downtime-bytes": 0, "page-size": 4096, "remaining": 2806267904, "postcopy-bytes": 0, "mbps": 615.55226016260156, "transferred": 573374799, "dirty-sync-missed-zero-copy": 0, "precopy-bytes": 2316367, "duplicate": 257305, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 569139200, "normal": 138950}}, "id": "NeeVUFkq"}
2023-01-13-06:00:29: Host(10.19.241.174) Sending qmp command   : {"execute": "query-migrate", "id": "pZnBPkIF"}
2023-01-13-06:00:29: Host(10.19.241.174) Responding qmp command: {"return": {"status": "active", "socket-address": [{"port": "4000", "ipv6": true, "host": "::", "type": "inet"}]}, "id": "pZnBPkIF"}
2023-01-13-06:00:29: ======= Step 6. During migration, cancel it =======
2023-01-13-06:00:29: ----- 6.1 Cancel migration during it is active -----
2023-01-13-06:00:29: Host(10.19.241.172) Sending qmp command   : {"execute": "migrate_cancel", "id": "Lu4AfMCD"}
2023-01-13-06:00:35: Host(10.19.241.172) Responding qmp command: {"return": {}, "id": "Lu4AfMCD"}
2023-01-13-06:00:35: Host(10.19.241.172) Sending qmp command   : {"execute": "query-migrate", "id": "96lzw0jZ"}
2023-01-13-06:00:35: Host(10.19.241.172) Responding qmp command: {"return": {"expected-downtime": 300, "status": "cancelling", "setup-time": 4, "total-time": 11031, "ram": {"total": 4429328384, "postcopy-requests": 0, "dirty-sync-count": 1, "multifd-bytes": 571062464, "pages-per-second": 773219, "downtime-bytes": 0, "page-size": 4096, "remaining": 2806267904, "postcopy-bytes": 0, "mbps": 615.55226016260156, "transferred": 573378831, "dirty-sync-missed-zero-copy": 0, "precopy-bytes": 2316367, "duplicate": 257305, "dirty-pages-rate": 0, "skipped": 0, "normal-bytes": 569139200, "normal": 138950}}, "id": "96lzw0jZ"}


Actual results:
As the step 5 of Steps to Reproduce, cancel migration hang in cancelling status. Can't cancel migration now


Expected results:
Cancel migration successfully.


Additional info:
1. Tried 300 times for the plain migration without zerocopy and multifd enabled, cancel migration always successfully;
2. Tried 100 times with only multifd enabled and set multifd channel to 4, cancel migration also successfully

Comment 1 Li Xiaohui 2023-01-14 13:46:51 UTC
Will try on x86 to see if this bug is aarch64 only.

Comment 3 Li Xiaohui 2023-01-18 10:14:54 UTC
Didn't reproduce this bug on x86 with repeating 200 times:
1) tried 100 times on qemu-kvm-7.2.0-4.el9.x86_64
2) tried 100 times on qemu-kvm-7.2.0-2.el9.x86_64



Will provide the network info of aarch64 machines later.

Comment 4 Li Xiaohui 2023-01-19 03:23:51 UTC
Also hit this issue on s390x, the host system of s390x is a KVM guest.


You can reserve them from beaker.
src host name: s390x-kvm-042.lab.eng.rdu2.redhat.com
dst host name: s390x-kvm-055.lab.eng.rdu2.redhat.com



The network info is same on src and dst:
# ethtool -k enc1 | grep scatter-gather
scatter-gather: on
	tx-scatter-gather: on
	tx-scatter-gather-fraglist: off [fixed]
# lshw -c network -businfo
Bus info      Device     Class      Description
===============================================
virtio@1      enc1       network    Ethernet interface
ccw.0000             network    Virtual network device
ccw.0001             network    Virtual network device
[root@s390x-kvm-042 ~]# hostname
s390x-kvm-042.lab.eng.rdu2.redhat.com

Comment 5 Li Xiaohui 2023-01-31 06:42:41 UTC
The network info of aarch64 machine is (both src and dst machine are same):
# lshw -c network -businfo
Bus info          Device       Class      Description
=====================================================
pci@0000:01:00.0  enp1s0f0np0  network    MT27710 Family [ConnectX-4 Lx]
pci@0000:01:00.1  enp1s0f1np1  network    MT27710 Family [ConnectX-4 Lx]
pci@0002:01:00.0  enP2p1s0     network    I210 Gigabit Network Connection
# ethtool -k enP2p1s0 | grep scatter-gather
scatter-gather: on
	tx-scatter-gather: on
	tx-scatter-gather-fraglist: off [fixed]

Comment 7 Li Xiaohui 2023-02-06 04:33:49 UTC
Hi Yan, thanks for the update, I will try on x86 later.

Comment 8 Juan Quintela 2023-02-06 15:39:14 UTC
Hi yafu

This is a different bug.
When we are on migration, there are two stages:
- iterative stage
- final stage.

During final stage, migration_cancel don't work.  We don't have the infrastructure to get back to iterative stage.  So it is a different bug.  We can open a new bug to try to fix it, but we don't have (upstream) the infrastructure to fix it.
Notice that you don't have any of the multifd threads working at that time.

So I think we are back to only s390 and arm to reproduce it.

Comment 9 yafu 2023-02-07 09:42:28 UTC
(In reply to Juan Quintela from comment #8)
> Hi yafu
> 
> This is a different bug.
> When we are on migration, there are two stages:
> - iterative stage
> - final stage.
> 
> During final stage, migration_cancel don't work.  We don't have the
> infrastructure to get back to iterative stage.  So it is a different bug. 
> We can open a new bug to try to fix it, but we don't have (upstream) the
> infrastructure to fix it.
> Notice that you don't have any of the multifd threads working at that time.
> 
> So I think we are back to only s390 and arm to reproduce it.

Hi Juan,

Thanks for your clarification. File a bug to track this issue:
https://bugzilla.redhat.com/show_bug.cgi?id=2167670

Comment 10 Li Xiaohui 2023-02-23 07:25:20 UTC
I could also reproduce this bug on the latest rhel 9.2.0 with 1/100 rate. 

So update hardware from aarch64 to all.

Comment 13 Li Xiaohui 2023-04-10 09:10:34 UTC
Also reproduce migration cancel hang issue when migrating with multifd enabled and multifd thread 4, but zerocopy is disabled with 1/200 rate.
(adjust VIRT-296187 case to disable zerocopy and add a sleep of 6 sceonds before canceling migration)

Qemu and libvirt: qemu-kvm-7.2.0-14.el9_2.x86_64 && libvirt-client-9.0.0-9.el9_2.x86_64

Try to find the difference between this bug and bug 2167657 by testing via libvirt and qemu:
1. Only enable multifd:
(1) when set multifd threads to a big value, such as 100, 250, migration cancel issue can be easily reproduced through libvirt.
(2) but if threads are 4 or 10, reproduce with a very low rate like my above tests (1/200)

2. Enable  zerocopy and multifd:
when set multifd threads to 4, it's easier to reproduce than zerocopy disable, like this bug's Description, 1/50 rate. 



So in summary, seems this bug and bug 2167657 are the same, they test under different scenarios, and the reproduction rate is not same. 
Easier reproduce when set multifd threads to be a bug value, and enable zerocopy.

Comment 14 Li Xiaohui 2023-04-17 08:30:35 UTC
*** Bug 2167657 has been marked as a duplicate of this bug. ***

Comment 15 Juan Quintela 2023-05-08 15:03:09 UTC
Hi

This comment helps a lot to reproduce:
(1) when set multifd threads to a big value, such as 100, 250, migration cancel issue can be easily reproduced through libvirt.

I will try it and will told you if I can reproduce it easily that way (such a big number makes no sense at all), but if I helps debugging, that is very good.

Comment 16 Juan Quintela 2023-05-16 16:56:35 UTC
Hi
I have been able to reproduce this bug with multifd channels set to 250.
It looks like there are memory corruption.  Trying to follow what is going on here.


Thanks, Juan.

Comment 17 Li Xiaohui 2023-05-17 05:39:12 UTC
(In reply to Juan Quintela from comment #16)
> Hi
> I have been able to reproduce this bug with multifd channels set to 250.
> It looks like there are memory corruption.  Trying to follow what is going
> on here.
> 
> 
> Thanks, Juan.

Nice.


Update the summary of this bug as zerocopy is not a must, multifd and many channels also reproduce it.

Comment 18 RHEL Program Management 2023-09-22 17:32:08 UTC
Issue migration from Bugzilla to Jira is in process at this time. This will be the last message in Jira copied from the Bugzilla bug.

Comment 19 RHEL Program Management 2023-09-22 17:37:16 UTC
This BZ has been automatically migrated to the issues.redhat.com Red Hat Issue Tracker. All future work related to this report will be managed there.

Due to differences in account names between systems, some fields were not replicated.  Be sure to add yourself to Jira issue's "Watchers" field to continue receiving updates and add others to the "Need Info From" field to continue requesting information.

To find the migrated issue, look in the "Links" section for a direct link to the new issue location. The issue key will have an icon of 2 footprints next to it, and begin with "RHEL-" followed by an integer.  You can also find this issue by visiting https://issues.redhat.com/issues/?jql= and searching the "Bugzilla Bug" field for this BZ's number, e.g. a search like:

"Bugzilla Bug" = 1234567

In the event you have trouble locating or viewing this issue, you can file an issue by sending mail to rh-issues. You can also visit https://access.redhat.com/articles/7032570 for general account information.