Issue apparent in weekly nova regression testcase test_kpi_live_migrate[virtio] FAIL 20190714 12:25:41 test_kpi_live_migrate[virtio] Lab: WCP_63_66 Load: 20190713T013000Z For the following instance name='instance-00000171' uuid=dafd6ed4-584b-42dc-9a3c-392a041a7fd0 [2019-07-14 12:27:47,762] 423 DEBUG MainThread ssh.expect :: Output: +--------------------------------------+----------------------+--------+------------------------------------------------------------------------------------------+-------+----------+ | ID | Name | Status | Networks | Image | Flavor | +--------------------------------------+----------------------+--------+------------------------------------------------------------------------------------------+-------+----------+ | dafd6ed4-584b-42dc-9a3c-392a041a7fd0 | tenant2-virtio-0-130 | ACTIVE | internal0-net0-1=10.1.1.153; tenant2-mgmt-net=192.168.200.244; tenant2-net0=172.18.0.244 | | virtio-2 | | 97a93dbc-e59b-4b16-8c9d-3cfb26c3084c | tenant1-virtio-0-129 | ACTIVE | internal0-net0-1=10.1.1.212; tenant1-mgmt-net=192.168.100.150; tenant1-net1=172.16.1.180 | | virtio | [2019-07-14 12:27:54,084] 2567 WARNING MainThread network_helper.ping_server:: Ping from 128.224.186.181 to 192.168.200.244 failed. {"log":"2019-07-14 12:27:38.893 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Port 4243fe83-9615-4416-a4dd-af0cb5ebe8bd updated. Details: {'profile': {}, 'network_qos_policy_id': None, 'qos_policy_id': None, 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': 'e0a1f447-786d-41fc-815a-839d1d9644f5', 'segmentation_id': 808, 'fixed_ips': [{'subnet_id': '59652421-1905-4e5b-acbb-e272bbcb3549', 'ip_address': '10.1.1.153'}], 'device_owner': u'compute:nova', 'physical_network': u'group0-data0', 'mac_address': 'fa:16:3e:0e:2a:96', 'device': '4243fe83-9615-4416-a4dd-af0cb5ebe8bd', 'port_security_enabled': True, 'port_id': '4243fe83-9615-4416-a4dd-af0cb5ebe8bd', 'network_type': u'vlan', 'security_groups': [u'1e77918c-b860-4fe5-89db-9b7c31b9d526']}\n","stream":"stdout","time":"2019-07-14T12:27:38.8942472Z"} {"log":"2019-07-14 12:27:38.893 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Port 4243fe83-9615-4416-a4dd-af0cb5ebe8bd updated. Details: {'profile': {}, 'network_qos_policy_id': None, 'qos_policy_id': None, 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': 'e0a1f447-786d-41fc-815a-839d1d9644f5', 'segmentation_id': 808, 'fixed_ips': [{'subnet_id': '59652421-1905-4e5b-acbb-e272bbcb3549', 'ip_address': '10.1.1.153'}], 'device_owner': u'compute:nova', 'physical_network': u'group0-data0', 'mac_address': 'fa:16:3e:0e:2a:96', 'device': '4243fe83-9615-4416-a4dd-af0cb5ebe8bd', 'port_security_enabled': True, 'port_id': '4243fe83-9615-4416-a4dd-af0cb5ebe8bd', 'network_type': u'vlan', 'security_groups': [u'1e77918c-b860-4fe5-89db-9b7c31b9d526']}\n","stream":"stdout","time":"2019-07-14T12:27:38.894515973Z"} {"log":"2019-07-14 12:27:38.895 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Port 4ed40235-c566-472d-acc1-ba074013f9f2 updated. Details: {'profile': {}, 'network_qos_policy_id': None, 'qos_policy_id': None, 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': 'ebe48295-5406-4aef-9a9f-b1d6d662ff1d', 'segmentation_id': 879, 'fixed_ips': [{'subnet_id': '298e165f-004f-4915-8c5b-737b74a5e176', 'ip_address': '192.168.200.244'}], 'device_owner': u'compute:nova', 'physical_network': u'group0-data0', 'mac_address': 'fa:16:3e:bd:c1:a2', 'device': '4ed40235-c566-472d-acc1-ba074013f9f2', 'port_security_enabled': True, 'port_id': '4ed40235-c566-472d-acc1-ba074013f9f2', 'network_type': u'vlan', 'security_groups': [u'1e77918c-b860-4fe5-89db-9b7c31b9d526']}\n","stream":"stdout","time":"2019-07-14T12:27:38.896118768Z"} {"log":"2019-07-14 12:27:38.895 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Port 4ed40235-c566-472d-acc1-ba074013f9f2 updated. Details: {'profile': {}, 'network_qos_policy_id': None, 'qos_policy_id': None, 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': 'ebe48295-5406-4aef-9a9f-b1d6d662ff1d', 'segmentation_id': 879, 'fixed_ips': [{'subnet_id': '298e165f-004f-4915-8c5b-737b74a5e176', 'ip_address': '192.168.200.244'}], 'device_owner': u'compute:nova', 'physical_network': u'group0-data0', 'mac_address': 'fa:16:3e:bd:c1:a2', 'device': '4ed40235-c566-472d-acc1-ba074013f9f2', 'port_security_enabled': True, 'port_id': '4ed40235-c566-472d-acc1-ba074013f9f2', 'network_type': u'vlan', 'security_groups': [u'1e77918c-b860-4fe5-89db-9b7c31b9d526']}\n","stream":"stdout","time":"2019-07-14T12:27:38.896388073Z"} {"log":"2019-07-14 12:27:38.897 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Port be60b3b5-edaf-4e12-83f1-953ad3169241 updated. Details: {'profile': {}, 'network_qos_policy_id': None, 'qos_policy_id': None, 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': 'e8239830-46c8-4683-8cbf-149864ce1333', 'segmentation_id': 872, 'fixed_ips': [{'subnet_id': '8d156550-05d1-4683-aa70-65ea0df99d71', 'ip_address': '172.18.0.244'}], 'device_owner': u'compute:nova', 'physical_network': u'group0-data0', 'mac_address': 'fa:16:3e:b8:b1:87', 'device': 'be60b3b5-edaf-4e12-83f1-953ad3169241', 'port_security_enabled': True, 'port_id': 'be60b3b5-edaf-4e12-83f1-953ad3169241', 'network_type': u'vlan', 'security_groups': [u'1e77918c-b860-4fe5-89db-9b7c31b9d526']}\n","stream":"stdout","time":"2019-07-14T12:27:38.897887403Z"} {"log":"2019-07-14 12:27:38.897 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Port be60b3b5-edaf-4e12-83f1-953ad3169241 updated. Details: {'profile': {}, 'network_qos_policy_id': None, 'qos_policy_id': None, 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': 'e8239830-46c8-4683-8cbf-149864ce1333', 'segmentation_id': 872, 'fixed_ips': [{'subnet_id': '8d156550-05d1-4683-aa70-65ea0df99d71', 'ip_address': '172.18.0.244'}], 'device_owner': u'compute:nova', 'physical_network': u'group0-data0', 'mac_address': 'fa:16:3e:b8:b1:87', 'device': 'be60b3b5-edaf-4e12-83f1-953ad3169241', 'port_security_enabled': True, 'port_id': 'be60b3b5-edaf-4e12-83f1-953ad3169241', 'network_type': u'vlan', 'security_groups': [u'1e77918c-b860-4fe5-89db-9b7c31b9d526']}\n","stream":"stdout","time":"2019-07-14T12:27:38.89817973Z"} {"log":"2019-07-14 12:27:38.907 90 INFO neutron.agent.securitygroups_rpc [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Refresh firewall rules\n","stream":"stdout","time":"2019-07-14T12:27:38.90746363Z"} {"log":"2019-07-14 12:27:38.907 90 INFO neutron.agent.securitygroups_rpc [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Refresh firewall rules\n","stream":"stdout","time":"2019-07-14T12:27:38.907775408Z"} {"log":"2019-07-14 12:27:46.290 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] process_network_ports - iteration:6512 - agent port security group processed in 7.400\n","stream":"stdout","time":"2019-07-14T12:27:46.2913484Z"} {"log":"2019-07-14 12:27:46.290 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] process_network_ports - iteration:6512 - agent port security group processed in 7.400\n","stream":"stdout","time":"2019-07-14T12:27:46.291712404Z"} {"log":"2019-07-14 12:27:47.396 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Configuration for devices up ['4243fe83-9615-4416-a4dd-af0cb5ebe8bd', '4ed40235-c566-472d-acc1-ba074013f9f2', 'be60b3b5-edaf-4e12-83f1-953ad3169241'] and devices down [] completed.\n","stream":"stdout","time":"2019-07-14T12:27:47.39736217Z"} {"log":"2019-07-14 12:27:47.396 90 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-3a8081b8-6428-4b00-aba8-af53f5380eeb - - - - -] Configuration for devices up ['4243fe83-9615-4416-a4dd-af0cb5ebe8bd', '4ed40235-c566-472d-acc1-ba074013f9f2', 'be60b3b5-edaf-4e12-83f1-953ad3169241'] and devices down [] completed.\n","stream":"stdout","time":"2019-07-14T12:27:47.397699444Z"} {"log":"2019-07-14 12:28:37.386 90 ERROR oslo_messaging.rpc.server [-] Exception during message handling: NoSuchMethod: Endpoint does not support RPC method pod_health_probe_method_ignore_errors\n","stream":"stdout","time":"2019-07-14T12:28:37.3867528Z"} {"log":"2019-07-14 12:28:37.386 90 ERROR oslo_messaging.rpc.server Traceback (most recent call last):\n","stream":"stdout","time":"2019-07-14T12:28:37.386791793Z"} {"log":"2019-07-14 12:28:37.386 90 ERROR oslo_messaging.rpc.server File \"/var/lib/openstack/lib/python2.7/site-packages/oslo_messaging/rpc/server.py\", line 166, in _process_incoming\n","stream":"stdout","time":"2019-07-14T12:28:37.386800743Z"} {"log":"2019-07-14 12:28:37.386 90 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)\n","stream":"stdout","time":"2019-07-14T12:28:37.386808515Z"} {"log":"2019-07-14 12:28:37.386 90 ERROR oslo_messaging.rpc.server File \"/var/lib/openstack/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py\", line 274, in dispatch\n","stream":"stdout","time":"2019-07-14T12:28:37.386814425Z"} {"log":"2019-07-14 12:28:37.386 90 ERROR oslo_messaging.rpc.server raise NoSuchMethod(method)\n","stream":"stdout","time":"2019-07-14T12:28:37.386819882Z"} {"log":"2019-07-14 12:28:37.386 90 ERROR oslo_messaging.rpc.server NoSuchMethod: Endpoint does not support RPC method pod_health_probe_method_ignore_errors\n","stream":"stdout","time":"2019-07-14T12:28:37.386824972Z"} {"log":"2019-07-14 12:28:37.386 90 ERROR oslo_messaging.rpc.server \n","stream":"stdout","time":"2019-07-14T12:28:37.386830736Z"} {"log":"2019-07-14 12:30:07.382 90 ERROR oslo_messaging.rpc.server [-] Exception during message handling: NoSuchMethod: Endpoint does not support RPC method pod_health_probe_method_ignore_errors\n","stream":"stdout","time":"2019-07-14T12:30:07.384066913Z"} {"log":"2019-07-14 12:30:07.382 90 ERROR oslo_messaging.rpc.server Traceback (most recent call last):\n","stream":"stdout","time":"2019-07-14T12:30:07.384127447Z"} {"log":"2019-07-14 12:30:07.382 90 ERROR oslo_messaging.rpc.server File \"/var/lib/openstack/lib/python2.7/site-packages/oslo_messaging/rpc/server.py\", line 166, in _process_incoming\n","stream":"stdout","time":"2019-07-14T12:30:07.384136597Z"} {"log":"2019-07-14 12:30:07.382 90 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)\n","stream":"stdout","time":"2019-07-14T12:30:07.384142556Z"} {"log":"2019-07-14 12:30:07.382 90 ERROR oslo_messaging.rpc.server File \"/var/lib/openstack/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py\", line 274, in dispatch\n","stream":"stdout","time":"2019-07-14T12:30:07.38416026Z"} {"log":"2019-07-14 12:30:07.382 90 ERROR oslo_messaging.rpc.server raise NoSuchMethod(method)\n","stream":"stdout","time":"2019-07-14T12:30:07.384167659Z"} {"log":"2019-07-14 12:30:07.382 90 ERROR oslo_messaging.rpc.server NoSuchMethod: Endpoint does not support RPC method pod_health_probe_method_ignore_errors\n","stream":"stdout","time":"2019-07-14T12:30:07.384172687Z"} {"log":"2019-07-14 12:30:07.382 90 ERROR oslo_messaging.rpc.server \n","stream":"stdout","time":"2019-07-14T12:30:07.384177607Z"} {"log":"2019-07-14 12:31:37.401 90 ERROR oslo_messaging.rpc.server [-] Exception during message handling: NoSuchMethod: Endpoint does not support RPC method pod_health_probe_method_ignore_errors\n","stream":"stdout","time":"2019-07-14T12:31:37.402213554Z"} {"log":"2019-07-14 12:31:37.401 90 ERROR oslo_messaging.rpc.server Traceback (most recent call last):\n","stream":"stdout","time":"2019-07-14T12:31:37.402264726Z"} {"log":"2019-07-14 12:31:37.401 90 ERROR oslo_messaging.rpc.server File \"/var/lib/openstack/lib/python2.7/site-packages/oslo_messaging/rpc/server.py\", line 166, in _process_incoming\n","stream":"stdout","time":"2019-07-14T12:31:37.402274632Z"} {"log":"2019-07-14 12:31:37.401 90 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)\n","stream":"stdout","time":"2019-07-14T12:31:37.402286505Z"} {"log":"2019-07-14 12:31:37.401 90 ERROR oslo_messaging.rpc.server File \"/var/lib/openstack/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py\", line 274, in dispatch\n","stream":"stdout","time":"2019-07-14T12:31:37.402292392Z"} {"log":"2019-07-14 12:31:37.401 90 ERROR oslo_messaging.rpc.server raise NoSuchMethod(method)\n","stream":"stdout","time":"2019-07-14T12:31:37.402297149Z"} {"log":"2019-07-14 12:31:37.401 90 ERROR oslo_messaging.rpc.server NoSuchMethod: Endpoint does not support RPC method pod_health_probe_method_ignore_errors\n","stream":"stdout","time":"2019-07-14T12:31:37.402301621Z"} {"log":"2019-07-14 12:31:37.401 90 ERROR oslo_messaging.rpc.server \n","stream":"stdout","time":"2019-07-14T12:31:37.402305829Z"} console.log ... [[32m OK [0m] Started Titanium Cloud Filesystem Server. [ 68.004632] systemd[1]: Started Titanium Cloud Filesystem Server. [ 68.063331] cloud-init[1171]: Cloud-init v. 0.7.9 running 'init' at Sun, 14 Jul 2019 12:28:50 +0000. Up 68.02 seconds. [ 68.089767] cloud-init[1171]: ci-info: +++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++ [ 68.095756] cloud-init[1171]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+ [ 68.101521] cloud-init[1171]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | [ 68.106997] cloud-init[1171]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+ [ 68.112746] cloud-init[1171]: ci-info: | lo: | True | 127.0.0.1 | 255.0.0.0 | . | . | [ 68.117191] cloud-init[1171]: ci-info: | lo: | True | . | . | d | . | [ 68.124350] cloud-init[1171]: ci-info: | eth1: | False | . | . | . | fa:16:3e:b8:b1:87 | [ 68.129921] cloud-init[1171]: ci-info: | eth2: | False | . | . | . | fa:16:3e:0e:2a:96 | [ 68.135506] cloud-init[1171]: ci-info: | eth0: | True | . | . | . | fa:16:3e:bd:c1:a2 | [ 68.140852] cloud-init[1171]: ci-info: | eth0: | True | . | . | d | fa:16:3e:bd:c1:a2 | [ 68.146442] cloud-init[1171]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+ [ 68.184866] cloud-init[1171]: 2019-07-14 08:28:50,527 - url_helper.py[WARNING]: Calling 'http://169.254.169.254/2009-04-04/meta-data/instance-id' failed [0/30s]: request error [HTTPConnectionPool(host='169.254.169.254', port=80): Max retries exceeded with url: /2009-04-04/meta-data/instance-id (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 101] Network is unreachable',))] [ 68.255034] postfix/postfix-script[1333]: starting the Postfix mail system [ 68.271773] postfix/master[1335]: daemon started -- version 2.10.1, configuration /etc/postfix [[32m OK [0m] Started Postfix Mail Transport Agent. [ 68.278948] systemd[1]: Started Postfix Mail Transport Agent. [ 69.187872] cloud-init[1171]: 2019-07-14 08:28:51,530 - url_helper.py[WARNING]: Calling 'http://169.254.169.254/2009-04-04/meta-data/instance-id' failed [1/30s]: request error [HTTPConnectionPool(host='169.254.169.254', port=80): Max retries exceeded with url: /2009-04-04/meta-data/instance-id (Caused by NewConnectionError(': Failed to establish a new connection: [Errno 101] Network is unreachable',))]