Open Stack

Hi,

i ‘ve got live migration issue in one direction but not in other.
I deploy openstack with OSA, ubuntu trusty, stable/newton branch, 14.0.5 tag.

My 2 compute node are same host type and have nova-compute and cinder-volume (our ceph cluster as backend) services.

No problem to live migrate instance from Compute 2 to Compute 1 whereas the reverse is not true.
See log below:

Live migration instance Compute 2 to 1: OK

Compute 2 log
2017-01-25 11:00:15.621 28309 INFO nova.virt.libvirt.migration [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Increasing downtime to 46 ms after 0 sec elapsed time
2017-01-25 11:00:15.787 28309 INFO nova.virt.libvirt.driver [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Migration running for 0 secs, memory 100% remaining; (bytes processed=0, remaining=0, total=0)
2017-01-25 11:00:17.737 28309 INFO nova.compute.manager [-] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] VM Paused (Lifecycle Event)
2017-01-25 11:00:17.794 28309 INFO nova.virt.libvirt.driver [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Migration operation has completed
2017-01-25 11:00:17.795 28309 INFO nova.compute.manager [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] _post_live_migration() is started..
2017-01-25 11:00:17.815 28309 INFO oslo.privsep.daemon [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Running privsep helper: ['sudo', 'nova-rootwrap', '/etc/nova/rootwrap.conf', 'privsep-helper', '--config-file', '/etc/nova/nova.conf', '--privsep_context', 'os_brick.privileged.default', '--privsep_sock_path', '/tmp/tmpfL96lI/privsep.sock']
2017-01-25 11:00:18.387 28309 INFO oslo.privsep.daemon [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Spawned new privsep daemon via rootwrap
2017-01-25 11:00:18.395 28309 INFO oslo.privsep.daemon [-] privsep daemon starting
2017-01-25 11:00:18.396 28309 INFO oslo.privsep.daemon [-] privsep process running with uid/gid: 0/0
2017-01-25 11:00:18.396 28309 INFO oslo.privsep.daemon [-] privsep process running with capabilities (eff/prm/inh): CAP_SYS_ADMIN/CAP_SYS_ADMIN/none
2017-01-25 11:00:18.396 28309 INFO oslo.privsep.daemon [-] privsep daemon running as pid 28815
2017-01-25 11:00:18.397 28309 INFO nova.compute.manager [req-aa0997d7-bf5f-480f-abc5-beadd2d03409 - - - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] During sync_power_state the instance has a pending task (migrating). Skip.
2017-01-25 11:00:18.538 28309 INFO nova.compute.manager [req-115a99b8-48ef-43d5-908b-5ff7aadc3df4 - - - - -] Running instance usage audit for host p-oscompute02 from 2017-01-25 09:00:00 to 2017-01-25 10:00:00. 2 instances.
2017-01-25 11:00:18.691 28309 INFO nova.compute.resource_tracker [req-115a99b8-48ef-43d5-908b-5ff7aadc3df4 - - - - -] Auditing locally available compute resources for node p-oscompute02.openstack.local
2017-01-25 11:00:19.634 28309 INFO nova.compute.resource_tracker [req-115a99b8-48ef-43d5-908b-5ff7aadc3df4 - - - - -] Total usable vcpus: 40, total allocated vcpus: 4
2017-01-25 11:00:19.635 28309 INFO nova.compute.resource_tracker [req-115a99b8-48ef-43d5-908b-5ff7aadc3df4 - - - - -] Final resource view: name=p-oscompute02.openstack.local phys_ram=128700MB used_ram=6144MB phys_disk=33493GB used_disk=22GB total_vcpus=40 used_vcpus=4 pci_stats=[]
2017-01-25 11:00:19.709 28309 INFO nova.compute.resource_tracker [req-115a99b8-48ef-43d5-908b-5ff7aadc3df4 - - - - -] Compute_service record updated for p-oscompute02:p-oscompute02.openstack.local
2017-01-25 11:00:20.163 28309 INFO os_vif [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Successfully unplugged vif VIFBridge(active=True,address=fa:16:3e:d2:7c:83,bridge_name='brqc434ace8-45',has_traffic_filtering=True,id=dff20b91-a654-437d-8a74-dc55aeac8ab7,network=Network(c434ace8-45f6-4bb1-95bc-d52dadb557c7),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapdff20b91-a6')
2017-01-25 11:00:20.201 28309 INFO nova.virt.libvirt.driver [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Deleting instance files /var/lib/nova/instances/c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3_del
2017-01-25 11:00:20.202 28309 INFO nova.virt.libvirt.driver [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Deletion of /var/lib/nova/instances/c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3_del complete
2017-01-25 11:00:20.352 28309 INFO nova.compute.resource_tracker [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Auditing locally available compute resources for node p-oscompute02.openstack.local
2017-01-25 11:00:21.143 28309 INFO nova.compute.resource_tracker [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Total usable vcpus: 40, total allocated vcpus: 4
2017-01-25 11:00:21.143 28309 INFO nova.compute.resource_tracker [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Final resource view: name=p-oscompute02.openstack.local phys_ram=128700MB used_ram=6144MB phys_disk=33493GB used_disk=22GB total_vcpus=40 used_vcpus=4 pci_stats=[]
2017-01-25 11:00:21.204 28309 INFO nova.compute.resource_tracker [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Compute_service record updated for p-oscompute02:p-oscompute02.openstack.local
2017-01-25 11:00:21.214 28309 INFO nova.compute.manager [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Migrating instance to p-oscompute01 finished successfully.
2017-01-25 11:00:21.215 28309 INFO nova.compute.manager [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] You may see the error "libvirt: QEMU error: Domain not found: no domain with matching name." This error can be safely ignored.
2017-01-25 11:00:33.399 28309 INFO nova.compute.manager [-] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] VM Stopped (Lifecycle Event)

Compute 1 log
2017-01-25 11:00:13.067 113231 INFO nova.virt.libvirt.driver [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Instance launched has CPU info: {"vendor": "Intel", "model": "Haswell-noTSX", "arch": "x86_64", "features": ["pge", "avx", "clflush", "sep", "syscall", "vme", "dtes64", "invpcid", "tsc", "fsgsbase", "xsave", "vmx", "erms", "xtpr", "cmov", "smep", "ssse3", "est", "pat", "monitor", "smx", "pbe", "lm", "msr", "nx", "fxsr", "tm", "sse4.1", "pae", "sse4.2", "pclmuldq", "acpi", "fma", "tsc-deadline", "mmx", "osxsave", "cx8", "mce", "de", "tm2", "ht", "dca", "lahf_lm", "abm", "popcnt", "mca", "pdpe1gb", "apic", "sse", "f16c", "pse", "ds", "invtsc", "pni", "rdtscp", "avx2", "aes", "sse2", "ss", "ds_cpl", "bmi1", "bmi2", "pcid", "fpu", "cx16", "pse36", "mtrr", "movbe", "pdcm", "rdrand", "x2apic"], "topology": {"cores": 10, "cells": 2, "threads": 2, "sockets": 1}}
2017-01-25 11:00:13.434 113231 INFO oslo.privsep.daemon [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Running privsep helper: ['sudo', 'nova-rootwrap', '/etc/nova/rootwrap.conf', 'privsep-helper', '--config-file', '/etc/nova/nova.conf', '--privsep_context', 'os_brick.privileged.default', '--privsep_sock_path', '/tmp/tmp0444cm/privsep.sock']
2017-01-25 11:00:13.984 113231 INFO oslo.privsep.daemon [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Spawned new privsep daemon via rootwrap
2017-01-25 11:00:13.986 113231 INFO oslo.privsep.daemon [-] privsep daemon starting
2017-01-25 11:00:13.986 113231 INFO oslo.privsep.daemon [-] privsep process running with uid/gid: 0/0
2017-01-25 11:00:13.987 113231 INFO oslo.privsep.daemon [-] privsep process running with capabilities (eff/prm/inh): CAP_SYS_ADMIN/CAP_SYS_ADMIN/none
2017-01-25 11:00:13.987 113231 INFO oslo.privsep.daemon [-] privsep daemon running as pid 113978
2017-01-25 11:00:14.856 113231 INFO os_vif [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Successfully plugged vif VIFBridge(active=True,address=fa:16:3e:d2:7c:83,bridge_name='brqc434ace8-45',has_traffic_filtering=True,id=dff20b91-a654-437d-8a74-dc55aeac8ab7,network=Network(c434ace8-45f6-4bb1-95bc-d52dadb557c7),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapdff20b91-a6')
2017-01-25 11:00:15.931 113231 INFO nova.compute.resource_tracker [req-7d438646-5f1d-4cad-9c29-98272c1b8352 - - - - -] Auditing locally available compute resources for node p-oscompute01.openstack.local
2017-01-25 11:00:16.748 113231 INFO nova.compute.resource_tracker [req-7d438646-5f1d-4cad-9c29-98272c1b8352 - - - - -] Total usable vcpus: 40, total allocated vcpus: 8
2017-01-25 11:00:16.749 113231 INFO nova.compute.resource_tracker [req-7d438646-5f1d-4cad-9c29-98272c1b8352 - - - - -] Final resource view: name=p-oscompute01.openstack.local phys_ram=128700MB used_ram=12288MB phys_disk=33493GB used_disk=72GB total_vcpus=40 used_vcpus=8 pci_stats=[]
2017-01-25 11:00:16.819 113231 INFO nova.compute.resource_tracker [req-7d438646-5f1d-4cad-9c29-98272c1b8352 - - - - -] Compute_service record updated for p-oscompute01:p-oscompute01.openstack.local
2017-01-25 11:00:17.227 113231 INFO nova.compute.manager [-] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] VM Started (Lifecycle Event)
2017-01-25 11:00:17.896 113231 INFO nova.compute.manager [req-926f2642-43af-42a6-8b0a-1fcbf8c433ee - - - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] VM Resumed (Lifecycle Event)
2017-01-25 11:00:17.959 113231 INFO nova.compute.manager [req-7d438646-5f1d-4cad-9c29-98272c1b8352 - - - - -] Running instance usage audit for host p-oscompute01 from 2017-01-25 09:00:00 to 2017-01-25 10:00:00. 7 instances.
2017-01-25 11:00:18.027 113231 INFO nova.compute.manager [req-926f2642-43af-42a6-8b0a-1fcbf8c433ee - - - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] During the sync_power process the instance has moved from host p-oscompute02 to host p-oscompute01
2017-01-25 11:00:18.028 113231 INFO nova.compute.manager [req-926f2642-43af-42a6-8b0a-1fcbf8c433ee - - - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] VM Resumed (Lifecycle Event)
2017-01-25 11:00:18.135 113231 INFO nova.compute.manager [req-926f2642-43af-42a6-8b0a-1fcbf8c433ee - - - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] During the sync_power process the instance has moved from host p-oscompute02 to host p-oscompute01
2017-01-25 11:00:20.231 113231 INFO nova.compute.manager [req-6f21e4a4-28a8-48e3-bf2f-2e1ad3b52470 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Post operation of migration started


Live migration Compute 1 to 2: NOK

Compute 1 log
2017-01-25 11:03:57.676 113231 INFO nova.virt.libvirt.migration [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Increasing downtime to 46 ms after 0 sec elapsed time
2017-01-25 11:03:57.812 113231 INFO nova.virt.libvirt.driver [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Migration running for 0 secs, memory 100% remaining; (bytes processed=0, remaining=0, total=0)
2017-01-25 11:03:58.475 113231 ERROR nova.virt.libvirt.driver [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Live Migration failure: Requested operation is not valid: domain 'instance-00000187' is already active
2017-01-25 11:03:58.817 113231 ERROR nova.virt.libvirt.driver [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Migration operation has aborted

Compute 2 log
2017-01-25 11:03:55.783 28309 INFO nova.virt.libvirt.driver [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Instance launched has CPU info: {"vendor": "Intel", "model": "Haswell-noTSX", "arch": "x86_64", "features": ["pge", "avx", "clflush", "sep", "syscall", "vme", "dtes64", "invpcid", "tsc", "fsgsbase", "xsave", "vmx", "erms", "xtpr", "cmov", "smep", "ssse3", "est", "pat", "monitor", "smx", "pbe", "lm", "msr", "nx", "fxsr", "tm", "sse4.1", "pae", "sse4.2", "pclmuldq", "acpi", "fma", "tsc-deadline", "mmx", "osxsave", "cx8", "mce", "de", "tm2", "ht", "dca", "lahf_lm", "abm", "popcnt", "mca", "pdpe1gb", "apic", "sse", "f16c", "pse", "ds", "invtsc", "pni", "rdtscp", "avx2", "aes", "sse2", "ss", "ds_cpl", "bmi1", "bmi2", "pcid", "fpu", "cx16", "pse36", "mtrr", "movbe", "pdcm", "rdrand", "x2apic"], "topology": {"cores": 10, "cells": 2, "threads": 2, "sockets": 1}}
2017-01-25 11:03:56.849 28309 INFO os_vif [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Successfully plugged vif VIFBridge(active=True,address=fa:16:3e:d2:7c:83,bridge_name='brqc434ace8-45',has_traffic_filtering=True,id=dff20b91-a654-437d-8a74-dc55aeac8ab7,network=Network(c434ace8-45f6-4bb1-95bc-d52dadb557c7),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapdff20b91-a6')
2017-01-25 11:03:58.981 28309 INFO nova.compute.manager [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Detach volume f40efa24-4992-49ac-8d75-4ace88d9ecf7 from mountpoint /dev/vda
2017-01-25 11:03:58.984 28309 WARNING nova.compute.manager [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Detaching volume from unknown instance
2017-01-25 11:03:58.986 28309 WARNING nova.virt.libvirt.driver [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] During detach_volume, instance disappeared.
2017-01-25 11:04:00.033 28309 INFO nova.virt.libvirt.driver [-] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] During wait destroy, instance disappeared.
2017-01-25 11:04:00.034 28309 INFO os_vif [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] Successfully unplugged vif VIFBridge(active=True,address=fa:16:3e:d2:7c:83,bridge_name='brqc434ace8-45',has_traffic_filtering=True,id=dff20b91-a654-437d-8a74-dc55aeac8ab7,network=Network(c434ace8-45f6-4bb1-95bc-d52dadb557c7),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapdff20b91-a6')
2017-01-25 11:04:00.049 28309 INFO nova.virt.libvirt.driver [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Deleting instance files /var/lib/nova/instances/c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3_del
2017-01-25 11:04:00.050 28309 INFO nova.virt.libvirt.driver [req-7bd352bf-8818-4f71-9fa0-04fabccebf9c 0329776bd1634978a7fed35a70c77479 7531f209e3514e3f98eb58aafa480285 - - -] [instance: c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3] Deletion of /var/lib/nova/instances/c7a5e5d1-bc22-4143-a85a-ee5c3b6777b3_del complete 

Need some help or some hints to resolve/debug this issue. Give me some headache ;-) Because compute node hardware are the same, nova/libvirt conf too.

Regards,

Fabrice Grelaud
Université de Bordeaux