Occasional 5-10 minute hang of VM during live migrations

[NielsH]

Hello,

Unrelated to my other thread ( https://xcp-ng.org/forum/topic/7054/occasional-error-doing-live-migrations/1 ) there is another issue we sometimes see during live migrations.

This is an issue we mainly see on our larger VMs. That means starting at about 12 CPU cores / 48GB RAM, and usually these also have more local storage (500-800GB).

After the migration reaches 99-100% completion, the progress bar resets back to 0%. At this point, on our larger VMs, the VM will sometimes stop responding and sometimes fail the migration completely after 10-15 minutes of being unresponsive, or it will eventually come through after 5-10 minutes of being unresponsive.

In the logs, this is what we see:
Source hypervisor:

ar  7 16:55:26 ede-vmh001 xapi: [debug||58317 |Async.VM.migrate_send R:a55e0f0e16d0|storage_migrate] Local VDI 7e4883d8-a296-40a0-8087-6d4209ed47d5 == remote VDI f8ea0379-07f8-4472-a448-a5af100c80a2
Mar  7 16:55:27 ede-vmh001 xapi: [debug||58317 |Async.VM.migrate_send R:a55e0f0e16d0|storage_migrate] Local VDI 9d56b5b4-758d-4f41-be21-c47bbe3edf12 now mirrored to remote VDI: c972e8b8-0c05-4224-9aa5-2ff4fe54673d
Mar  7 16:55:27 ede-vmh001 xapi: [debug||58317 |Async.VM.migrate_send R:a55e0f0e16d0|storage_migrate] Destroying dummy VDI on remote
Mar  7 16:55:27 ede-vmh001 xapi: [debug||58317 |Async.VM.migrate_send R:a55e0f0e16d0|storage_migrate] Destroying snapshot on src
Mar  7 16:55:27 ede-vmh001 xapi: [ info||61579 HTTP 127.0.0.1->:::80|Querying services D:5d420abb79bd|storage_impl] VDI.destroy dbg:Async.VM.migrate_send R:a55e0f0e16d0 sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:7e4883d8-a296-40a0-8087-6d4209ed47d5
Mar  7 16:55:27 ede-vmh001 xapi: [debug||58317 |Async.VM.migrate_send R:a55e0f0e16d0|task_server] Task 48 completed; duration = 793
Mar  7 16:55:27 ede-vmh001 xapi: [debug||58317 |Async.VM.migrate_send R:a55e0f0e16d0|storage] TASK.signal 48 = ["Completed",{"result":["Mirror_id","5c93fb03-318e-93cb-c16d-b0f8deca16f9/9d56b5b4-758d-4f41-be21-c47bbe3edf12"],"duration":792.6625249385834}]
Mar  7 16:55:27 ede-vmh001 xapi: [ info||61634 HTTP 127.0.0.1->:::80|Querying services D:7c4a3f2d385d|storage_impl] DATA.MIRROR.stat dbg:Async.VM.migrate_send R:a55e0f0e16d0 id:5c93fb03-318e-93cb-c16d-b0f8deca16f9/9d56b5b4-758d-4f41-be21-c47bbe3edf12
Mar  7 16:55:29 ede-vmh001 xapi: [ info||61663 HTTP 127.0.0.1->:::80|Querying services D:a86dc3607764|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdc allow_leak:false
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61663 HTTP 127.0.0.1->:::80|Querying services D:a86dc3607764|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdc sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:506f2926-a956-4ee8-bafd-739a7b8405a4 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61663 HTTP 127.0.0.1->:::80|Querying services D:a86dc3607764|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdc sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:506f2926-a956-4ee8-bafd-739a7b8405a4 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [ info||61667 HTTP 127.0.0.1->:::80|Querying services D:b8c8ba50906e|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdb allow_leak:false
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61667 HTTP 127.0.0.1->:::80|Querying services D:b8c8ba50906e|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdb sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:42635a54-c435-46c1-8e2e-7f58b59b3c25 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61667 HTTP 127.0.0.1->:::80|Querying services D:b8c8ba50906e|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdb sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:42635a54-c435-46c1-8e2e-7f58b59b3c25 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [ info||61671 HTTP 127.0.0.1->:::80|Querying services D:14cbc8eaf49c|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvda allow_leak:false
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61671 HTTP 127.0.0.1->:::80|Querying services D:14cbc8eaf49c|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvda sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:58a45bf4-10bc-4dca-a72b-f5cf3110ef80 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61671 HTTP 127.0.0.1->:::80|Querying services D:14cbc8eaf49c|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvda sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:58a45bf4-10bc-4dca-a72b-f5cf3110ef80 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [ info||61675 HTTP 127.0.0.1->:::80|Querying services D:a4ca021b6388|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvde allow_leak:false
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61675 HTTP 127.0.0.1->:::80|Querying services D:a4ca021b6388|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvde sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:b2ae45fd-4164-4193-9707-35841ab405e6 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61675 HTTP 127.0.0.1->:::80|Querying services D:a4ca021b6388|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvde sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:b2ae45fd-4164-4193-9707-35841ab405e6 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [ info||61679 HTTP 127.0.0.1->:::80|Querying services D:f301e88246f2|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdi allow_leak:false
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61679 HTTP 127.0.0.1->:::80|Querying services D:f301e88246f2|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdi sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:962d0e61-0268-47b7-bd34-a01d220a2bd7 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61679 HTTP 127.0.0.1->:::80|Querying services D:f301e88246f2|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdi sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:962d0e61-0268-47b7-bd34-a01d220a2bd7 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [ info||61683 HTTP 127.0.0.1->:::80|Querying services D:32ac53c4a80c|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdf allow_leak:false
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61683 HTTP 127.0.0.1->:::80|Querying services D:32ac53c4a80c|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdf sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:b3aa5e45-f7d0-42a6-b82c-c10eb8fea20d superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61683 HTTP 127.0.0.1->:::80|Querying services D:32ac53c4a80c|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdf sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:b3aa5e45-f7d0-42a6-b82c-c10eb8fea20d superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [ info||61687 HTTP 127.0.0.1->:::80|Querying services D:93daaf27709b|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdg allow_leak:false
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61687 HTTP 127.0.0.1->:::80|Querying services D:93daaf27709b|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdg sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:d7a9fee9-c387-45c4-8970-bdb2e89d26f7 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61687 HTTP 127.0.0.1->:::80|Querying services D:93daaf27709b|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdg sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:d7a9fee9-c387-45c4-8970-bdb2e89d26f7 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [ info||61691 HTTP 127.0.0.1->:::80|Querying services D:e4285adb7033|storage_impl] DP.destroy dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdh allow_leak:false
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61691 HTTP 127.0.0.1->:::80|Querying services D:e4285adb7033|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdh sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:9d56b5b4-758d-4f41-be21-c47bbe3edf12 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xapi: [debug||61691 HTTP 127.0.0.1->:::80|Querying services D:e4285adb7033|storage_impl] dbg:Async.VM.migrate_send R:a55e0f0e16d0 dp:mirror_vbd/13/xvdh sr:5c93fb03-318e-93cb-c16d-b0f8deca16f9 vdi:9d56b5b4-758d-4f41-be21-c47bbe3edf12 superstate:activated RW
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] Task 826 reference Async.VM.migrate_send R:a55e0f0e16d0: ["VM_migrate",{"vmm_tmp_dest_id":"e8c6913e-6aae-e486-571f-000000000001","vmm_tmp_src_id":"e8c6913e-6aae-e486-571f-000000000000","vmm_url":"http://10.40.4.42/services/xenops?session_id=OpaqueRef:3e33ae54-0932-4607-a41b-e2c7fcde4fdc","vmm_vgpu_pci_map":{},"vmm_vif_map":{"0":["Local","xapi4"]},"vmm_vdi_map":{"5c93fb03-318e-93cb-c16d-b0f8deca16f9/506f2926-a956-4ee8-bafd-739a7b8405a4":"20df4650-1ccd-6b78-e41d-a2fabf17385b/c61074bc-c3f8-47b1-9e99-75344917c548","5c93fb03-318e-93cb-c16d-b0f8deca16f9/42635a54-c435-46c1-8e2e-7f58b59b3c25":"20df4650-1ccd-6b78-e41d-a2fabf17385b/8174850d-709b-460c-b1ae-46ae7c27bb65","5c93fb03-318e-93cb-c16d-b0f8deca16f9/58a45bf4-10bc-4dca-a72b-f5cf3110ef80":"20df4650-1ccd-6b78-e41d-a2fabf17385b/5416378a-8b6d-49d9-ac6a-3684bae66251","5c93fb03-318e-93cb-c16d-b0f8deca16f9/b2ae45fd-4164-4193-9707-35841ab405e6":"20df4650-1ccd-6b78-e41d-a2fabf17385b/b77f6550-3195-4180-9a28-e0720db8f50e","5c93fb03-318e-93cb-c16d-b0f8deca16f9/962d0e61-0268-47b7-bd34-a01d220a2bd7":"20df4650-1ccd-6b78-e41d-a2fabf17385b/00138f15-3354-4e04-a879-87c11fc93efc","5c93fb03-318e-93cb-c16d-b0f8deca16f9/b3aa5e45-f7d0-42a6-b82c-c10eb8fea20d":"20df4650-1ccd-6b78-e41d-a2fabf17385b/8d6e4142-731f-488b-9471-a815ffd52c86","5c93fb03-318e-93cb-c16d-b0f8deca16f9/d7a9fee9-c387-45c4-8970-bdb2e89d26f7":"20df4650-1ccd-6b78-e41d-a2fabf17385b/9f519d8f-76c6-46e1-afb3-f6c54e9882aa","5c93fb03-318e-93cb-c16d-b0f8deca16f9/9d56b5b4-758d-4f41-be21-c47bbe3edf12":"20df4650-1ccd-6b78-e41d-a2fabf17385b/c972e8b8-0c05-4224-9aa5-2ff4fe54673d"},"vmm_id":"e8c6913e-6aae-e486-571f-70d1791e4a97"}]
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] VM.migrate e8c6913e-6aae-e486-571f-70d1791e4a97 -> http://10.40.4.42/services/xenops?session_id=OpaqueRef:3e33ae54-0932-4607-a41b-e2c7fcde4fdc
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] QMP command for domid 13: {"execute":"query-migratable","id":"qmp-000067-13"}
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] received QMP response qmp-000067-13 (File "xc/device_common.ml", line 502, characters 49-56)
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] query-migratable precheck passed (domid=13)
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] xenstore-rm /local/domain/13/data/cant_suspend_reason
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] assert_can_suspend: OK (domid=13)
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] Destination domain will be built with uuid=e8c6913e-6aae-e486-571f-000000000001
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] Original domain will be moved to uuid=e8c6913e-6aae-e486-571f-000000000000
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] Queue: Aliasing existing tag 'e8c6913e-6aae-e486-571f-70d1791e4a97' to new tag 'e8c6913e-6aae-e486-571f-000000000000'
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] Remapping bootloader VDIs
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_utils] Remapping VIF: 0
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] Remapping normal VDIs
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_utils] Remapping VDI: 5c93fb03-318e-93cb-c16d-b0f8deca16f9/b3aa5e45-f7d0-42a6-b82c-c10eb8fea20d -> 20df4650-1ccd-6b78-e41d-a2fabf17385b/8d6e4142-731f-488b-9471-a815ffd52c86
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_utils] Remapping VDI: 5c93fb03-318e-93cb-c16d-b0f8deca16f9/b2ae45fd-4164-4193-9707-35841ab405e6 -> 20df4650-1ccd-6b78-e41d-a2fabf17385b/b77f6550-3195-4180-9a28-e0720db8f50e
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_utils] Remapping VDI: 5c93fb03-318e-93cb-c16d-b0f8deca16f9/9d56b5b4-758d-4f41-be21-c47bbe3edf12 -> 20df4650-1ccd-6b78-e41d-a2fabf17385b/c972e8b8-0c05-4224-9aa5-2ff4fe54673d
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_utils] Remapping VDI: 5c93fb03-318e-93cb-c16d-b0f8deca16f9/506f2926-a956-4ee8-bafd-739a7b8405a4 -> 20df4650-1ccd-6b78-e41d-a2fabf17385b/c61074bc-c3f8-47b1-9e99-75344917c548
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_utils] Remapping VDI: 5c93fb03-318e-93cb-c16d-b0f8deca16f9/58a45bf4-10bc-4dca-a72b-f5cf3110ef80 -> 20df4650-1ccd-6b78-e41d-a2fabf17385b/5416378a-8b6d-49d9-ac6a-3684bae66251
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_utils] Remapping VDI: 5c93fb03-318e-93cb-c16d-b0f8deca16f9/d7a9fee9-c387-45c4-8970-bdb2e89d26f7 -> 20df4650-1ccd-6b78-e41d-a2fabf17385b/9f519d8f-76c6-46e1-afb3-f6c54e9882aa
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_utils] Remapping VDI: 5c93fb03-318e-93cb-c16d-b0f8deca16f9/42635a54-c435-46c1-8e2e-7f58b59b3c25 -> 20df4650-1ccd-6b78-e41d-a2fabf17385b/8174850d-709b-460c-b1ae-46ae7c27bb65
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_utils] Remapping VDI: 5c93fb03-318e-93cb-c16d-b0f8deca16f9/962d0e61-0268-47b7-bd34-a01d220a2bd7 -> 20df4650-1ccd-6b78-e41d-a2fabf17385b/00138f15-3354-4e04-a879-87c11fc93efc
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] Received vm-id = e8c6913e-6aae-e486-571f-000000000001
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] VM.set_memory_dynamic_range (e8c6913e-6aae-e486-571f-70d1791e4a97, 103079215104, 103079215104)
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; set_memory_dynamic_range min = 100663296; max = 100663296
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] rebalance_memory
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] VM_DB.signal e8c6913e-6aae-e486-571f-70d1791e4a97
Mar  7 16:55:29 ede-vmh001 xenopsd-xc: [ info||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] VM e8c6913e-6aae-e486-571f-70d1791e4a97 has memory_limit = 103079211008
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] VM.migrate: Synchronisation point 1
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] Performing: ["VM_save",["e8c6913e-6aae-e486-571f-70d1791e4a97",["Live"],["FD",25],[]]]
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] VM.save e8c6913e-6aae-e486-571f-70d1791e4a97
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] looking for emu-manager in [ featureset : 178bfbff-f6d83203-2e500800-040001f7-0000000f-219c01a9-00400004-00000000-010cd005-00000000-00000000-00000000-00000000-00000000-00000000-00000000-00000000-00000000; timeoffset : 1; usb : true; usb_tablet : true; device-model : qemu-upstream-compat; viridian : false; hpet : true; pae : true; apic : true; acpi : 1; device_id : 0001; videoram : 8; vga : std; nx : true; cores-per-socket : 1 ]
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|mig64] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; suspend live = true
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|mig64] Writing save signature: XenSavedDomv2-\x0A
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|mig64] Writing Xenops header (length=1668)
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|mig64] Writing Xenops record contents
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|emu-manager] connect: args = [ -fd 9b940ee4-28dc-4ddc-83e7-627571199e1f -mode hvm_save -domid 13 -dm qemu -live true ]
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; waiting for emu-manager...
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; progress = 0 / 100
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] TASK.signal 826 = ["Pending",0.0]
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; message from emu-manager: prepare:xenguest
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] Writing Libxc header
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] Writing Libxc record
Mar  7 16:55:30 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; waiting for emu-manager...
Mar  7 17:01:28 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; progress = 1 / 100
Mar  7 17:01:28 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] TASK.signal 826 = ["Pending",0.00909090909090909]
Mar  7 17:02:22 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; progress = 2 / 100
Mar  7 17:02:22 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] TASK.signal 826 = ["Pending",0.01818181818181818]
Mar  7 17:02:25 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; progress = 3 / 100
Mar  7 17:02:25 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] TASK.signal 826 = ["Pending",0.02727272727272727]
Mar  7 17:02:28 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] VM = e8c6913e-6aae-e486-571f-70d1791e4a97; domid = 13; progress = 4 / 100
Mar  7 17:02:28 ede-vmh001 xenopsd-xc: [debug||17 |Async.VM.migrate_send R:a55e0f0e16d0|xenops_server] TASK.signal 826 = ["Pending",0.03636363636363636]

Destination:

Mar  7 16:47:06 ede-vmh023 xenopsd-xc: [error||42 |events|task_server] Task 1339 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:48:06 ede-vmh023 xenopsd-xc: [ info||32 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:48:06 ede-vmh023 xenopsd-xc: [error||32 |events|task_server] Task 1350 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:49:06 ede-vmh023 xenopsd-xc: [ info||26 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:49:06 ede-vmh023 xenopsd-xc: [error||26 |events|task_server] Task 1361 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:50:06 ede-vmh023 xenopsd-xc: [ info||17 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:50:06 ede-vmh023 xenopsd-xc: [error||17 |events|task_server] Task 1372 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:51:07 ede-vmh023 xenopsd-xc: [ info||40 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:51:07 ede-vmh023 xenopsd-xc: [error||40 |events|task_server] Task 1383 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:52:07 ede-vmh023 xenopsd-xc: [ info||36 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:52:07 ede-vmh023 xenopsd-xc: [error||36 |events|task_server] Task 1394 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:53:07 ede-vmh023 xenopsd-xc: [ info||38 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:53:07 ede-vmh023 xenopsd-xc: [error||38 |events|task_server] Task 1405 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:54:07 ede-vmh023 xenopsd-xc: [ info||30 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:54:07 ede-vmh023 xenopsd-xc: [error||30 |events|task_server] Task 1416 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:55:08 ede-vmh023 xenopsd-xc: [ info||11 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:55:08 ede-vmh023 xenopsd-xc: [error||11 |events|task_server] Task 1427 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:55:29 ede-vmh023 xenopsd-xc: [debug||28 |Async.VM.migrate_send R:a55e0f0e16d0|xenops] Device.Vif.add domid=12 devid=0 mac=3e:1a:63:bd:7b:6d carrier=true rate=none other_config=[] extra_private_keys=[vif-id=0; vif-uuid=90338c8e-ff8a-1185-ad87-96bcdb31b002; network-uuid=dab4a716-c66b-8adc-370d-bc5b870eb2ed; locking-mode=unlocked; setup-vif-rules=/usr/libexec/xenopsd/setup-vif-rules; setup-pvs-proxy-rules=/usr/libexec/xenopsd/setup-pvs-proxy-rules; xenopsd-backend=classic] extra_xenserver_keys=[static-ip-setting/mac=3e:1a:63:bd:7b:6d; static-ip-setting/error-code=0; static-ip-setting/error-msg=; static-ip-setting/enabled=0; static-ip-setting/enabled6=0]
Mar  7 16:55:29 ede-vmh023 xapi: [error||72 |org.xen.xapi.xenops.classic events D:eecca4959efc|xenops] xenopsd event: Caught Db_exn.Read_missing_uuid("VM", "", "e8c6913e-6aae-e486-571f-000000000001") while updating VIF
Mar  7 16:55:30 ede-vmh023 xapi: [error||72 |org.xen.xapi.xenops.classic events D:eecca4959efc|xenops] xenopsd event: Caught Db_exn.Read_missing_uuid("VM", "", "e8c6913e-6aae-e486-571f-000000000001") while updating VIF
Mar  7 16:56:08 ede-vmh023 xenopsd-xc: [ info||19 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:56:08 ede-vmh023 xenopsd-xc: [error||19 |events|task_server] Task 1439 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:57:08 ede-vmh023 xenopsd-xc: [ info||42 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:57:08 ede-vmh023 xenopsd-xc: [error||42 |events|task_server] Task 1450 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:58:08 ede-vmh023 xenopsd-xc: [ info||32 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:58:08 ede-vmh023 xenopsd-xc: [error||32 |events|task_server] Task 1461 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 16:59:08 ede-vmh023 xenopsd-xc: [ info||36 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 16:59:08 ede-vmh023 xenopsd-xc: [error||36 |events|task_server] Task 1472 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 17:00:09 ede-vmh023 xenopsd-xc: [ info||24 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 17:00:09 ede-vmh023 xenopsd-xc: [error||24 |events|task_server] Task 1483 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 17:01:09 ede-vmh023 xenopsd-xc: [ info||13 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 17:01:09 ede-vmh023 xenopsd-xc: [error||13 |events|task_server] Task 1494 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 17:02:09 ede-vmh023 xenopsd-xc: [ info||21 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 17:02:09 ede-vmh023 xenopsd-xc: [error||21 |events|task_server] Task 1505 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 17:03:09 ede-vmh023 xenopsd-xc: [ info||26 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 17:03:09 ede-vmh023 xenopsd-xc: [error||26 |events|task_server] Task 1516 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 17:04:10 ede-vmh023 xenopsd-xc: [ info||38 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 17:04:10 ede-vmh023 xenopsd-xc: [error||38 |events|task_server] Task 1527 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])
Mar  7 17:05:10 ede-vmh023 xenopsd-xc: [ info||30 |events|xenops_server] Caught Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]]) executing ["VM_check_state","cc1ec41b-58e2-d4db-5af6-000000000001"]: triggering cleanup actions
Mar  7 17:05:10 ede-vmh023 xenopsd-xc: [error||30 |events|task_server] Task 1538 failed; Xenops_interface.Xenopsd_error([S(Does_not_exist);[S(VM);S(cc1ec41b-58e2-d4db-5af6-000000000001/config)]])

Now I'm thinking the Xenops_interface.Xenopsd_error message might be a red herring since it occurs during the entire migration, and also continues after the VM has already started being responsive again

Here, the VM was unreachable from 16:55:30 until 17:00:28.
On our smallers VMs we don't really see the behaviour, but our larger VMs do have it quite often. This means we are always quite anxious to live migrate larger VMs since there's often a few minutes impact.

Is there anything we can do to debug this?

[NielsH]

@NielsH said in Occasional 5-10 minute hang of VM during live migrations:

message from emu-manager: prepare:xenguest

I found some more information regarding the xenguest-output in the daemon.log, it appears to give some more details in what is happening between 16:55 and 17:01:

I'm hitting the post limit so will put into 3 posts
Part 1:

Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: received 'close' message (uuid = 0)
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: nbd: NBD server pause(0x2564610)
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: nbd: NBD server free(0x2564610)
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: gaps written/skipped: 0/0
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: /var/run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/7e4883d8-a296-40a0-8087-6d4209ed47d5.vhd: b: 102400, a: 0, f: 0, n: 0
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: closed image /var/run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/7e4883d8-a296-40a0-8087-6d4209ed47d5.vhd (0 users, state: 0x00000002, type: 4)
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: gaps written/skipped: 0/0
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: /run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/4b8c58fc-70eb-426e-ab86-cf1ac3adf3bb.vhd: b: 102400, a: 102399, f: 102390, n: 0
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: closed image /run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/4b8c58fc-70eb-426e-ab86-cf1ac3adf3bb.vhd (0 users, state: 0x00000002, type: 4)
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: sending 'close response' message (uuid = 0)
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: received 'detach' message (uuid = 0)
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: sending 'detach response' message (uuid = 0)
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: tapdisk-log: closing after 0 errors
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: tapdisk-syslog: 18 messages, 1606 bytes, xmits: 19, failed: 0, dropped: 0
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: tapdisk-control: draining 1 connections
Mar  7 16:55:25 ede-vmh001 tapdisk[5882]: tapdisk-control: done
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] watch /memory/dynamic-min <- 100663296
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||4 ||xenops] watch /memory/dynamic-min <- 100663296
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] watch /memory/dynamic-max <- 100663296
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||4 ||xenops] watch /memory/dynamic-max <- 100663296
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] change_host_free_memory required_mem = 9216 KiB target_mem = 9216 KiB free_mem = 394576612 KiB
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||22 ||xenops] change_host_free_memory required_mem = 9216 KiB target_mem = 9216 KiB free_mem = 394576612 KiB
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] change_host_free_memory all VM target meet true
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||22 ||xenops] change_host_free_memory all VM target meet true
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] total_range = 0 gamma = 1.000000 gamma' = inf
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||22 ||xenops] total_range = 0 gamma = 1.000000 gamma' = inf
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] Total additional memory over dynamic_min = 394567396 KiB; will set gamma = 1.00 (leaving unallocated 0 KiB)
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||22 ||xenops] Total additional memory over dynamic_min = 394567396 KiB; will set gamma = 1.00 (leaving unallocated 0 KiB)
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] Maximum possible free memory if all active domains balloon down to dynamic_min = 394576612
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||22 ||xenops] Maximum possible free memory if all active domains balloon down to dynamic_min = 394576612
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] current host free mem = 394576612 KiB (aiming for 9216 KiB); cannot allocate enough; all domain targets reached; allocation phase
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||22 ||xenops] current host free mem = 394576612 KiB (aiming for 9216 KiB); cannot allocate enough; all domain targets reached; allocation phase
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] F394576612 S0 R0 T536721328; 13 T100663296 A100663296 M100663292 Bxx
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||22 ||xenops] F394576612 S0 R0 T536721328; 13 T100663296 A100663296 M100663292 Bxx
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] Failed to free 9216 KiB of memory: operation impossible within current dynamic_min limits of balloonable domains
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||22 ||xenops] Failed to free 9216 KiB of memory: operation impossible within current dynamic_min limits of balloonable domains
Mar  7 16:55:29 ede-vmh001 squeezed[28579]: [6376.76] balance memory caught: Squeeze.Cannot_free_this_much_memory(_, _)
Mar  7 16:55:29 ede-vmh001 squeezed: [debug||22 ||xenops] balance memory caught: Squeeze.Cannot_free_this_much_memory(_, _)
Mar  7 16:55:30 ede-vmh001 systemd[1]: Started Session c89800 of user root.
Mar  7 16:55:30 ede-vmh001 systemd[1]: Starting Session c89800 of user root.
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Startup: xenopsd control fds (8, 7).
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Startup: domid 13.
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Startup: operation mode (hvm_save, live).
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Emu `xenguest` is enabled.
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Emu `qemu` is enabled.
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Starting `/usr/libexec/xen/bin/xenguest`...
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: Command line: -debug -domid 13 -controloutfd 2 -controlinfd 0 -mode listen
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Connecting to `xenguest` (/run/xen/xenguest-control-13)...
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Connecting to `qemu` (/var/run/xen/qmp-libxl-13)...
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver: Adding client on fd 12 as (0)
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver: On (0) got message '{ "execute" : "migrate_init" }'
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "return" : {} }
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Got QMP version negotiation.
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver: On (0) got message '{ "execute" : "track_dirty" }'
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "return" : {} }
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver: On (0) got message '{ "execute" : "migrate_progress" }'
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: setting progress_cli to 0
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "return" : {} }
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver: On (0) got message '{ "execute" : "migrate_live" }'
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "return" : {} }
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: xc: detail: fd 13, dom 13, flags 1, hvm 1
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: xc: info: Saving domain 13, type x86 HVM
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: progress: Start of stream
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: Checking live policy.  25229312 / 0 for 0
Mar  7 16:55:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 0,"remaining": 25229312,"iteration": 0}}
Mar  7 16:55:30 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem 25229312, sent 0, iter 0, not waiting. Progress = 0
Mar  7 16:55:38 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 1024,"remaining": -1,"iteration": 0}}
Mar  7 16:55:38 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 1024 of 25229312 (0%)
Mar  7 16:55:38 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 1024, iter 0, not waiting. Progress = 0
Mar  7 16:55:42 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 2048,"remaining": -1,"iteration": 0}}
Mar  7 16:55:42 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 2048, iter 0, not waiting. Progress = 0
Mar  7 16:55:46 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 3072,"remaining": -1,"iteration": 0}}
Mar  7 16:55:46 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 3072 of 25229312 (0%)
Mar  7 16:55:46 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 3072, iter 0, not waiting. Progress = 0
Mar  7 16:55:51 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 4096,"remaining": -1,"iteration": 0}}
Mar  7 16:55:51 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 4096, iter 0, not waiting. Progress = 0
Mar  7 16:55:55 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 5120,"remaining": -1,"iteration": 0}}
Mar  7 16:55:55 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 5120 of 25229312 (0%)
Mar  7 16:55:55 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 5120, iter 0, not waiting. Progress = 0
Mar  7 16:55:59 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 6144,"remaining": -1,"iteration": 0}}
Mar  7 16:55:59 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 6144, iter 0, not waiting. Progress = 0
Mar  7 16:56:00 ede-vmh001 systemd[1]: Started Session c89801 of user root.
Mar  7 16:56:00 ede-vmh001 systemd[1]: Starting Session c89801 of user root.
Mar  7 16:56:03 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 7168,"remaining": -1,"iteration": 0}}
Mar  7 16:56:03 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 7168 of 25229312 (0%)
Mar  7 16:56:03 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 7168, iter 0, not waiting. Progress = 0
Mar  7 16:56:07 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 8192,"remaining": -1,"iteration": 0}}
Mar  7 16:56:07 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 8192, iter 0, not waiting. Progress = 0
Mar  7 16:56:10 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 9216,"remaining": -1,"iteration": 0}}
Mar  7 16:56:10 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 9216 of 25229312 (0%)
Mar  7 16:56:10 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 9216, iter 0, not waiting. Progress = 0
Mar  7 16:56:14 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 10240,"remaining": -1,"iteration": 0}}
Mar  7 16:56:14 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 10240, iter 0, not waiting. Progress = 0
Mar  7 16:56:19 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 11264,"remaining": -1,"iteration": 0}}
Mar  7 16:56:19 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 11264 of 25229312 (0%)
Mar  7 16:56:19 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 11264, iter 0, not waiting. Progress = 0
Mar  7 16:56:22 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 12288,"remaining": -1,"iteration": 0}}
Mar  7 16:56:22 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 12288, iter 0, not waiting. Progress = 0
Mar  7 16:56:26 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 13312,"remaining": -1,"iteration": 0}}
Mar  7 16:56:26 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 13312 of 25229312 (0%)
Mar  7 16:56:26 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 13312, iter 0, not waiting. Progress = 0
Mar  7 16:56:29 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 14336,"remaining": -1,"iteration": 0}}
Mar  7 16:56:29 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 14336, iter 0, not waiting. Progress = 0
Mar  7 16:56:30 ede-vmh001 systemd[1]: Started Session c89802 of user root.
Mar  7 16:56:30 ede-vmh001 systemd[1]: Starting Session c89802 of user root.
Mar  7 16:56:33 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 15360,"remaining": -1,"iteration": 0}}
Mar  7 16:56:33 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 15360 of 25229312 (0%)
Mar  7 16:56:33 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 15360, iter 0, not waiting. Progress = 0
Mar  7 16:56:36 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 16384,"remaining": -1,"iteration": 0}}
Mar  7 16:56:36 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 16384, iter 0, not waiting. Progress = 0
Mar  7 16:56:40 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 17408,"remaining": -1,"iteration": 0}}
Mar  7 16:56:40 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 17408 of 25229312 (0%)
Mar  7 16:56:40 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 17408, iter 0, not waiting. Progress = 0
Mar  7 16:56:43 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 18432,"remaining": -1,"iteration": 0}}
Mar  7 16:56:43 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 18432, iter 0, not waiting. Progress = 0
Mar  7 16:56:48 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 19456,"remaining": -1,"iteration": 0}}
Mar  7 16:56:48 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 19456 of 25229312 (0%)
Mar  7 16:56:48 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 19456, iter 0, not waiting. Progress = 0
Mar  7 16:56:52 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 20480,"remaining": -1,"iteration": 0}}
Mar  7 16:56:52 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 20480, iter 0, not waiting. Progress = 0
Mar  7 16:56:55 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 21504,"remaining": -1,"iteration": 0}}
Mar  7 16:56:55 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 21504 of 25229312 (0%)
Mar  7 16:56:55 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 21504, iter 0, not waiting. Progress = 0
Mar  7 16:56:58 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 22528,"remaining": -1,"iteration": 0}}
Mar  7 16:56:58 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 22528, iter 0, not waiting. Progress = 0
Mar  7 16:57:00 ede-vmh001 systemd[1]: Started Session c89803 of user root.
Mar  7 16:57:00 ede-vmh001 systemd[1]: Starting Session c89803 of user root.
Mar  7 16:57:00 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 23552,"remaining": -1,"iteration": 0}}
Mar  7 16:57:00 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 23552 of 25229312 (0%)
Mar  7 16:57:00 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 23552, iter 0, not waiting. Progress = 0
Mar  7 16:57:04 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 24576,"remaining": -1,"iteration": 0}}
Mar  7 16:57:04 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 24576, iter 0, not waiting. Progress = 0
Mar  7 16:57:07 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 25600,"remaining": -1,"iteration": 0}}
Mar  7 16:57:07 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 25600 of 25229312 (0%)
Mar  7 16:57:07 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 25600, iter 0, not waiting. Progress = 0
Mar  7 16:57:11 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 26624,"remaining": -1,"iteration": 0}}
Mar  7 16:57:11 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 26624, iter 0, not waiting. Progress = 0
Mar  7 16:57:15 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 27648,"remaining": -1,"iteration": 0}}
Mar  7 16:57:15 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 27648 of 25229312 (0%)
Mar  7 16:57:15 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 27648, iter 0, not waiting. Progress = 0
Mar  7 16:57:19 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 28672,"remaining": -1,"iteration": 0}}
Mar  7 16:57:19 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 28672, iter 0, not waiting. Progress = 0
Mar  7 16:57:23 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 29696,"remaining": -1,"iteration": 0}}
Mar  7 16:57:23 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 29696 of 25229312 (0%)
Mar  7 16:57:23 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 29696, iter 0, not waiting. Progress = 0
Mar  7 16:57:26 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 30720,"remaining": -1,"iteration": 0}}
Mar  7 16:57:26 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 30720, iter 0, not waiting. Progress = 0
Mar  7 16:57:30 ede-vmh001 systemd[1]: Started Session c89804 of user root.
Mar  7 16:57:30 ede-vmh001 systemd[1]: Starting Session c89804 of user root.
Mar  7 16:57:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 31744,"remaining": -1,"iteration": 0}}
Mar  7 16:57:30 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 31744 of 25229312 (0%)
Mar  7 16:57:30 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 31744, iter 0, not waiting. Progress = 0
Mar  7 16:57:32 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 32768,"remaining": -1,"iteration": 0}}
Mar  7 16:57:32 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 32768, iter 0, not waiting. Progress = 0
Mar  7 16:57:36 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 33792,"remaining": -1,"iteration": 0}}
Mar  7 16:57:36 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 33792 of 25229312 (0%)
Mar  7 16:57:36 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 33792, iter 0, not waiting. Progress = 0
Mar  7 16:57:41 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 34816,"remaining": -1,"iteration": 0}}
Mar  7 16:57:41 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 34816, iter 0, not waiting. Progress = 0
Mar  7 16:57:44 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 35840,"remaining": -1,"iteration": 0}}
Mar  7 16:57:44 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 35840 of 25229312 (0%)
Mar  7 16:57:44 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 35840, iter 0, not waiting. Progress = 0
Mar  7 16:57:48 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 36864,"remaining": -1,"iteration": 0}}
Mar  7 16:57:48 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 36864, iter 0, not waiting. Progress = 0
Mar  7 16:57:51 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 37888,"remaining": -1,"iteration": 0}}
Mar  7 16:57:51 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 37888 of 25229312 (0%)
Mar  7 16:57:51 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 37888, iter 0, not waiting. Progress = 0
Mar  7 16:57:55 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 38912,"remaining": -1,"iteration": 0}}
Mar  7 16:57:55 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 38912, iter 0, not waiting. Progress = 0
Mar  7 16:57:58 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 39936,"remaining": -1,"iteration": 0}}
Mar  7 16:57:58 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 39936 of 25229312 (0%)
Mar  7 16:57:58 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 39936, iter 0, not waiting. Progress = 0
Mar  7 16:58:00 ede-vmh001 systemd[1]: Started Session c89805 of user root.
Mar  7 16:58:00 ede-vmh001 systemd[1]: Starting Session c89805 of user root.
Mar  7 16:58:02 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 40960,"remaining": -1,"iteration": 0}}
Mar  7 16:58:02 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 40960, iter 0, not waiting. Progress = 0
Mar  7 16:58:05 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 41984,"remaining": -1,"iteration": 0}}
Mar  7 16:58:05 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 41984 of 25229312 (0%)
Mar  7 16:58:05 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 41984, iter 0, not waiting. Progress = 0
Mar  7 16:58:09 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 43008,"remaining": -1,"iteration": 0}}
Mar  7 16:58:09 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 43008, iter 0, not waiting. Progress = 0
Mar  7 16:58:13 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 44032,"remaining": -1,"iteration": 0}}
Mar  7 16:58:13 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 44032 of 25229312 (0%)
Mar  7 16:58:13 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 44032, iter 0, not waiting. Progress = 0
Mar  7 16:58:16 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 45056,"remaining": -1,"iteration": 0}}
Mar  7 16:58:16 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 45056, iter 0, not waiting. Progress = 0
Mar  7 16:58:19 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 46080,"remaining": -1,"iteration": 0}}
Mar  7 16:58:19 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 46080 of 25229312 (0%)
Mar  7 16:58:19 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 46080, iter 0, not waiting. Progress = 0
Mar  7 16:58:22 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 47104,"remaining": -1,"iteration": 0}}
Mar  7 16:58:22 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 47104, iter 0, not waiting. Progress = 0
Mar  7 16:58:27 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 48128,"remaining": -1,"iteration": 0}}
Mar  7 16:58:27 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 48128 of 25229312 (0%)
Mar  7 16:58:27 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 48128, iter 0, not waiting. Progress = 0
Mar  7 16:58:30 ede-vmh001 systemd[1]: Started Session c89806 of user root.
Mar  7 16:58:30 ede-vmh001 systemd[1]: Starting Session c89806 of user root.
Mar  7 16:58:31 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 49152,"remaining": -1,"iteration": 0}}
Mar  7 16:58:31 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 49152, iter 0, not waiting. Progress = 0
Mar  7 16:58:34 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 50176,"remaining": -1,"iteration": 0}}
Mar  7 16:58:34 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 50176 of 25229312 (0%)
Mar  7 16:58:34 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 50176, iter 0, not waiting. Progress = 0
Mar  7 16:58:38 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 51200,"remaining": -1,"iteration": 0}}
Mar  7 16:58:38 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 51200, iter 0, not waiting. Progress = 0
Mar  7 16:58:40 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 52224,"remaining": -1,"iteration": 0}}
Mar  7 16:58:40 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 52224 of 25229312 (0%)
Mar  7 16:58:40 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 52224, iter 0, not waiting. Progress = 0
Mar  7 16:58:43 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 53248,"remaining": -1,"iteration": 0}}
Mar  7 16:58:43 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 53248, iter 0, not waiting. Progress = 0
Mar  7 16:58:45 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 54272,"remaining": -1,"iteration": 0}}
Mar  7 16:58:45 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 54272 of 25229312 (0%)
Mar  7 16:58:45 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 54272, iter 0, not waiting. Progress = 0
Mar  7 16:58:48 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 55296,"remaining": -1,"iteration": 0}}
Mar  7 16:58:48 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 55296, iter 0, not waiting. Progress = 0
Mar  7 16:58:51 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 56320,"remaining": -1,"iteration": 0}}
Mar  7 16:58:51 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 56320 of 25229312 (0%)
Mar  7 16:58:51 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 56320, iter 0, not waiting. Progress = 0
Mar  7 16:58:53 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 57344,"remaining": -1,"iteration": 0}}
Mar  7 16:58:53 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 57344, iter 0, not waiting. Progress = 0
Mar  7 16:58:56 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 58368,"remaining": -1,"iteration": 0}}
Mar  7 16:58:56 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 58368, iter 0, not waiting. Progress = 0
Mar  7 16:58:58 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 59392,"remaining": -1,"iteration": 0}}
Mar  7 16:58:58 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 59392 of 25229312 (0%)
Mar  7 16:58:58 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 59392, iter 0, not waiting. Progress = 0
Mar  7 16:59:00 ede-vmh001 systemd[1]: Started Session c89807 of user root.
Mar  7 16:59:00 ede-vmh001 systemd[1]: Starting Session c89807 of user root.
Mar  7 16:59:01 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 60416,"remaining": -1,"iteration": 0}}
Mar  7 16:59:01 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 60416, iter 0, not waiting. Progress = 0
Mar  7 16:59:02 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 61440,"remaining": -1,"iteration": 0}}
Mar  7 16:59:02 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 61440, iter 0, not waiting. Progress = 0
Mar  7 16:59:05 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 62464,"remaining": -1,"iteration": 0}}
Mar  7 16:59:05 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 62464 of 25229312 (0%)
Mar  7 16:59:05 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 62464, iter 0, not waiting. Progress = 0
Mar  7 16:59:07 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 63488,"remaining": -1,"iteration": 0}}
Mar  7 16:59:07 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 63488, iter 0, not waiting. Progress = 0
Mar  7 16:59:09 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 64512,"remaining": -1,"iteration": 0}}
Mar  7 16:59:09 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 64512, iter 0, not waiting. Progress = 0
Mar  7 16:59:11 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 65536,"remaining": -1,"iteration": 0}}
Mar  7 16:59:11 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 65536 of 25229312 (0%)
Mar  7 16:59:11 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 65536, iter 0, not waiting. Progress = 0
Mar  7 16:59:13 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 66560,"remaining": -1,"iteration": 0}}
Mar  7 16:59:13 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 66560, iter 0, not waiting. Progress = 0
Mar  7 16:59:15 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 67584,"remaining": -1,"iteration": 0}}
Mar  7 16:59:15 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 67584, iter 0, not waiting. Progress = 0
Mar  7 16:59:17 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 68608,"remaining": -1,"iteration": 0}}
Mar  7 16:59:17 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 68608 of 25229312 (0%)

[NielsH]

Part 2:

Mar  7 16:59:17 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 68608, iter 0, not waiting. Progress = 0
Mar  7 16:59:19 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 69632,"remaining": -1,"iteration": 0}}
Mar  7 16:59:19 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 69632, iter 0, not waiting. Progress = 0
Mar  7 16:59:20 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 70656,"remaining": -1,"iteration": 0}}
Mar  7 16:59:20 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 70656, iter 0, not waiting. Progress = 0
Mar  7 16:59:23 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 71680,"remaining": -1,"iteration": 0}}
Mar  7 16:59:23 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 71680 of 25229312 (0%)
Mar  7 16:59:23 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 71680, iter 0, not waiting. Progress = 0
Mar  7 16:59:24 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 72704,"remaining": -1,"iteration": 0}}
Mar  7 16:59:24 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 72704, iter 0, not waiting. Progress = 0
Mar  7 16:59:26 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 73728,"remaining": -1,"iteration": 0}}
Mar  7 16:59:26 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 73728, iter 0, not waiting. Progress = 0
Mar  7 16:59:28 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 74752,"remaining": -1,"iteration": 0}}
Mar  7 16:59:28 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 74752 of 25229312 (0%)
Mar  7 16:59:28 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 74752, iter 0, not waiting. Progress = 0
Mar  7 16:59:30 ede-vmh001 systemd[1]: Started Session c89808 of user root.
Mar  7 16:59:30 ede-vmh001 systemd[1]: Starting Session c89808 of user root.
Mar  7 16:59:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 75776,"remaining": -1,"iteration": 0}}
Mar  7 16:59:30 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 75776, iter 0, not waiting. Progress = 0
Mar  7 16:59:32 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 76800,"remaining": -1,"iteration": 0}}
Mar  7 16:59:32 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 76800, iter 0, not waiting. Progress = 0
Mar  7 16:59:33 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 77824,"remaining": -1,"iteration": 0}}
Mar  7 16:59:33 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 77824 of 25229312 (0%)
Mar  7 16:59:33 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 77824, iter 0, not waiting. Progress = 0
Mar  7 16:59:35 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 78848,"remaining": -1,"iteration": 0}}
Mar  7 16:59:35 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 78848, iter 0, not waiting. Progress = 0
Mar  7 16:59:36 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 79872,"remaining": -1,"iteration": 0}}
Mar  7 16:59:36 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 79872, iter 0, not waiting. Progress = 0
Mar  7 16:59:38 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 80896,"remaining": -1,"iteration": 0}}
Mar  7 16:59:38 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 80896, iter 0, not waiting. Progress = 0
Mar  7 16:59:40 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 81920,"remaining": -1,"iteration": 0}}
Mar  7 16:59:40 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 81920 of 25229312 (0%)
Mar  7 16:59:40 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 81920, iter 0, not waiting. Progress = 0
Mar  7 16:59:42 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 82944,"remaining": -1,"iteration": 0}}
Mar  7 16:59:42 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 82944, iter 0, not waiting. Progress = 0
Mar  7 16:59:43 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 83968,"remaining": -1,"iteration": 0}}
Mar  7 16:59:43 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 83968, iter 0, not waiting. Progress = 0
Mar  7 16:59:45 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 84992,"remaining": -1,"iteration": 0}}
Mar  7 16:59:45 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 84992, iter 0, not waiting. Progress = 0
Mar  7 16:59:46 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 86016,"remaining": -1,"iteration": 0}}
Mar  7 16:59:46 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 86016 of 25229312 (0%)
Mar  7 16:59:46 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 86016, iter 0, not waiting. Progress = 0
Mar  7 16:59:48 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 87040,"remaining": -1,"iteration": 0}}
Mar  7 16:59:48 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 87040, iter 0, not waiting. Progress = 0
Mar  7 16:59:49 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 88064,"remaining": -1,"iteration": 0}}
Mar  7 16:59:49 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 88064, iter 0, not waiting. Progress = 0
Mar  7 16:59:51 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 89088,"remaining": -1,"iteration": 0}}
Mar  7 16:59:51 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 89088, iter 0, not waiting. Progress = 0
Mar  7 16:59:52 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 90112,"remaining": -1,"iteration": 0}}
Mar  7 16:59:52 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 90112 of 25229312 (0%)
Mar  7 16:59:52 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 90112, iter 0, not waiting. Progress = 0
Mar  7 16:59:54 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 91136,"remaining": -1,"iteration": 0}}
Mar  7 16:59:54 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 91136, iter 0, not waiting. Progress = 0
Mar  7 16:59:55 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 92160,"remaining": -1,"iteration": 0}}
Mar  7 16:59:55 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 92160, iter 0, not waiting. Progress = 0
Mar  7 16:59:56 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 93184,"remaining": -1,"iteration": 0}}
Mar  7 16:59:56 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 93184, iter 0, not waiting. Progress = 0
Mar  7 16:59:57 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 94208,"remaining": -1,"iteration": 0}}
Mar  7 16:59:57 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 94208, iter 0, not waiting. Progress = 0
Mar  7 16:59:58 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 95232,"remaining": -1,"iteration": 0}}
Mar  7 16:59:58 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 95232 of 25229312 (0%)
Mar  7 16:59:58 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 95232, iter 0, not waiting. Progress = 0
Mar  7 16:59:59 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 96256,"remaining": -1,"iteration": 0}}
Mar  7 16:59:59 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 96256, iter 0, not waiting. Progress = 0
Mar  7 17:00:00 ede-vmh001 systemd[1]: Started Session c89809 of user root.
Mar  7 17:00:00 ede-vmh001 systemd[1]: Starting Session c89809 of user root.
Mar  7 17:00:01 ede-vmh001 systemd[1]: Started Session c89810 of user root.
Mar  7 17:00:01 ede-vmh001 systemd[1]: Starting Session c89810 of user root.
Mar  7 17:00:01 ede-vmh001 systemd[1]: Started Session c89811 of user root.
Mar  7 17:00:01 ede-vmh001 systemd[1]: Starting Session c89811 of user root.
Mar  7 17:00:01 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 97280,"remaining": -1,"iteration": 0}}
Mar  7 17:00:01 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 97280, iter 0, not waiting. Progress = 0
Mar  7 17:00:02 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 98304,"remaining": -1,"iteration": 0}}
Mar  7 17:00:02 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 98304, iter 0, not waiting. Progress = 0
Mar  7 17:00:03 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 99328,"remaining": -1,"iteration": 0}}
Mar  7 17:00:03 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 99328, iter 0, not waiting. Progress = 0
Mar  7 17:00:04 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 100352,"remaining": -1,"iteration": 0}}
Mar  7 17:00:04 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 100352 of 25229312 (0%)
Mar  7 17:00:04 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 100352, iter 0, not waiting. Progress = 0
Mar  7 17:00:05 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 101376,"remaining": -1,"iteration": 0}}
Mar  7 17:00:05 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 101376, iter 0, not waiting. Progress = 0
Mar  7 17:00:06 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 102400,"remaining": -1,"iteration": 0}}
Mar  7 17:00:06 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 102400, iter 0, not waiting. Progress = 0
Mar  7 17:00:07 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 103424,"remaining": -1,"iteration": 0}}
Mar  7 17:00:07 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 103424, iter 0, not waiting. Progress = 0
Mar  7 17:00:08 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 104448,"remaining": -1,"iteration": 0}}
Mar  7 17:00:08 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 104448, iter 0, not waiting. Progress = 0
Mar  7 17:00:09 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 105472,"remaining": -1,"iteration": 0}}
Mar  7 17:00:09 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 105472 of 25229312 (0%)
Mar  7 17:00:09 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 105472, iter 0, not waiting. Progress = 0
Mar  7 17:00:10 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 106496,"remaining": -1,"iteration": 0}}
Mar  7 17:00:10 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 106496, iter 0, not waiting. Progress = 0
Mar  7 17:00:11 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 107520,"remaining": -1,"iteration": 0}}
Mar  7 17:00:11 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 107520, iter 0, not waiting. Progress = 0
Mar  7 17:00:12 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 108544,"remaining": -1,"iteration": 0}}
Mar  7 17:00:12 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 108544, iter 0, not waiting. Progress = 0
Mar  7 17:00:13 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 109568,"remaining": -1,"iteration": 0}}
Mar  7 17:00:13 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 109568, iter 0, not waiting. Progress = 0
Mar  7 17:00:14 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 110592,"remaining": -1,"iteration": 0}}
Mar  7 17:00:14 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 110592, iter 0, not waiting. Progress = 0
Mar  7 17:00:14 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 111616,"remaining": -1,"iteration": 0}}
Mar  7 17:00:14 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 111616 of 25229312 (0%)
Mar  7 17:00:14 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 111616, iter 0, not waiting. Progress = 0
Mar  7 17:00:15 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 112640,"remaining": -1,"iteration": 0}}
Mar  7 17:00:15 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 112640, iter 0, not waiting. Progress = 0
Mar  7 17:00:16 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 113664,"remaining": -1,"iteration": 0}}
Mar  7 17:00:16 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 113664, iter 0, not waiting. Progress = 0
Mar  7 17:00:17 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 114688,"remaining": -1,"iteration": 0}}
Mar  7 17:00:17 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 114688, iter 0, not waiting. Progress = 0
Mar  7 17:00:17 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 115712,"remaining": -1,"iteration": 0}}
Mar  7 17:00:17 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 115712, iter 0, not waiting. Progress = 0
Mar  7 17:00:18 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 116736,"remaining": -1,"iteration": 0}}
Mar  7 17:00:18 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 116736, iter 0, not waiting. Progress = 0
Mar  7 17:00:18 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 117760,"remaining": -1,"iteration": 0}}
Mar  7 17:00:18 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 117760, iter 0, not waiting. Progress = 0
Mar  7 17:00:19 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 118784,"remaining": -1,"iteration": 0}}
Mar  7 17:00:19 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 118784, iter 0, not waiting. Progress = 0
Mar  7 17:00:20 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 119808,"remaining": -1,"iteration": 0}}
Mar  7 17:00:20 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 119808 of 25229312 (0%)
Mar  7 17:00:20 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 119808, iter 0, not waiting. Progress = 0
Mar  7 17:00:20 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 120832,"remaining": -1,"iteration": 0}}
Mar  7 17:00:20 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 120832, iter 0, not waiting. Progress = 0
Mar  7 17:00:21 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 121856,"remaining": -1,"iteration": 0}}
Mar  7 17:00:21 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 121856, iter 0, not waiting. Progress = 0
Mar  7 17:00:21 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 122880,"remaining": -1,"iteration": 0}}
Mar  7 17:00:21 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 122880, iter 0, not waiting. Progress = 0
Mar  7 17:00:22 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 123904,"remaining": -1,"iteration": 0}}
Mar  7 17:00:22 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 123904, iter 0, not waiting. Progress = 0
Mar  7 17:00:23 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 124928,"remaining": -1,"iteration": 0}}
Mar  7 17:00:23 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 124928, iter 0, not waiting. Progress = 0
Mar  7 17:00:23 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 125952,"remaining": -1,"iteration": 0}}
Mar  7 17:00:23 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 125952, iter 0, not waiting. Progress = 0
Mar  7 17:00:24 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 126976,"remaining": -1,"iteration": 0}}
Mar  7 17:00:24 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 126976, iter 0, not waiting. Progress = 0
Mar  7 17:00:25 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 128000,"remaining": -1,"iteration": 0}}
Mar  7 17:00:25 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 128000, iter 0, not waiting. Progress = 0
Mar  7 17:00:25 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 129024,"remaining": -1,"iteration": 0}}
Mar  7 17:00:25 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 129024 of 25229312 (0%)
Mar  7 17:00:25 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 129024, iter 0, not waiting. Progress = 0
Mar  7 17:00:26 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 130048,"remaining": -1,"iteration": 0}}
Mar  7 17:00:26 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 130048, iter 0, not waiting. Progress = 0
Mar  7 17:00:27 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 131072,"remaining": -1,"iteration": 0}}
Mar  7 17:00:27 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 131072, iter 0, not waiting. Progress = 0
Mar  7 17:00:28 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 132096,"remaining": -1,"iteration": 0}}
Mar  7 17:00:28 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 132096, iter 0, not waiting. Progress = 0
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: received 'pause' message (uuid = 42)
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: control: pause requested
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: vbd: pause requested
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: NBD server pause(0x118aa10)
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: gaps written/skipped: 0/0
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: /var/run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/9d56b5b4-758d-4f41-be21-c47bbe3edf12.vhd: b: 102400, a: 15, f: 0, n: 62392
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: closed image /var/run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/9d56b5b4-758d-4f41-be21-c47bbe3edf12.vhd (0 users, state: 0x00000000, type: 4)
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: Sending disconnect request
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: Switching socket to blocking IO mode
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: Writing disconnection request
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: sent close request
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: NBD client full-disable
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: NBD client cancelling sent reqs
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: NBD client cancelling pending reqs
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: Setting closed
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: nbd: Written
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: closed image mirror_vbd/13/xvdh (0 users, state: 0x00000000, type: 15)
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: gaps written/skipped: 0/0
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: /run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/4b8c58fc-70eb-426e-ab86-cf1ac3adf3bb.vhd: b: 102400, a: 102399, f: 102390, n: 0
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: closed image /run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/4b8c58fc-70eb-426e-ab86-cf1ac3adf3bb.vhd (0 users, state: 0x00000002, type: 4)
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: vbd: pause completed
Mar  7 17:00:28 ede-vmh001 tapdisk[13712]: sending 'pause response' message (uuid = 42)
Mar  7 17:00:28 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 133120,"remaining": -1,"iteration": 0}}
Mar  7 17:00:28 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 133120, iter 0, not waiting. Progress = 0
Mar  7 17:00:29 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 134144,"remaining": -1,"iteration": 0}}
Mar  7 17:00:29 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 134144, iter 0, not waiting. Progress = 0
Mar  7 17:00:30 ede-vmh001 systemd[1]: Started Session c89812 of user root.
Mar  7 17:00:30 ede-vmh001 systemd[1]: Starting Session c89812 of user root.
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: received 'resume' message (uuid = 42)
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: control: resuming VBD 42, flags=0x00000000, secondary=0x63b0fc
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: /var/run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/9d56b5b4-758d-4f41-be21-c47bbe3edf12.vhd version: tap 0x00010003, b: 102400, a: 102399, f: 102390, n: 420246320
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: opened image /var/run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/9d56b5b4-758d-4f41-be21-c47bbe3edf12.vhd (1 users, state: 0x00000001, type: 4, rw)
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: VBD CHAIN:
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: /var/run/sr-mount/5c93fb03-318e-93cb-c16d-b0f8deca16f9/9d56b5b4-758d-4f41-be21-c47bbe3edf12.vhd: type:vhd(4) storage:ext(2)
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: Adding secondary image: nbd:mirror_vbd/13/xvdh
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: nbd: Opening nbd export to mirror_vbd/13/xvdh (flags=2408)
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: nbd: Found passed fd. Connecting...
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: nbd: Got size: 214748364800
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: nbd: Got flags: 0
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: nbd: Successfully connected to NBD server
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: nbd: Opening in secondary mode: Read requests will be forwarded
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: opened image mirror_vbd/13/xvdh (1 users, state: 0x00000001, type: 15, rw)
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: In mirror mode
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: Added secondary image
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: nbd: NBD server unpause(0x118aa10) - fdrecv_listening_fd -1, unix_listening_fd=23
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: nbd: registering for unix_listening_fd
Mar  7 17:00:30 ede-vmh001 tapdisk[13712]: sending 'resume response' message (uuid = 42)
Mar  7 17:00:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 135168,"remaining": -1,"iteration": 0}}
Mar  7 17:00:30 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 135168, iter 0, not waiting. Progress = 0
Mar  7 17:00:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 136192,"remaining": -1,"iteration": 0}}
Mar  7 17:00:30 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 136192 of 25229312 (0%)
Mar  7 17:00:30 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 136192, iter 0, not waiting. Progress = 0
Mar  7 17:00:31 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 137216,"remaining": -1,"iteration": 0}}
Mar  7 17:00:31 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 137216, iter 0, not waiting. Progress = 0
Mar  7 17:00:32 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 138240,"remaining": -1,"iteration": 0}}
Mar  7 17:00:32 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 138240, iter 0, not waiting. Progress = 0
Mar  7 17:00:33 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 140288,"remaining": -1,"iteration": 0}}
Mar  7 17:00:33 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 140288, iter 0, not waiting. Progress = 0
Mar  7 17:00:33 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 141312,"remaining": -1,"iteration": 0}}
Mar  7 17:00:33 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 141312, iter 0, not waiting. Progress = 0
Mar  7 17:00:34 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 143360,"remaining": -1,"iteration": 0}}
Mar  7 17:00:34 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 143360, iter 0, not waiting. Progress = 0
Mar  7 17:00:34 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 144384,"remaining": -1,"iteration": 0}}
Mar  7 17:00:34 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 144384, iter 0, not waiting. Progress = 0
Mar  7 17:00:35 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 146432,"remaining": -1,"iteration": 0}}
Mar  7 17:00:35 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 146432, iter 0, not waiting. Progress = 0
Mar  7 17:00:36 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 147456,"remaining": -1,"iteration": 0}}
Mar  7 17:00:36 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 147456 of 25229312 (0%)
Mar  7 17:00:36 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 147456, iter 0, not waiting. Progress = 0
Mar  7 17:00:37 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 148480,"remaining": -1,"iteration": 0}}
Mar  7 17:00:37 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 148480, iter 0, not waiting. Progress = 0
Mar  7 17:00:37 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 150528,"remaining": -1,"iteration": 0}}
Mar  7 17:00:37 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 150528, iter 0, not waiting. Progress = 0
Mar  7 17:00:38 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 151552,"remaining": -1,"iteration": 0}}
Mar  7 17:00:38 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 151552, iter 0, not waiting. Progress = 0
Mar  7 17:00:39 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 153600,"remaining": -1,"iteration": 0}}
Mar  7 17:00:39 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 153600, iter 0, not waiting. Progress = 0
Mar  7 17:00:39 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 154624,"remaining": -1,"iteration": 0}}
Mar  7 17:00:39 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 154624, iter 0, not waiting. Progress = 0
Mar  7 17:00:40 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 156672,"remaining": -1,"iteration": 0}}
Mar  7 17:00:40 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 156672, iter 0, not waiting. Progress = 0
Mar  7 17:00:41 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 158720,"remaining": -1,"iteration": 0}}
Mar  7 17:00:41 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 158720 of 25229312 (0%)
Mar  7 17:00:41 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 158720, iter 0, not waiting. Progress = 0
Mar  7 17:00:42 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 160768,"remaining": -1,"iteration": 0}}
Mar  7 17:00:42 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 160768, iter 0, not waiting. Progress = 0
Mar  7 17:00:43 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 162816,"remaining": -1,"iteration": 0}}
Mar  7 17:00:43 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 162816, iter 0, not waiting. Progress = 0

[NielsH]

Part 3:

Mar  7 17:00:44 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 164864,"remaining": -1,"iteration": 0}}
Mar  7 17:00:44 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 164864, iter 0, not waiting. Progress = 0
Mar  7 17:00:44 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 166912,"remaining": -1,"iteration": 0}}
Mar  7 17:00:44 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 166912, iter 0, not waiting. Progress = 0
Mar  7 17:00:45 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 168960,"remaining": -1,"iteration": 0}}
Mar  7 17:00:45 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 168960, iter 0, not waiting. Progress = 0
Mar  7 17:00:46 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 171008,"remaining": -1,"iteration": 0}}
Mar  7 17:00:46 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 171008, iter 0, not waiting. Progress = 0
Mar  7 17:00:46 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 172032 of 25229312 (0%)
Mar  7 17:00:47 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 173056,"remaining": -1,"iteration": 0}}
Mar  7 17:00:47 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 173056, iter 0, not waiting. Progress = 0
Mar  7 17:00:47 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 174080,"remaining": -1,"iteration": 0}}
Mar  7 17:00:47 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 174080, iter 0, not waiting. Progress = 0
Mar  7 17:00:48 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 176128,"remaining": -1,"iteration": 0}}
Mar  7 17:00:48 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 176128, iter 0, not waiting. Progress = 0
Mar  7 17:00:49 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 178176,"remaining": -1,"iteration": 0}}
Mar  7 17:00:49 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 178176, iter 0, not waiting. Progress = 0
Mar  7 17:00:50 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 180224,"remaining": -1,"iteration": 0}}
Mar  7 17:00:50 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 180224, iter 0, not waiting. Progress = 0
Mar  7 17:00:50 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 182272,"remaining": -1,"iteration": 0}}
Mar  7 17:00:50 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 182272, iter 0, not waiting. Progress = 0
Mar  7 17:00:51 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 184320,"remaining": -1,"iteration": 0}}
Mar  7 17:00:51 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 184320, iter 0, not waiting. Progress = 0
Mar  7 17:00:51 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 185344 of 25229312 (0%)
Mar  7 17:00:52 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 186368,"remaining": -1,"iteration": 0}}
Mar  7 17:00:52 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 186368, iter 0, not waiting. Progress = 0
Mar  7 17:00:52 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 188416,"remaining": -1,"iteration": 0}}
Mar  7 17:00:52 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 188416, iter 0, not waiting. Progress = 0
Mar  7 17:00:53 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 190464,"remaining": -1,"iteration": 0}}
Mar  7 17:00:53 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 190464, iter 0, not waiting. Progress = 0
Mar  7 17:00:54 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 192512,"remaining": -1,"iteration": 0}}
Mar  7 17:00:54 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 192512, iter 0, not waiting. Progress = 0
Mar  7 17:00:54 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 194560,"remaining": -1,"iteration": 0}}
Mar  7 17:00:54 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 194560, iter 0, not waiting. Progress = 0
Mar  7 17:00:55 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 196608,"remaining": -1,"iteration": 0}}
Mar  7 17:00:55 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 196608, iter 0, not waiting. Progress = 0
Mar  7 17:00:56 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 198656,"remaining": -1,"iteration": 0}}
Mar  7 17:00:56 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 198656, iter 0, not waiting. Progress = 0
Mar  7 17:00:56 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 200704,"remaining": -1,"iteration": 0}}
Mar  7 17:00:56 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 200704, iter 0, not waiting. Progress = 0
Mar  7 17:00:57 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 201728 of 25229312 (0%)
Mar  7 17:00:57 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 202752,"remaining": -1,"iteration": 0}}
Mar  7 17:00:57 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 202752, iter 0, not waiting. Progress = 0
Mar  7 17:00:58 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 204800,"remaining": -1,"iteration": 0}}
Mar  7 17:00:58 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 204800, iter 0, not waiting. Progress = 0
Mar  7 17:00:58 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 206848,"remaining": -1,"iteration": 0}}
Mar  7 17:00:58 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 206848, iter 0, not waiting. Progress = 0
Mar  7 17:00:59 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 208896,"remaining": -1,"iteration": 0}}
Mar  7 17:00:59 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 208896, iter 0, not waiting. Progress = 0
Mar  7 17:01:00 ede-vmh001 systemd[1]: Started Session c89813 of user root.
Mar  7 17:01:00 ede-vmh001 systemd[1]: Starting Session c89813 of user root.
Mar  7 17:01:00 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 210944,"remaining": -1,"iteration": 0}}
Mar  7 17:01:00 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 210944, iter 0, not waiting. Progress = 0
Mar  7 17:01:00 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 212992,"remaining": -1,"iteration": 0}}
Mar  7 17:01:00 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 212992, iter 0, not waiting. Progress = 0
Mar  7 17:01:01 ede-vmh001 systemd[1]: Started Session c89814 of user root.
Mar  7 17:01:01 ede-vmh001 systemd[1]: Starting Session c89814 of user root.
Mar  7 17:01:01 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 215040,"remaining": -1,"iteration": 0}}
Mar  7 17:01:01 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 215040, iter 0, not waiting. Progress = 0
Mar  7 17:01:02 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 217088,"remaining": -1,"iteration": 0}}
Mar  7 17:01:02 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 217088, iter 0, not waiting. Progress = 0
Mar  7 17:01:02 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 218112 of 25229312 (0%)
Mar  7 17:01:02 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 219136,"remaining": -1,"iteration": 0}}
Mar  7 17:01:02 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 219136, iter 0, not waiting. Progress = 0
Mar  7 17:01:03 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 221184,"remaining": -1,"iteration": 0}}
Mar  7 17:01:03 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 221184, iter 0, not waiting. Progress = 0
Mar  7 17:01:03 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 223232,"remaining": -1,"iteration": 0}}
Mar  7 17:01:03 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 223232, iter 0, not waiting. Progress = 0
Mar  7 17:01:04 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 225280,"remaining": -1,"iteration": 0}}
Mar  7 17:01:04 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 225280, iter 0, not waiting. Progress = 0
Mar  7 17:01:05 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 227328,"remaining": -1,"iteration": 0}}
Mar  7 17:01:05 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 227328, iter 0, not waiting. Progress = 0
Mar  7 17:01:05 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 229376,"remaining": -1,"iteration": 0}}
Mar  7 17:01:05 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 229376, iter 0, not waiting. Progress = 0
Mar  7 17:01:06 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 231424,"remaining": -1,"iteration": 0}}
Mar  7 17:01:06 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 231424, iter 0, not waiting. Progress = 0
Mar  7 17:01:06 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 233472,"remaining": -1,"iteration": 0}}
Mar  7 17:01:06 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 233472, iter 0, not waiting. Progress = 0
Mar  7 17:01:07 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 236544,"remaining": -1,"iteration": 0}}
Mar  7 17:01:07 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 236544 of 25229312 (0%)
Mar  7 17:01:07 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 236544, iter 0, not waiting. Progress = 0
Mar  7 17:01:08 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 239616,"remaining": -1,"iteration": 0}}
Mar  7 17:01:08 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 239616, iter 0, not waiting. Progress = 0
Mar  7 17:01:08 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 242688,"remaining": -1,"iteration": 0}}
Mar  7 17:01:08 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 242688, iter 0, not waiting. Progress = 0
Mar  7 17:01:09 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 245760,"remaining": -1,"iteration": 0}}
Mar  7 17:01:09 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 245760, iter 0, not waiting. Progress = 0
Mar  7 17:01:10 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 247808,"remaining": -1,"iteration": 0}}
Mar  7 17:01:10 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 247808, iter 0, not waiting. Progress = 0
Mar  7 17:01:10 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 249856,"remaining": -1,"iteration": 0}}
Mar  7 17:01:10 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 249856, iter 0, not waiting. Progress = 0
Mar  7 17:01:11 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 252928,"remaining": -1,"iteration": 0}}
Mar  7 17:01:11 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 252928, iter 0, not waiting. Progress = 0
Mar  7 17:01:12 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 256000,"remaining": -1,"iteration": 0}}
Mar  7 17:01:12 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 256000, iter 0, not waiting. Progress = 0
Mar  7 17:01:12 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 258048 of 25229312 (1%)
Mar  7 17:01:12 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 259072,"remaining": -1,"iteration": 0}}
Mar  7 17:01:12 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 259072, iter 0, not waiting. Progress = 0
Mar  7 17:01:13 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 262144,"remaining": -1,"iteration": 0}}
Mar  7 17:01:13 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 262144, iter 0, not waiting. Progress = 0
Mar  7 17:01:14 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 264192,"remaining": -1,"iteration": 0}}
Mar  7 17:01:14 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 264192, iter 0, not waiting. Progress = 0
Mar  7 17:01:14 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 267264,"remaining": -1,"iteration": 0}}
Mar  7 17:01:14 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 267264, iter 0, not waiting. Progress = 0
Mar  7 17:01:15 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 269312,"remaining": -1,"iteration": 0}}
Mar  7 17:01:15 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 269312, iter 0, not waiting. Progress = 0
Mar  7 17:01:16 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 272384,"remaining": -1,"iteration": 0}}
Mar  7 17:01:16 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 272384, iter 0, not waiting. Progress = 0
Mar  7 17:01:16 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 275456,"remaining": -1,"iteration": 0}}
Mar  7 17:01:16 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 275456, iter 0, not waiting. Progress = 0
Mar  7 17:01:17 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 277504,"remaining": -1,"iteration": 0}}
Mar  7 17:01:17 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 277504, iter 0, not waiting. Progress = 0
Mar  7 17:01:17 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 278528 of 25229312 (1%)
Mar  7 17:01:17 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 279552,"remaining": -1,"iteration": 0}}
Mar  7 17:01:17 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 279552, iter 0, not waiting. Progress = 0
Mar  7 17:01:18 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 281600,"remaining": -1,"iteration": 0}}
Mar  7 17:01:18 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 281600, iter 0, not waiting. Progress = 0
Mar  7 17:01:19 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 283648,"remaining": -1,"iteration": 0}}
Mar  7 17:01:19 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 283648, iter 0, not waiting. Progress = 0
Mar  7 17:01:19 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 285696,"remaining": -1,"iteration": 0}}
Mar  7 17:01:19 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 285696, iter 0, not waiting. Progress = 0
Mar  7 17:01:20 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 287744,"remaining": -1,"iteration": 0}}
Mar  7 17:01:20 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 287744, iter 0, not waiting. Progress = 0
Mar  7 17:01:21 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 289792,"remaining": -1,"iteration": 0}}
Mar  7 17:01:21 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 289792, iter 0, not waiting. Progress = 0
Mar  7 17:01:21 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 291840,"remaining": -1,"iteration": 0}}
Mar  7 17:01:21 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 291840, iter 0, not waiting. Progress = 0
Mar  7 17:01:22 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 293888,"remaining": -1,"iteration": 0}}
Mar  7 17:01:22 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 293888, iter 0, not waiting. Progress = 0
Mar  7 17:01:22 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 295936,"remaining": -1,"iteration": 0}}
Mar  7 17:01:22 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 295936 of 25229312 (1%)
Mar  7 17:01:22 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 295936, iter 0, not waiting. Progress = 0
Mar  7 17:01:23 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 297984,"remaining": -1,"iteration": 0}}
Mar  7 17:01:23 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 297984, iter 0, not waiting. Progress = 0
Mar  7 17:01:24 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 300032,"remaining": -1,"iteration": 0}}
Mar  7 17:01:24 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 300032, iter 0, not waiting. Progress = 0
Mar  7 17:01:24 ede-vmh001 squeezed[28579]: [6731.51] watch /data/updated <- Tue Mar  7 17:01:24 2023
Mar  7 17:01:24 ede-vmh001 squeezed: [debug||4 ||xenops] watch /data/updated <- Tue Mar  7 17:01:24 2023
Mar  7 17:01:24 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 302080,"remaining": -1,"iteration": 0}}
Mar  7 17:01:24 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 302080, iter 0, not waiting. Progress = 0
Mar  7 17:01:25 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 304128,"remaining": -1,"iteration": 0}}
Mar  7 17:01:25 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 304128, iter 0, not waiting. Progress = 0
Mar  7 17:01:25 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 306176,"remaining": -1,"iteration": 0}}
Mar  7 17:01:25 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 306176, iter 0, not waiting. Progress = 0
Mar  7 17:01:26 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 308224,"remaining": -1,"iteration": 0}}
Mar  7 17:01:26 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 308224, iter 0, not waiting. Progress = 0
Mar  7 17:01:27 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 310272,"remaining": -1,"iteration": 0}}
Mar  7 17:01:27 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 310272, iter 0, not waiting. Progress = 0
Mar  7 17:01:27 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 313344,"remaining": -1,"iteration": 0}}
Mar  7 17:01:27 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 313344, iter 0, not waiting. Progress = 0
Mar  7 17:01:27 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 314368 of 25229312 (1%)
Mar  7 17:01:28 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 316416,"remaining": -1,"iteration": 0}}
Mar  7 17:01:28 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 316416, iter 0, not waiting. Progress = 1
Mar  7 17:01:29 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 319488,"remaining": -1,"iteration": 0}}
Mar  7 17:01:29 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 319488, iter 0, not waiting. Progress = 1
Mar  7 17:01:29 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 321536,"remaining": -1,"iteration": 0}}
Mar  7 17:01:29 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 321536, iter 0, not waiting. Progress = 1
Mar  7 17:01:30 ede-vmh001 systemd[1]: Started Session c89815 of user root.
Mar  7 17:01:30 ede-vmh001 systemd[1]: Starting Session c89815 of user root.
Mar  7 17:01:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 323584,"remaining": -1,"iteration": 0}}
Mar  7 17:01:30 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 323584, iter 0, not waiting. Progress = 1
Mar  7 17:01:30 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 325632,"remaining": -1,"iteration": 0}}
Mar  7 17:01:30 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 325632, iter 0, not waiting. Progress = 1
Mar  7 17:01:31 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 328704,"remaining": -1,"iteration": 0}}
Mar  7 17:01:31 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 328704, iter 0, not waiting. Progress = 1
Mar  7 17:01:32 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 331776,"remaining": -1,"iteration": 0}}
Mar  7 17:01:32 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 331776, iter 0, not waiting. Progress = 1
Mar  7 17:01:32 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 333824,"remaining": -1,"iteration": 0}}
Mar  7 17:01:32 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 333824, iter 0, not waiting. Progress = 1
Mar  7 17:01:33 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 335872 of 25229312 (1%)
Mar  7 17:01:33 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 336896,"remaining": -1,"iteration": 0}}
Mar  7 17:01:33 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 336896, iter 0, not waiting. Progress = 1
Mar  7 17:01:34 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 338944,"remaining": -1,"iteration": 0}}
Mar  7 17:01:34 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 338944, iter 0, not waiting. Progress = 1
Mar  7 17:01:34 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 340992,"remaining": -1,"iteration": 0}}
Mar  7 17:01:34 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 340992, iter 0, not waiting. Progress = 1
Mar  7 17:01:35 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 343040,"remaining": -1,"iteration": 0}}
Mar  7 17:01:35 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 343040, iter 0, not waiting. Progress = 1
Mar  7 17:01:36 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 345088,"remaining": -1,"iteration": 0}}
Mar  7 17:01:36 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 345088, iter 0, not waiting. Progress = 1
Mar  7 17:01:37 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 347136,"remaining": -1,"iteration": 0}}
Mar  7 17:01:37 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 347136, iter 0, not waiting. Progress = 1
Mar  7 17:01:38 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 349184,"remaining": -1,"iteration": 0}}
Mar  7 17:01:38 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 349184, iter 0, not waiting. Progress = 1
Mar  7 17:01:38 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 350208 of 25229312 (1%)
Mar  7 17:01:38 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 351232,"remaining": -1,"iteration": 0}}
Mar  7 17:01:38 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 351232, iter 0, not waiting. Progress = 1
Mar  7 17:01:39 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 353280,"remaining": -1,"iteration": 0}}
Mar  7 17:01:39 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 353280, iter 0, not waiting. Progress = 1
Mar  7 17:01:39 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 355328,"remaining": -1,"iteration": 0}}
Mar  7 17:01:39 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 355328, iter 0, not waiting. Progress = 1
Mar  7 17:01:40 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 357376,"remaining": -1,"iteration": 0}}
Mar  7 17:01:40 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 357376, iter 0, not waiting. Progress = 1
Mar  7 17:01:41 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 359424,"remaining": -1,"iteration": 0}}
Mar  7 17:01:41 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 359424, iter 0, not waiting. Progress = 1
Mar  7 17:01:41 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 361472,"remaining": -1,"iteration": 0}}
Mar  7 17:01:41 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 361472, iter 0, not waiting. Progress = 1
Mar  7 17:01:42 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 363520,"remaining": -1,"iteration": 0}}
Mar  7 17:01:42 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 363520, iter 0, not waiting. Progress = 1
Mar  7 17:01:42 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 366592,"remaining": -1,"iteration": 0}}
Mar  7 17:01:42 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 366592, iter 0, not waiting. Progress = 1
Mar  7 17:01:43 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 368640 of 25229312 (1%)
Mar  7 17:01:43 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 369664,"remaining": -1,"iteration": 0}}
Mar  7 17:01:43 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 369664, iter 0, not waiting. Progress = 1
Mar  7 17:01:44 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 372736,"remaining": -1,"iteration": 0}}
Mar  7 17:01:44 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 372736, iter 0, not waiting. Progress = 1
Mar  7 17:01:44 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 375808,"remaining": -1,"iteration": 0}}
Mar  7 17:01:44 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 375808, iter 0, not waiting. Progress = 1
Mar  7 17:01:45 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 378880,"remaining": -1,"iteration": 0}}
Mar  7 17:01:45 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 378880, iter 0, not waiting. Progress = 1
Mar  7 17:01:46 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 381952,"remaining": -1,"iteration": 0}}
Mar  7 17:01:46 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 381952, iter 0, not waiting. Progress = 1
Mar  7 17:01:47 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 385024,"remaining": -1,"iteration": 0}}
Mar  7 17:01:47 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 385024, iter 0, not waiting. Progress = 1
Mar  7 17:01:47 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 388096,"remaining": -1,"iteration": 0}}
Mar  7 17:01:47 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 388096, iter 0, not waiting. Progress = 1
Mar  7 17:01:48 ede-vmh001 xenguest-13-emp[21258]: libempserver:debug: replying to (0): { "event" : "MIGRATION", "data": {"sent": 391168,"remaining": -1,"iteration": 0}}
Mar  7 17:01:48 ede-vmh001 emu-manager-13[21257]: Event for `xenguest`: rem -1, sent 391168, iter 0, not waiting. Progress = 1
Mar  7 17:01:48 ede-vmh001 xenguest-13-emp[21258]: progress: Frames iteration 0: 392192 of 25229312 (1%)