[KVM] Reorder migration logs to prevent populating agent logs on migrations

[nvazquez]

Description

This PR improves the KVM migration logging, preventing to populate the agent logs on migrations after the improvements added on #12332

Types of changes

• Breaking change (fix or feature that would cause existing functionality to change)
• New feature (non-breaking change which adds functionality)
• Bug fix (non-breaking change which fixes an issue)
• Enhancement (improves an existing feature and functionality)
• Cleanup (Code refactoring and cleanup, that may add test cases)
• Build/CI
• Test (unit or integration test code)

Feature/Enhancement Scale or Bug Severity

Feature/Enhancement Scale

• Major
• Minor

Bug Severity

• BLOCKER
• Critical
• Major
• Minor
• Trivial

Screenshots (if appropriate):

How Has This Been Tested?

Before the fix:

2026-03-24 23:03:38,857 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:38,857 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:38,957 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) Waiting for migration of i-2-25-VM to complete, waited 23000ms
2026-03-24 23:03:38,957 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:38,957 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,057 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,057 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,157 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,157 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,257 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,258 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,358 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,358 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,458 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,458 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,558 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,558 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,658 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,658 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,758 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,758 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,858 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,858 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:39,959 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) Waiting for migration of i-2-25-VM to complete, waited 24000ms
2026-03-24 23:03:39,959 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:39,959 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,059 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,059 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,159 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,159 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,259 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,259 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,359 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,359 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,459 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,460 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,560 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,560 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,660 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,660 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,760 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,760 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,860 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,860 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:40,960 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) Waiting for migration of i-2-25-VM to complete, waited 25000ms
2026-03-24 23:03:40,960 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:40,960 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,061 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,061 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,161 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,161 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,261 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,261 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,361 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,361 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,461 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,461 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,561 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,561 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,661 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,662 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,762 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,762 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,862 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,862 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,963 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) Waiting for migration of i-2-25-VM to complete, waited 26000ms
2026-03-24 23:03:41,963 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:03:41,963 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:03:41,963 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-1:[]) (logid:21bbbf9b) Migration thread of VM [i-2-25-VM] finished.

After the fix:

2026-03-24 23:11:02,899 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) vm.migrate.wait value set to: 3600for VM: i-2-25-VM
2026-03-24 23:11:02,899 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) vm.migrate.pauseafter value set to: -1 for VM: i-2-25-VM
2026-03-24 23:11:02,899 DEBUG [kvm.resource.MigrateKVMAsync] (pool-3-thread-1:[]) (logid:) Setting VIR_MIGRATE_NON_SHARED_INC for linked clone migration.
2026-03-24 23:11:02,900 DEBUG [kvm.resource.MigrateKVMAsync] (pool-3-thread-1:[]) (logid:) Migrating [i-2-25-VM] with flags [2185], destination [10.1.35.71] and speed [1000]. The disks with the following labels will be migrated [[vda]].
2026-03-24 23:11:03,902 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Waiting for migration of i-2-25-VM to complete, waited 1000ms
2026-03-24 23:11:04,903 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Waiting for migration of i-2-25-VM to complete, waited 2000ms
2026-03-24 23:11:05,904 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Waiting for migration of i-2-25-VM to complete, waited 3000ms
2026-03-24 23:11:06,905 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Waiting for migration of i-2-25-VM to complete, waited 4000ms
2026-03-24 23:11:07,907 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Waiting for migration of i-2-25-VM to complete, waited 5000ms
2026-03-24 23:11:08,908 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Waiting for migration of i-2-25-VM to complete, waited 6000ms
2026-03-24 23:11:09,909 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Waiting for migration of i-2-25-VM to complete, waited 7000ms
2026-03-24 23:11:10,910 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Waiting for migration of i-2-25-VM to complete, waited 8000ms
2026-03-24 23:11:11,911 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Waiting for migration of i-2-25-VM to complete, waited 9000ms
2026-03-24 23:11:12,312 INFO [resource.wrapper.LibvirtMigrateCommandWrapper] (AgentRequest-Handler-5:[]) (logid:604bf08f) Migration thread of VM [i-2-25-VM] finished.

How did you try to break this feature and the system with this change?

[nvazquez]

@blueorangutan package

[blueorangutan]

@nvazquez a [SL] Jenkins job has been kicked to build packages. It will be bundled with KVM, XenServer and VMware SystemVM templates. I'll keep you posted as I make progress.

[codecov]

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 17.60%. Comparing base (7c3637a) to head (2ff03c9).
⚠️ Report is 115 commits behind head on 4.22.

Additional details and impacted files

@@ Coverage Diff @@## 4.22 #12883 +/- ##
============================================
+ Coverage 3.70% 17.60% +13.90% - Complexity 0 15676 +15676 
============================================
Files 448 5918 +5470 Lines 38041 531667 +493626 Branches 7038 65001 +57963 ============================================
+ Hits 1409 93616 +92207 - Misses 36445 427492 +391047 - Partials 187 10559 +10372 

Flag	Coverage Δ
uitests	3.70% <ø> (-0.01%)	⬇️
unittests	18.67% <100.00%> (?)

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
• 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

[blueorangutan]

Packaging result [SF]: ✔️ el8 ✔️ el9 ✔️ el10 ✔️ debian ✔️ suse15. SL-JID 17234

[nvazquez]

@blueorangutan test

[blueorangutan]

@nvazquez a [SL] Trillian-Jenkins test job (ol8 mgmt + kvm-ol8) has been kicked to run smoke tests

[blueorangutan]

[SF] Trillian test result (tid-15726)
Environment: kvm-ol8 (x2), zone: Advanced Networking with Mgmt server ol8
Total time taken: 49641 seconds
Marvin logs: https://github.com/blueorangutan/acs-prs/releases/download/trillian/pr12883-t15726-kvm-ol8.zip
Smoke tests completed. 149 look OK, 0 have errors, 0 did not run
Only failed and skipped tests results shown below:

Test	Result	Time (s)	Test File

[nvazquez]

@blueorangutan package

[blueorangutan]

@nvazquez a [SL] Jenkins job has been kicked to build packages. It will be bundled with KVM, XenServer and VMware SystemVM templates. I'll keep you posted as I make progress.

[blueorangutan]

Packaging result [SF]: ✔️ el8 ✔️ el9 ✔️ el10 ✔️ debian ✔️ suse15. SL-JID 17302

[sureshanaparti]

code lgtm

[DaanHoogland]

@sureshanaparti@rajujith do you feel this needs testing?

[nvazquez]

Merging based on approvals and test results (also tested and verified the log lines are reduced)