2016-08-11 12:00:24.076 8206 INFO nova.compute.manager [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Running instance usage audit for host compute1 from 2016-08-11 14:00:00 to 2016-08-11 15:00:00. 0 instances.
2016-08-11 12:00:24.102 8206 DEBUG oslo_service.periodic_task [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2016-08-11 12:00:25.010 8206 DEBUG oslo_service.periodic_task [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Running periodic task ComputeManager._run_image_cache_manager_pass run_periodic_tasks /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2016-08-11 12:00:25.012 8206 DEBUG oslo_concurrency.lockutils [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Lock "storage-registry-lock" acquired by "nova.virt.storage_users.do_register_storage_use" :: waited 0.000s inner /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2016-08-11 12:00:25.013 8206 DEBUG oslo_concurrency.lockutils [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Lock "storage-registry-lock" released by "nova.virt.storage_users.do_register_storage_use" :: held 0.002s inner /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2016-08-11 12:00:25.015 8206 DEBUG oslo_concurrency.lockutils [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Lock "storage-registry-lock" acquired by "nova.virt.storage_users.do_get_storage_users" :: waited 0.000s inner /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2016-08-11 12:00:25.016 8206 DEBUG oslo_concurrency.lockutils [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Lock "storage-registry-lock" released by "nova.virt.storage_users.do_get_storage_users" :: held 0.001s inner /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2016-08-11 12:00:25.034 8206 DEBUG nova.virt.libvirt.imagecache [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Skipping verification, no base directory at /var/lib/nova/instances/_base _get_base /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/imagecache.py:655
2016-08-11 12:00:32.035 8206 DEBUG oslo_service.periodic_task [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2016-08-11 12:00:43.008 8206 DEBUG oslo_service.periodic_task [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Running periodic task ComputeManager._sync_scheduler_instance_info run_periodic_tasks /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2016-08-11 12:01:00.232 8206 DEBUG nova.objects.instance [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Lazy-loading 'vcpu_model' on Instance uuid fe889ac9-0078-4441-a22d-94cdaa8a160d obj_load_attr /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/objects/instance.py:895
2016-08-11 12:01:00.248 8206 INFO nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Instance launched has CPU info: {"vendor": "Intel", "model": "SandyBridge", "arch": "x86_64", "features": ["pge", "avx", "clflush", "sep", "syscall", "vme", "dtes64", "msr", "xsave", "vmx", "xtpr", "cmov", "ssse3", "est", "pat", "monitor", "smx", "pbe", "lm", "tsc", "nx", "fxsr", "tm", "sse4.1", "pae", "sse4.2", "pclmuldq", "acpi", "tsc-deadline", "mmx", "osxsave", "cx8", "mce", "de", "tm2", "ht", "dca", "lahf_lm", "pdcm", "mca", "pdpe1gb", "apic", "sse", "pse", "ds", "pni", "rdtscp", "aes", "sse2", "ss", "ds_cpl", "pcid", "fpu", "cx16", "pse36", "mtrr", "popcnt", "x2apic"], "topology": {"cores": 6, "cells": 2, "threads": 2, "sockets": 1}}
2016-08-11 12:01:00.250 8206 DEBUG nova.virt.libvirt.config [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Generated XML ('<cpu>\n <arch>x86_64</arch>\n <model>SandyBridge</model>\n <vendor>Intel</vendor>\n <topology sockets="1" cores="6" threads="2"/>\n <feature name="acpi"/>\n <feature name="aes"/>\n <feature name="apic"/>\n <feature name="avx"/>\n <feature name="clflush"/>\n <feature name="cmov"/>\n <feature name="cx16"/>\n <feature name="cx8"/>\n <feature name="dca"/>\n <feature name="de"/>\n <feature name="ds"/>\n <feature name="ds_cpl"/>\n <feature name="dtes64"/>\n <feature name="est"/>\n <feature name="fpu"/>\n <feature name="fxsr"/>\n <feature name="ht"/>\n <feature name="lahf_lm"/>\n <feature name="lm"/>\n <feature name="mca"/>\n <feature name="mce"/>\n <feature name="mmx"/>\n <feature name="monitor"/>\n <feature name="msr"/>\n <feature name="mtrr"/>\n <feature name="nx"/>\n <feature name="osxsave"/>\n <feature name="pae"/>\n <feature name="pat"/>\n <feature name="pbe"/>\n <feature name="pcid"/>\n <feature name="pclmuldq"/>\n <feature name="pdcm"/>\n <feature name="pdpe1gb"/>\n <feature name="pge"/>\n <feature name="pni"/>\n <feature name="popcnt"/>\n <feature name="pse"/>\n <feature name="pse36"/>\n <feature name="rdtscp"/>\n <feature name="sep"/>\n <feature name="smx"/>\n <feature name="ss"/>\n <feature name="sse"/>\n <feature name="sse2"/>\n <feature name="sse4.1"/>\n <feature name="sse4.2"/>\n <feature name="ssse3"/>\n <feature name="syscall"/>\n <feature name="tm"/>\n <feature name="tm2"/>\n <feature name="tsc"/>\n <feature name="tsc-deadline"/>\n <feature name="vme"/>\n <feature name="vmx"/>\n <feature name="x2apic"/>\n <feature name="xsave"/>\n <feature name="xtpr"/>\n</cpu>\n',) to_xml /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/config.py:82
2016-08-11 12:01:00.256 8206 DEBUG nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Creating tmpfile /var/lib/nova/instances/tmpgRsVab to notify to other compute nodes that they should mount the same storage. _create_shared_storage_test_file /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:5733
2016-08-11 12:01:00.257 8206 DEBUG nova.compute.manager [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] destination check data is LibvirtLiveMigrateData(bdms=<?>,block_migration=False,disk_available_mb=51478528,disk_over_commit=False,filename='tmpgRsVab',graphics_listen_addr_spice=<?>,graphics_listen_addr_vnc=<?>,image_type='rbd',instance_relative_path=<?>,is_shared_block_storage=<?>,is_shared_instance_path=<?>,is_volume_backed=<?>,migration=<?>,serial_listen_addr=<?>,target_connect_addr=<?>) _do_check_can_live_migrate_destination /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:5148
2016-08-11 12:01:01.496 8206 DEBUG nova.compute.manager [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] pre_live_migration data is LibvirtLiveMigrateData(bdms=<?>,block_migration=False,disk_available_mb=51478528,disk_over_commit=False,filename='tmpgRsVab',graphics_listen_addr_spice=<?>,graphics_listen_addr_vnc=<?>,image_type='rbd',instance_relative_path='fe889ac9-0078-4441-a22d-94cdaa8a160d',is_shared_block_storage=True,is_shared_instance_path=False,is_volume_backed=True,migration=<?>,serial_listen_addr=<?>,target_connect_addr=<?>) pre_live_migration /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:5206
2016-08-11 12:01:01.520 8206 DEBUG oslo_concurrency.processutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Running cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf cat /etc/iscsi/initiatorname.iscsi execute /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/processutils.py:344
2016-08-11 12:01:01.636 8206 DEBUG oslo_concurrency.processutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] CMD "sudo nova-rootwrap /etc/nova/rootwrap.conf cat /etc/iscsi/initiatorname.iscsi" returned: 0 in 0.116s execute /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/processutils.py:374
2016-08-11 12:01:01.638 8206 DEBUG oslo_concurrency.processutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Running cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf systool -c fc_host -v execute /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/processutils.py:344
2016-08-11 12:01:01.751 8206 DEBUG oslo_concurrency.processutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] CMD "sudo nova-rootwrap /etc/nova/rootwrap.conf systool -c fc_host -v" returned: 1 in 0.113s execute /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/processutils.py:374
2016-08-11 12:01:01.753 8206 DEBUG oslo_concurrency.processutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] u'sudo nova-rootwrap /etc/nova/rootwrap.conf systool -c fc_host -v' failed. Not Retrying. execute /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/processutils.py:422
2016-08-11 12:01:01.754 8206 DEBUG oslo_concurrency.processutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Running cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf systool -c fc_host -v execute /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/processutils.py:344
2016-08-11 12:01:01.874 8206 DEBUG oslo_concurrency.processutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] CMD "sudo nova-rootwrap /etc/nova/rootwrap.conf systool -c fc_host -v" returned: 1 in 0.120s execute /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/processutils.py:374
2016-08-11 12:01:01.876 8206 DEBUG oslo_concurrency.processutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] u'sudo nova-rootwrap /etc/nova/rootwrap.conf systool -c fc_host -v' failed. Not Retrying. execute /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/processutils.py:422
2016-08-11 12:01:01.878 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X POST http://172.16.116.101:8776/v2/dfa0dd8586294d45b6ce518470e1f53a/volumes/43eff600-4ccd-40dc-a2d5-323902dbdf6f/action -H "User-Agent: python-cinderclient" -H "Content-Type: application/json" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}ad73fb17a62424c6f2aac91e2c352b4904f5176b" -d '{"os-initialize_connection": {"connector": {"initiator": "iqn.1993-08.org.debian:01:c02268eeaeee", "ip": "172.16.116.16", "platform": "x86_64", "host": "compute1", "os_type": "linux2", "multipath": false}}}' _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:02.605 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:02 GMT X-Compute-Request-Id: req-064a9c47-e4e8-4343-a158-9ba22d9d4e07 Content-Type: application/json Content-Length: 411 X-Openstack-Request-Id: req-064a9c47-e4e8-4343-a158-9ba22d9d4e07
RESP BODY: {"connection_info": {"driver_volume_type": "rbd", "data": {"secret_type": "ceph", "name": "volumes/volume-43eff600-4ccd-40dc-a2d5-323902dbdf6f", "encrypted": false, "secret_uuid": null, "qos_specs": null, "hosts": ["10.1.4.1", "10.1.4.2", "10.1.4.3"], "volume_id": "43eff600-4ccd-40dc-a2d5-323902dbdf6f", "auth_enabled": true, "access_mode": "rw", "auth_username": "cinder", "ports": ["6789", "6789", "6789"]}}}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:02.631 8206 DEBUG oslo_concurrency.lockutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Acquired semaphore "refresh_cache-fe889ac9-0078-4441-a22d-94cdaa8a160d" lock /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
2016-08-11 12:01:02.632 8206 DEBUG nova.network.neutronv2.api [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] _get_instance_nw_info() _get_instance_nw_info /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/network/neutronv2/api.py:910
2016-08-11 12:01:02.651 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/ports.json?tenant_id=dfa0dd8586294d45b6ce518470e1f53a&device_id=fe889ac9-0078-4441-a22d-94cdaa8a160d -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}de82ff82764446e5245295078c4da1edbf4c54de" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:02.803 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:02 GMT Content-Length: 878 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-82de78d4-4027-41b2-ad03-2211ee0577eb
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "compute2", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T15:00:05", "device_owner": "compute:nova", "port_security_enabled": true, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.5"}], "id": "9062d380-6c57-48ff-98f1-9ddf52051882", "security_groups": ["58118527-c2d6-4925-9711-87f8399a9b0a"], "device_id": "fe889ac9-0078-4441-a22d-94cdaa8a160d", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:1a:4b:76", "created_at": "2016-08-11T12:33:35"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:02.805 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/networks.json?id=18df8b2f-2eb3-403b-b59c-15be601f5429 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}ad73fb17a62424c6f2aac91e2c352b4904f5176b" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:02.863 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:02 GMT Content-Length: 660 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-4e0bf043-0857-4d9c-8399-61237abece8f
RESP BODY: {"networks": [{"provider:physical_network": null, "ipv6_address_scope": null, "port_security_enabled": true, "mtu": 1450, "id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "router:external": false, "availability_zone_hints": [], "availability_zones": ["nova"], "ipv4_address_scope": null, "shared": false, "provider:segmentation_id": 4171, "status": "ACTIVE", "subnets": ["bb071108-ea70-4654-b423-771cb68e0540"], "description": "", "tags": [], "updated_at": "2016-08-11T12:30:25", "qos_policy_id": null, "name": "lan", "admin_state_up": true, "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "created_at": "2016-08-11T12:30:25", "provider:network_type": "vxlan"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:02.865 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/floatingips.json?fixed_ip_address=192.168.50.5&port_id=9062d380-6c57-48ff-98f1-9ddf52051882 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}de82ff82764446e5245295078c4da1edbf4c54de" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:02.884 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:02 GMT Content-Length: 19 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-10da95c3-c751-4b30-bd91-ea46444973ca
RESP BODY: {"floatingips": []}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:02.885 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/subnets.json?id=bb071108-ea70-4654-b423-771cb68e0540 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}ad73fb17a62424c6f2aac91e2c352b4904f5176b" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:02.937 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:02 GMT Content-Length: 574 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-d496b4b1-d7a5-41b0-a46b-d48c1b8900b5
RESP BODY: {"subnets": [{"description": "", "enable_dhcp": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "created_at": "2016-08-11T12:30:26", "dns_nameservers": ["8.8.8.8", "8.8.4.4"], "updated_at": "2016-08-11T12:30:26", "gateway_ip": "192.168.50.1", "ipv6_ra_mode": null, "allocation_pools": [{"start": "192.168.50.2", "end": "192.168.50.62"}], "host_routes": [], "ip_version": 4, "ipv6_address_mode": null, "cidr": "192.168.50.0/26", "id": "bb071108-ea70-4654-b423-771cb68e0540", "subnetpool_id": null, "name": "lan"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:02.939 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/ports.json?network_id=18df8b2f-2eb3-403b-b59c-15be601f5429&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}ad73fb17a62424c6f2aac91e2c352b4904f5176b" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:02.975 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:02 GMT Content-Length: 2720 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-2142067b-aae5-4fd7-956c-4cb4e6d5a555
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "infra1-neutron-agents-container-0eb59f4a", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T12:30:33", "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.4"}], "id": "41a98926-b5ff-4d04-b174-490518c2ff4b", "security_groups": [], "device_id": "dhcp0ad9d4cf-c9bc-5381-8c2c-60d51f7c4be8-18df8b2f-2eb3-403b-b59c-15be601f5429", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:55:1a:f1", "created_at": "2016-08-11T12:30:26"}, {"status": "ACTIVE", "binding:host_id": "infra3-neutron-agents-container-88ab550e", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T12:30:30", "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.3"}], "id": "61ce1aae-d06c-45aa-9695-57d856a43fc0", "security_groups": [], "device_id": "dhcp95ac1b17-f4a7-50a2-8702-dd2c38476ac6-18df8b2f-2eb3-403b-b59c-15be601f5429", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:97:08:22", "created_at": "2016-08-11T12:30:26"}, {"status": "ACTIVE", "binding:host_id": "infra2-neutron-agents-container-8f8746a4", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T12:30:30", "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.2"}], "id": "fa5f49bb-a540-4bce-90d0-af3dfbe8ca68", "security_groups": [], "device_id": "dhcpb8d52507-3975-5056-97ca-d5d74d51987e-18df8b2f-2eb3-403b-b59c-15be601f5429", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:01:31:20", "created_at": "2016-08-11T12:30:26"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:02.978 8206 DEBUG nova.network.base_api [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Updating instance_info_cache with network_info: [VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': u'brq18df8b2f-2e', 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'192.168.50.5'})], 'version': 4, 'meta': {'dhcp_server': u'192.168.50.2'}, 'dns': [IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.8.8'}), IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.4.4'})], 'routes': [], 'cidr': u'192.168.50.0/26', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'192.168.50.1'})})], 'meta': {'injected': False, 'tenant_id': u'dfa0dd8586294d45b6ce518470e1f53a', 'should_create_bridge': True, 'mtu': 1450}, 'id': u'18df8b2f-2eb3-403b-b59c-15be601f5429', 'label': u'lan'}), 'devname': u'tap9062d380-6c', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True}, 'address': u'fa:16:3e:1a:4b:76', 'active': True, 'type': u'bridge', 'id': u'9062d380-6c57-48ff-98f1-9ddf52051882', 'qbg_params': None})] update_instance_cache_with_nw_info /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/network/base_api.py:43
2016-08-11 12:01:02.997 8206 DEBUG oslo_concurrency.lockutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Releasing semaphore "refresh_cache-fe889ac9-0078-4441-a22d-94cdaa8a160d" lock /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
2016-08-11 12:01:02.998 8206 DEBUG nova.objects.instance [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Lazy-loading 'flavor' on Instance uuid fe889ac9-0078-4441-a22d-94cdaa8a160d obj_load_attr /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/objects/instance.py:895
2016-08-11 12:01:03.068 8206 DEBUG nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] migrate_data in pre_live_migration: LibvirtLiveMigrateData(bdms=<?>,block_migration=False,disk_available_mb=51478528,disk_over_commit=False,filename='tmpgRsVab',graphics_listen_addr_spice=<?>,graphics_listen_addr_vnc=<?>,image_type='rbd',instance_relative_path='fe889ac9-0078-4441-a22d-94cdaa8a160d',is_shared_block_storage=True,is_shared_instance_path=False,is_volume_backed=True,migration=<?>,serial_listen_addr=<?>,target_connect_addr=<?>) pre_live_migration /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:6613
2016-08-11 12:01:03.070 8206 DEBUG nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Creating instance directory: /var/lib/nova/instances/fe889ac9-0078-4441-a22d-94cdaa8a160d pre_live_migration /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:6642
2016-08-11 12:01:03.071 8206 DEBUG nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Touch instance console log: /var/lib/nova/instances/fe889ac9-0078-4441-a22d-94cdaa8a160d/console.log pre_live_migration /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:6680
2016-08-11 12:01:03.072 8206 DEBUG nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Connecting volumes before live migration. pre_live_migration /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:6693
2016-08-11 12:01:03.073 8206 DEBUG nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Plugging VIFs before live migration. pre_live_migration /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:6706
2016-08-11 12:01:03.074 8206 DEBUG nova.virt.libvirt.vif [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] vif_type=bridge instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=True,availability_zone='nova',cell_name=None,cleaned=True,config_drive='',created_at=2016-08-11T12:33:34Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,disable_terminate=False,display_description='ubuntu14',display_name='ubuntu14',ec2_ids=<?>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,flavor=Flavor(4),host='compute2',hostname='ubuntu14',id=4,image_ref='',info_cache=InstanceInfoCache,instance_type_id=4,kernel_id='',key_data='ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCnF95HG7f35+TvfZGgt48aZYMrfIGewGjiixM1trjRokxU7rxFQmRu0kXNEGJWhTlupAwViZyFtaPx+JBAjRg4saTdFLjkped0l1lApqgqBxFQaQyIkZUSRfam3EYu4GFvd253kAdBaPHAoqQ+dAuFSm+QurrrDw/R464PlHwHvhB4z2PoloxfLuebkp4VxBLLcH0XFIREILeI+XOPsBsl2S5vhRsHZgnqMzYi18PhTHTE8DIlD7JivvvDEJd+8byWeH/6kYquyTQwk81qtpddS5a9HM67TlIYqaxCQYYFNXl3Y1ClDpgcLXH7kUVwQ33SzM/aCsgoD/VLpWpVDXRD',key_name='desenvolvimento',launch_index=0,launched_at=2016-08-11T12:34:19Z,launched_on='compute1',locked=False,locked_by=None,memory_mb=4096,metadata={},migration_context=<?>,new_flavor=None,node='compute2',numa_topology=<?>,old_flavor=None,os_type=None,pci_devices=<?>,pci_requests=<?>,power_state=1,progress=0,project_id='dfa0dd8586294d45b6ce518470e1f53a',ramdisk_id='',reservation_id='r-g79k6nvf',root_device_name='/dev/vda',root_gb=40,security_groups=SecurityGroupList,services=<?>,shutdown_terminate=False,system_metadata={clean_attempts='9',image_base_image_ref='',image_container_format='bare',image_disk_format='qcow2',image_min_disk='40',image_min_ram='0'},tags=<?>,task_state='migrating',terminated_at=None,updated_at=2016-08-11T15:00:02Z,user_data=None,user_id='90cb07ccd2224bc68d1462d3fc339f28',uuid=fe889ac9-0078-4441-a22d-94cdaa8a160d,vcpu_model=<?>,vcpus=2,vm_mode=None,vm_state='active') vif=VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': u'brq18df8b2f-2e', 'subnets': [Subnet({'ips': [FixedIP({'version': 4, 'vif_mac': u'fa:16:3e:1a:4b:76', 'floating_ips': [], 'label': u'lan', 'meta': {}, 'address': u'192.168.50.5', 'type': 'fixed'})], 'version': 4, 'meta': {'dhcp_server': u'192.168.50.2'}, 'dns': [IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.8.8'}), IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.4.4'})], 'routes': [], 'cidr': u'192.168.50.0/26', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'192.168.50.1'})})], 'meta': {'injected': False, 'tenant_id': u'dfa0dd8586294d45b6ce518470e1f53a', 'should_create_bridge': True, 'mtu': 1450}, 'id': u'18df8b2f-2eb3-403b-b59c-15be601f5429', 'label': u'lan'}), 'devname': u'tap9062d380-6c', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True}, 'address': u'fa:16:3e:1a:4b:76', 'active': True, 'type': u'bridge', 'id': u'9062d380-6c57-48ff-98f1-9ddf52051882', 'qbg_params': None}) plug /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/vif.py:744
2016-08-11 12:01:03.077 8206 DEBUG nova.virt.libvirt.vif [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Ensuring bridge brq18df8b2f-2e plug_bridge /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/vif.py:471
2016-08-11 12:01:03.078 8206 DEBUG oslo_concurrency.lockutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Lock "lock_bridge" acquired by "nova.network.linux_net.ensure_bridge" :: waited 0.000s inner /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2016-08-11 12:01:03.079 8206 DEBUG nova.network.linux_net [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Skipping duplicate iptables rule addition. [0:0] -A nova-compute-FORWARD -i brq18df8b2f-2e -j ACCEPT already in [[0:0] -A FORWARD -j nova-filter-top, [0:0] -A OUTPUT -j nova-filter-top, [0:0] -A nova-filter-top -j nova-compute-local, [0:0] -A INPUT -j nova-compute-INPUT, [0:0] -A OUTPUT -j nova-compute-OUTPUT, [0:0] -A FORWARD -j nova-compute-FORWARD, [0:0] -A nova-compute-FORWARD -i brq18df8b2f-2e -j ACCEPT, [0:0] -A nova-compute-FORWARD -o brq18df8b2f-2e -j ACCEPT] add_rule /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/network/linux_net.py:289
2016-08-11 12:01:03.080 8206 DEBUG nova.network.linux_net [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Skipping duplicate iptables rule addition. [0:0] -A nova-compute-FORWARD -o brq18df8b2f-2e -j ACCEPT already in [[0:0] -A FORWARD -j nova-filter-top, [0:0] -A OUTPUT -j nova-filter-top, [0:0] -A nova-filter-top -j nova-compute-local, [0:0] -A INPUT -j nova-compute-INPUT, [0:0] -A OUTPUT -j nova-compute-OUTPUT, [0:0] -A FORWARD -j nova-compute-FORWARD, [0:0] -A nova-compute-FORWARD -i brq18df8b2f-2e -j ACCEPT, [0:0] -A nova-compute-FORWARD -o brq18df8b2f-2e -j ACCEPT] add_rule /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/network/linux_net.py:289
2016-08-11 12:01:03.081 8206 DEBUG oslo_concurrency.lockutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Lock "lock_bridge" released by "nova.network.linux_net.ensure_bridge" :: held 0.003s inner /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2016-08-11 12:01:03.083 8206 DEBUG nova.compute.manager [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] driver pre_live_migration data is LibvirtLiveMigrateData(bdms=[LibvirtLiveMigrateBDMInfo],block_migration=False,disk_available_mb=51478528,disk_over_commit=False,filename='tmpgRsVab',graphics_listen_addr_spice=172.16.116.16,graphics_listen_addr_vnc=127.0.0.1,image_type='rbd',instance_relative_path='fe889ac9-0078-4441-a22d-94cdaa8a160d',is_shared_block_storage=True,is_shared_instance_path=False,is_volume_backed=True,migration=<?>,serial_listen_addr='127.0.0.1',target_connect_addr=None) pre_live_migration /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:5227
2016-08-11 12:01:03.088 8206 DEBUG nova.compute.manager [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] pre_live_migration result data is LibvirtLiveMigrateData(bdms=[LibvirtLiveMigrateBDMInfo],block_migration=False,disk_available_mb=51478528,disk_over_commit=False,filename='tmpgRsVab',graphics_listen_addr_spice=172.16.116.16,graphics_listen_addr_vnc=127.0.0.1,image_type='rbd',instance_relative_path='fe889ac9-0078-4441-a22d-94cdaa8a160d',is_shared_block_storage=True,is_shared_instance_path=False,is_volume_backed=True,migration=<?>,serial_listen_addr='127.0.0.1',target_connect_addr=None) pre_live_migration /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:5250
2016-08-11 12:01:04.551 8206 DEBUG nova.virt.driver [req-a429e05b-927c-48e3-b11d-277d0ccf767e - - - - -] Emitting event <LifecycleEvent: 1470927664.55, fe889ac9-0078-4441-a22d-94cdaa8a160d => Started> emit_event /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/driver.py:1443
2016-08-11 12:01:04.552 8206 INFO nova.compute.manager [req-a429e05b-927c-48e3-b11d-277d0ccf767e - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] VM Started (Lifecycle Event)
2016-08-11 12:01:04.607 8206 DEBUG nova.compute.manager [req-a429e05b-927c-48e3-b11d-277d0ccf767e - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Checking state _get_power_state /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:1347
2016-08-11 12:01:06.916 8206 DEBUG nova.virt.driver [req-a429e05b-927c-48e3-b11d-277d0ccf767e - - - - -] Emitting event <LifecycleEvent: 1470927666.92, fe889ac9-0078-4441-a22d-94cdaa8a160d => Resumed> emit_event /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/driver.py:1443
2016-08-11 12:01:06.918 8206 INFO nova.compute.manager [req-a429e05b-927c-48e3-b11d-277d0ccf767e - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] VM Resumed (Lifecycle Event)
2016-08-11 12:01:06.974 8206 DEBUG nova.compute.manager [req-a429e05b-927c-48e3-b11d-277d0ccf767e - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Checking state _get_power_state /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:1347
2016-08-11 12:01:07.444 8206 DEBUG nova.virt.driver [req-a429e05b-927c-48e3-b11d-277d0ccf767e - - - - -] Emitting event <LifecycleEvent: 1470927666.92, fe889ac9-0078-4441-a22d-94cdaa8a160d => Resumed> emit_event /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/driver.py:1443
2016-08-11 12:01:07.445 8206 INFO nova.compute.manager [req-a429e05b-927c-48e3-b11d-277d0ccf767e - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] VM Resumed (Lifecycle Event)
2016-08-11 12:01:07.634 8206 DEBUG nova.compute.manager [req-a429e05b-927c-48e3-b11d-277d0ccf767e - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Checking state _get_power_state /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:1347
2016-08-11 12:01:09.034 8206 INFO nova.compute.manager [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Post operation of migration started
2016-08-11 12:01:09.035 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/extensions.json -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}ad73fb17a62424c6f2aac91e2c352b4904f5176b" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:09.043 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:09 GMT Content-Length: 7681 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-664a0ff9-1c67-4051-99c3-d945caca6282
RESP BODY: {"extensions": [{"alias": "default-subnetpools", "updated": "2016-02-18T18:00:00-00:00", "name": "Default Subnetpools", "links": [], "description": "Provides ability to mark and use a subnetpool as the default"}, {"alias": "qos", "updated": "2015-06-08T10:00:00-00:00", "name": "Quality of Service", "links": [], "description": "The Quality of Service extension."}, {"alias": "network-ip-availability", "updated": "2015-09-24T00:00:00-00:00", "name": "Network IP Availability", "links": [], "description": "Provides IP availability data for each network and subnet."}, {"alias": "network_availability_zone", "updated": "2015-01-01T10:00:00-00:00", "name": "Network Availability Zone", "links": [], "description": "Availability zone support for network."}, {"alias": "auto-allocated-topology", "updated": "2016-01-01T00:00:00-00:00", "name": "Auto Allocated Topology Services", "links": [], "description": "Auto Allocated Topology Services."}, {"alias": "ext-gw-mode", "updated": "2013-03-28T10:00:00-00:00", "name": "Neutron L3 Configurable external gateway mode", "links": [], "description": "Extension of the router abstraction for specifying whether SNAT should occur on the external gateway"}, {"alias": "binding", "updated": "2014-02-03T10:00:00-00:00", "name": "Port Binding", "links": [], "description": "Expose port bindings of a virtual port to external application"}, {"alias": "metering", "updated": "2013-06-12T10:00:00-00:00", "name": "Neutron Metering", "links": [], "description": "Neutron Metering extension."}, {"alias": "agent", "updated": "2013-02-03T10:00:00-00:00", "name": "agent", "links": [], "description": "The agent management extension."}, {"alias": "subnet_allocation", "updated": "2015-03-30T10:00:00-00:00", "name": "Subnet Allocation", "links": [], "description": "Enables allocation of subnets from a subnet pool"}, {"alias": "l3_agent_scheduler", "updated": "2013-02-07T10:00:00-00:00", "name": "L3 Agent Scheduler", "links": [], "description": "Schedule routers among l3 agents"}, {"alias": "tag", "updated": "2016-01-01T00:00:00-00:00", "name": "Tag support", "links": [], "description": "Enables to set tag on resources."}, {"alias": "external-net", "updated": "2013-01-14T10:00:00-00:00", "name": "Neutron external network", "links": [], "description": "Adds external network attribute to network resource."}, {"alias": "fwaasrouterinsertion", "updated": "2015-01-27T10:00:00-00:00", "name": "Firewall Router insertion", "links": [], "description": "Firewall Router insertion on specified set of routers"}, {"alias": "net-mtu", "updated": "2015-03-25T10:00:00-00:00", "name": "Network MTU", "links": [], "description": "Provides MTU attribute for a network resource."}, {"alias": "availability_zone", "updated": "2015-01-01T10:00:00-00:00", "name": "Availability Zone", "links": [], "description": "The availability zone extension."}, {"alias": "quotas", "updated": "2012-07-29T10:00:00-00:00", "name": "Quota management support", "links": [], "description": "Expose functions for quotas management per tenant"}, {"alias": "l3-ha", "updated": "2014-04-26T00:00:00-00:00", "name": "HA Router extension", "links": [], "description": "Add HA capability to routers."}, {"alias": "provider", "updated": "2012-09-07T10:00:00-00:00", "name": "Provider Network", "links": [], "description": "Expose mapping of virtual networks to physical networks"}, {"alias": "multi-provider", "updated": "2013-06-27T10:00:00-00:00", "name": "Multi Provider Network", "links": [], "description": "Expose mapping of virtual networks to multiple physical networks"}, {"alias": "vpnaas", "updated": "2013-05-29T10:00:00-00:00", "name": "VPN service", "links": [], "description": "Extension for VPN service"}, {"alias": "address-scope", "updated": "2015-07-26T10:00:00-00:00", "name": "Address scope", "links": [], "description": "Address scopes extension."}, {"alias": "extraroute", "updated": "2013-02-01T10:00:00-00:00", "name": "Neutron Extra Route", "links": [], "description": "Extra routes configuration for L3 router"}, {"alias": "lbaasv2", "updated": "2014-06-18T10:00:00-00:00", "name": "LoadBalancing service v2", "links": [], "description": "Extension for LoadBalancing service v2"}, {"alias": "shared_pools", "updated": "2016-01-20T10:00:00-00:00", "name": "Shared pools for LBaaSv2", "links": [], "description": "Allow pools to be shared among listeners for LBaaSv2"}, {"alias": "timestamp_core", "updated": "2016-03-01T10:00:00-00:00", "name": "Time Stamp Fields addition for core resources", "links": [], "description": "This extension can be used for recording create/update timestamps for core resources like port/subnet/network/subnetpools."}, {"alias": "fwaas", "updated": "2013-02-25T10:00:00-00:00", "name": "Firewall service", "links": [], "description": "Extension for Firewall service"}, {"alias": "port-security", "updated": "2012-07-23T10:00:00-00:00", "name": "Port Security", "links": [], "description": "Provides port security"}, {"alias": "lbaas_agent_schedulerv2", "updated": "2013-02-07T10:00:00-00:00", "name": "Loadbalancer Agent Scheduler V2", "links": [], "description": "Schedule load balancers among lbaas agents"}, {"alias": "extra_dhcp_opt", "updated": "2013-03-17T12:00:00-00:00", "name": "Neutron Extra DHCP opts", "links": [], "description": "Extra options configuration for DHCP. For example PXE boot options to DHCP clients can be specified (e.g. tftp-server, server-ip-address, bootfile-name)"}, {"alias": "dns-integration", "updated": "2015-08-15T18:00:00-00:00", "name": "DNS Integration", "links": [], "description": "Provides integration with DNS."}, {"alias": "service-type", "updated": "2013-01-20T00:00:00-00:00", "name": "Neutron Service Type Management", "links": [], "description": "API for retrieving service providers for Neutron advanced services"}, {"alias": "vpn-endpoint-groups", "updated": "2015-08-04T10:00:00-00:00", "name": "VPN Endpoint Groups", "links": [], "description": "VPN endpoint groups support"}, {"alias": "security-group", "updated": "2012-10-05T10:00:00-00:00", "name": "security-group", "links": [], "description": "The security groups extension."}, {"alias": "dhcp_agent_scheduler", "updated": "2013-02-07T10:00:00-00:00", "name": "DHCP Agent Scheduler", "links": [], "description": "Schedule networks among dhcp agents"}, {"alias": "router_availability_zone", "updated": "2015-01-01T10:00:00-00:00", "name": "Router Availability Zone", "links": [], "description": "Availability zone support for router."}, {"alias": "rbac-policies", "updated": "2015-06-17T12:15:12-00:00", "name": "RBAC Policies", "links": [], "description": "Allows creation and modification of policies that control tenant access to resources."}, {"alias": "l7", "updated": "2016-01-24T10:00:00-00:00", "name": "L7 capabilities for LBaaSv2", "links": [], "description": "Adding L7 policies and rules support for LBaaSv2"}, {"alias": "standard-attr-description", "updated": "2016-02-10T10:00:00-00:00", "name": "standard-attr-description", "links": [], "description": "Extension to add descriptions to standard attributes"}, {"alias": "router", "updated": "2012-07-20T10:00:00-00:00", "name": "Neutron L3 Router", "links": [], "description": "Router abstraction for basic L3 forwarding between L2 Neutron networks and access to external networks via a NAT gateway."}, {"alias": "allowed-address-pairs", "updated": "2013-07-23T10:00:00-00:00", "name": "Allowed Address Pairs", "links": [], "description": "Provides allowed address pairs"}, {"alias": "dvr", "updated": "2014-06-1T10:00:00-00:00", "name": "Distributed Virtual Router", "links": [], "description": "Enables configuration of Distributed Virtual Routers."}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:09.044 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/ports.json?tenant_id=dfa0dd8586294d45b6ce518470e1f53a&device_id=fe889ac9-0078-4441-a22d-94cdaa8a160d -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}de82ff82764446e5245295078c4da1edbf4c54de" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:09.075 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:08 GMT Content-Length: 876 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-528f4964-52d9-4f63-b5ac-20cb66f26bfc
RESP BODY: {"ports": [{"status": "DOWN", "binding:host_id": "compute2", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T15:01:08", "device_owner": "compute:nova", "port_security_enabled": true, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.5"}], "id": "9062d380-6c57-48ff-98f1-9ddf52051882", "security_groups": ["58118527-c2d6-4925-9711-87f8399a9b0a"], "device_id": "fe889ac9-0078-4441-a22d-94cdaa8a160d", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:1a:4b:76", "created_at": "2016-08-11T12:33:35"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:09.076 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X PUT http://172.16.116.101:9696/v2.0/ports/9062d380-6c57-48ff-98f1-9ddf52051882.json -H "User-Agent: python-neutronclient" -H "Content-Type: application/json" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}de82ff82764446e5245295078c4da1edbf4c54de" -d '{"port": {"binding:host_id": "compute1"}}' _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:09.378 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:09 GMT Content-Length: 873 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-f65f3727-66b3-4387-8a3b-5da8a3b1dbef
RESP BODY: {"port": {"status": "DOWN", "binding:host_id": "compute1", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T15:01:09", "device_owner": "compute:nova", "port_security_enabled": true, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.5"}], "id": "9062d380-6c57-48ff-98f1-9ddf52051882", "security_groups": ["58118527-c2d6-4925-9711-87f8399a9b0a"], "device_id": "fe889ac9-0078-4441-a22d-94cdaa8a160d", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:1a:4b:76", "created_at": "2016-08-11T12:33:35"}}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:09.379 8206 DEBUG oslo_concurrency.lockutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Acquired semaphore "refresh_cache-fe889ac9-0078-4441-a22d-94cdaa8a160d" lock /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
2016-08-11 12:01:09.380 8206 DEBUG nova.network.neutronv2.api [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] _get_instance_nw_info() _get_instance_nw_info /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/network/neutronv2/api.py:910
2016-08-11 12:01:09.402 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/ports.json?tenant_id=dfa0dd8586294d45b6ce518470e1f53a&device_id=fe889ac9-0078-4441-a22d-94cdaa8a160d -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}de82ff82764446e5245295078c4da1edbf4c54de" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:09.436 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:09 GMT Content-Length: 876 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-11ed0f11-ceb0-4f08-a9d0-8b60e16c47a0
RESP BODY: {"ports": [{"status": "DOWN", "binding:host_id": "compute1", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T15:01:09", "device_owner": "compute:nova", "port_security_enabled": true, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.5"}], "id": "9062d380-6c57-48ff-98f1-9ddf52051882", "security_groups": ["58118527-c2d6-4925-9711-87f8399a9b0a"], "device_id": "fe889ac9-0078-4441-a22d-94cdaa8a160d", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:1a:4b:76", "created_at": "2016-08-11T12:33:35"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:09.437 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/networks.json?id=18df8b2f-2eb3-403b-b59c-15be601f5429 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}ad73fb17a62424c6f2aac91e2c352b4904f5176b" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:09.499 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:09 GMT Content-Length: 660 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-36634b58-cd10-4c00-b39b-8001f90ab3aa
RESP BODY: {"networks": [{"provider:physical_network": null, "ipv6_address_scope": null, "port_security_enabled": true, "mtu": 1450, "id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "router:external": false, "availability_zone_hints": [], "availability_zones": ["nova"], "ipv4_address_scope": null, "shared": false, "provider:segmentation_id": 4171, "status": "ACTIVE", "subnets": ["bb071108-ea70-4654-b423-771cb68e0540"], "description": "", "tags": [], "updated_at": "2016-08-11T12:30:25", "qos_policy_id": null, "name": "lan", "admin_state_up": true, "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "created_at": "2016-08-11T12:30:25", "provider:network_type": "vxlan"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:09.501 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/floatingips.json?fixed_ip_address=192.168.50.5&port_id=9062d380-6c57-48ff-98f1-9ddf52051882 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}de82ff82764446e5245295078c4da1edbf4c54de" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:09.520 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:09 GMT Content-Length: 19 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-fb2234d8-63d2-4725-9e9f-eb551b918c40
RESP BODY: {"floatingips": []}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:09.521 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/subnets.json?id=bb071108-ea70-4654-b423-771cb68e0540 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}ad73fb17a62424c6f2aac91e2c352b4904f5176b" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:09.578 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:09 GMT Content-Length: 574 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-16492c2a-c4a0-43c6-a8ae-7e1cf0f12b3a
RESP BODY: {"subnets": [{"description": "", "enable_dhcp": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "created_at": "2016-08-11T12:30:26", "dns_nameservers": ["8.8.8.8", "8.8.4.4"], "updated_at": "2016-08-11T12:30:26", "gateway_ip": "192.168.50.1", "ipv6_ra_mode": null, "allocation_pools": [{"start": "192.168.50.2", "end": "192.168.50.62"}], "host_routes": [], "ip_version": 4, "ipv6_address_mode": null, "cidr": "192.168.50.0/26", "id": "bb071108-ea70-4654-b423-771cb68e0540", "subnetpool_id": null, "name": "lan"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:09.579 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/ports.json?network_id=18df8b2f-2eb3-403b-b59c-15be601f5429&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}ad73fb17a62424c6f2aac91e2c352b4904f5176b" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:09.613 8206 DEBUG keystoneauth.session [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:09 GMT Content-Length: 2720 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-44356116-ff7a-4476-b92b-852aed06a884
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "infra1-neutron-agents-container-0eb59f4a", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T12:30:33", "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.4"}], "id": "41a98926-b5ff-4d04-b174-490518c2ff4b", "security_groups": [], "device_id": "dhcp0ad9d4cf-c9bc-5381-8c2c-60d51f7c4be8-18df8b2f-2eb3-403b-b59c-15be601f5429", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:55:1a:f1", "created_at": "2016-08-11T12:30:26"}, {"status": "ACTIVE", "binding:host_id": "infra3-neutron-agents-container-88ab550e", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T12:30:30", "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.3"}], "id": "61ce1aae-d06c-45aa-9695-57d856a43fc0", "security_groups": [], "device_id": "dhcp95ac1b17-f4a7-50a2-8702-dd2c38476ac6-18df8b2f-2eb3-403b-b59c-15be601f5429", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:97:08:22", "created_at": "2016-08-11T12:30:26"}, {"status": "ACTIVE", "binding:host_id": "infra2-neutron-agents-container-8f8746a4", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T12:30:30", "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.2"}], "id": "fa5f49bb-a540-4bce-90d0-af3dfbe8ca68", "security_groups": [], "device_id": "dhcpb8d52507-3975-5056-97ca-d5d74d51987e-18df8b2f-2eb3-403b-b59c-15be601f5429", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:01:31:20", "created_at": "2016-08-11T12:30:26"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:09.615 8206 DEBUG nova.network.base_api [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Updating instance_info_cache with network_info: [VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': u'brq18df8b2f-2e', 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'192.168.50.5'})], 'version': 4, 'meta': {'dhcp_server': u'192.168.50.2'}, 'dns': [IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.8.8'}), IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.4.4'})], 'routes': [], 'cidr': u'192.168.50.0/26', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'192.168.50.1'})})], 'meta': {'injected': False, 'tenant_id': u'dfa0dd8586294d45b6ce518470e1f53a', 'should_create_bridge': True, 'mtu': 1450}, 'id': u'18df8b2f-2eb3-403b-b59c-15be601f5429', 'label': u'lan'}), 'devname': u'tap9062d380-6c', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True}, 'address': u'fa:16:3e:1a:4b:76', 'active': False, 'type': u'bridge', 'id': u'9062d380-6c57-48ff-98f1-9ddf52051882', 'qbg_params': None})] update_instance_cache_with_nw_info /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/network/base_api.py:43
2016-08-11 12:01:09.639 8206 DEBUG oslo_concurrency.lockutils [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Releasing semaphore "refresh_cache-fe889ac9-0078-4441-a22d-94cdaa8a160d" lock /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
2016-08-11 12:01:09.667 8206 DEBUG nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Start _get_guest_xml network_info=[VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': u'brq18df8b2f-2e', 'subnets': [Subnet({'ips': [FixedIP({'version': 4, 'vif_mac': u'fa:16:3e:1a:4b:76', 'floating_ips': [], 'label': u'lan', 'meta': {}, 'address': u'192.168.50.5', 'type': 'fixed'})], 'version': 4, 'meta': {'dhcp_server': u'192.168.50.2'}, 'dns': [IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.8.8'}), IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.4.4'})], 'routes': [], 'cidr': u'192.168.50.0/26', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'192.168.50.1'})})], 'meta': {'injected': False, 'tenant_id': u'dfa0dd8586294d45b6ce518470e1f53a', 'should_create_bridge': True, 'mtu': 1450}, 'id': u'18df8b2f-2eb3-403b-b59c-15be601f5429', 'label': u'lan'}), 'devname': u'tap9062d380-6c', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True}, 'address': u'fa:16:3e:1a:4b:76', 'active': False, 'type': u'bridge', 'id': u'9062d380-6c57-48ff-98f1-9ddf52051882', 'qbg_params': None})] disk_info={'disk_bus': 'virtio', 'cdrom_bus': 'ide', 'mapping': {u'/dev/vda': {'bus': u'virtio', 'boot_index': '1', 'type': u'disk', 'dev': u'vda'}, 'root': {'bus': u'virtio', 'boot_index': '1', 'type': u'disk', 'dev': u'vda'}}} image_meta=ImageMeta(checksum=<?>,container_format='bare',created_at=<?>,direct_url=<?>,disk_format='qcow2',id=<?>,min_disk=40,min_ram=0,name=<?>,owner=<?>,properties=ImageMetaProps,protected=<?>,size=<?>,status=<?>,tags=<?>,updated_at=<?>,virtual_size=<?>,visibility=<?>) rescue=None block_device_info={'swap': None, 'root_device_name': u'/dev/vda', 'ephemerals': [], 'block_device_mapping': [{'guest_format': None, 'boot_index': 0, 'mount_device': u'/dev/vda', 'connection_info': {u'driver_volume_type': u'rbd', u'connector': {u'initiator': u'iqn.1993-08.org.debian:01:c02268eeaeee', u'ip': u'172.16.116.16', u'platform': u'x86_64', u'host': u'compute1', u'os_type': u'linux2', u'multipath': False}, u'serial': u'43eff600-4ccd-40dc-a2d5-323902dbdf6f', u'data': {u'secret_type': u'ceph', u'name': u'volumes/volume-43eff600-4ccd-40dc-a2d5-323902dbdf6f', u'encrypted': False, u'secret_uuid': None, u'qos_specs': None, u'hosts': [u'10.1.4.1', u'10.1.4.2', u'10.1.4.3'], u'volume_id': u'43eff600-4ccd-40dc-a2d5-323902dbdf6f', u'auth_enabled': True, u'access_mode': u'rw', u'auth_username': u'cinder', u'ports': [u'6789', u'6789', u'6789']}}, 'disk_bus': u'virtio', 'device_type': u'disk', 'delete_on_termination': False}]} _get_guest_xml /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:4727
2016-08-11 12:01:09.668 8206 DEBUG nova.objects.instance [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Lazy-loading 'pci_devices' on Instance uuid fe889ac9-0078-4441-a22d-94cdaa8a160d obj_load_attr /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/objects/instance.py:895
2016-08-11 12:01:09.684 8206 DEBUG nova.objects.instance [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Lazy-loading 'numa_topology' on Instance uuid fe889ac9-0078-4441-a22d-94cdaa8a160d obj_load_attr /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/objects/instance.py:895
2016-08-11 12:01:09.710 8206 DEBUG nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] CPU mode 'host-model' model '' was chosen _get_guest_cpu_model_config /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:3524
2016-08-11 12:01:09.711 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Getting desirable topologies for flavor Flavor(created_at=None,deleted=False,deleted_at=None,disabled=False,ephemeral_gb=0,extra_specs={},flavorid='3',id=4,is_public=True,memory_mb=4096,name='m1.medium',projects=<?>,root_gb=40,rxtx_factor=1.0,swap=0,updated_at=None,vcpu_weight=0,vcpus=2) and image_meta ImageMeta(checksum=<?>,container_format='bare',created_at=<?>,direct_url=<?>,disk_format='qcow2',id=<?>,min_disk=40,min_ram=0,name=<?>,owner=<?>,properties=ImageMetaProps,protected=<?>,size=<?>,status=<?>,tags=<?>,updated_at=<?>,virtual_size=<?>,visibility=<?>), allow threads: True _get_desirable_cpu_topologies /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:568
2016-08-11 12:01:09.712 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Flavor limits 65536:65536:65536 _get_cpu_topology_constraints /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:312
2016-08-11 12:01:09.713 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Image limits 65536:65536:65536 _get_cpu_topology_constraints /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:323
2016-08-11 12:01:09.713 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Flavor pref -1:-1:-1 _get_cpu_topology_constraints /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:346
2016-08-11 12:01:09.714 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Image pref -1:-1:-1 _get_cpu_topology_constraints /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:365
2016-08-11 12:01:09.714 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Chosen -1:-1:-1 limits 65536:65536:65536 _get_cpu_topology_constraints /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:394
2016-08-11 12:01:09.715 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Topology preferred VirtCPUTopology(cores=-1,sockets=-1,threads=-1), maximum VirtCPUTopology(cores=65536,sockets=65536,threads=65536) _get_desirable_cpu_topologies /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:572
2016-08-11 12:01:09.716 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Build topologies for 2 vcpu(s) 2:2:2 _get_possible_cpu_topologies /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:433
2016-08-11 12:01:09.716 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Got 3 possible topologies _get_possible_cpu_topologies /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:460
2016-08-11 12:01:09.717 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Possible topologies [VirtCPUTopology(cores=1,sockets=2,threads=1), VirtCPUTopology(cores=2,sockets=1,threads=1), VirtCPUTopology(cores=1,sockets=1,threads=2)] _get_desirable_cpu_topologies /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:577
2016-08-11 12:01:09.718 8206 DEBUG nova.virt.hardware [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Sorted desired topologies [VirtCPUTopology(cores=1,sockets=2,threads=1), VirtCPUTopology(cores=2,sockets=1,threads=1), VirtCPUTopology(cores=1,sockets=1,threads=2)] _get_desirable_cpu_topologies /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/hardware.py:602
2016-08-11 12:01:09.718 8206 DEBUG nova.objects.instance [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Lazy-loading 'vcpu_model' on Instance uuid fe889ac9-0078-4441-a22d-94cdaa8a160d obj_load_attr /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/objects/instance.py:895
2016-08-11 12:01:09.753 8206 DEBUG nova.virt.libvirt.vif [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] vif_type=bridge instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=True,availability_zone='nova',cell_name=None,cleaned=True,config_drive='',created_at=2016-08-11T12:33:34Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,disable_terminate=False,display_description='ubuntu14',display_name='ubuntu14',ec2_ids=<?>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,flavor=Flavor(4),host='compute2',hostname='ubuntu14',id=4,image_ref='',info_cache=InstanceInfoCache,instance_type_id=4,kernel_id='',key_data='ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCnF95HG7f35+TvfZGgt48aZYMrfIGewGjiixM1trjRokxU7rxFQmRu0kXNEGJWhTlupAwViZyFtaPx+JBAjRg4saTdFLjkped0l1lApqgqBxFQaQyIkZUSRfam3EYu4GFvd253kAdBaPHAoqQ+dAuFSm+QurrrDw/R464PlHwHvhB4z2PoloxfLuebkp4VxBLLcH0XFIREILeI+XOPsBsl2S5vhRsHZgnqMzYi18PhTHTE8DIlD7JivvvDEJd+8byWeH/6kYquyTQwk81qtpddS5a9HM67TlIYqaxCQYYFNXl3Y1ClDpgcLXH7kUVwQ33SzM/aCsgoD/VLpWpVDXRD',key_name='desenvolvimento',launch_index=0,launched_at=2016-08-11T12:34:19Z,launched_on='compute1',locked=False,locked_by=None,memory_mb=4096,metadata={},migration_context=<?>,new_flavor=None,node='compute2',numa_topology=None,old_flavor=None,os_type=None,pci_devices=PciDeviceList,pci_requests=<?>,power_state=1,progress=0,project_id='dfa0dd8586294d45b6ce518470e1f53a',ramdisk_id='',reservation_id='r-g79k6nvf',root_device_name='/dev/vda',root_gb=40,security_groups=SecurityGroupList,services=<?>,shutdown_terminate=False,system_metadata={clean_attempts='9',image_base_image_ref='',image_container_format='bare',image_disk_format='qcow2',image_min_disk='40',image_min_ram='0'},tags=<?>,task_state='migrating',terminated_at=None,updated_at=2016-08-11T15:00:59Z,user_data=None,user_id='90cb07ccd2224bc68d1462d3fc339f28',uuid=fe889ac9-0078-4441-a22d-94cdaa8a160d,vcpu_model=VirtCPUModel,vcpus=2,vm_mode=None,vm_state='active') vif=VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': u'brq18df8b2f-2e', 'subnets': [Subnet({'ips': [FixedIP({'version': 4, 'vif_mac': u'fa:16:3e:1a:4b:76', 'floating_ips': [], 'label': u'lan', 'meta': {}, 'address': u'192.168.50.5', 'type': 'fixed'})], 'version': 4, 'meta': {'dhcp_server': u'192.168.50.2'}, 'dns': [IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.8.8'}), IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.4.4'})], 'routes': [], 'cidr': u'192.168.50.0/26', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'192.168.50.1'})})], 'meta': {'injected': False, 'tenant_id': u'dfa0dd8586294d45b6ce518470e1f53a', 'should_create_bridge': True, 'mtu': 1450}, 'id': u'18df8b2f-2eb3-403b-b59c-15be601f5429', 'label': u'lan'}), 'devname': u'tap9062d380-6c', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True}, 'address': u'fa:16:3e:1a:4b:76', 'active': False, 'type': u'bridge', 'id': u'9062d380-6c57-48ff-98f1-9ddf52051882', 'qbg_params': None}) virt_typekvm get_config /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/vif.py:437
2016-08-11 12:01:09.759 8206 DEBUG nova.virt.libvirt.config [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] Generated XML ('<domain type="kvm">\n <uuid>fe889ac9-0078-4441-a22d-94cdaa8a160d</uuid>\n <name>instance-00000004</name>\n <memory>4194304</memory>\n <vcpu>2</vcpu>\n <metadata>\n <nova:instance xmlns:nova="http://openstack.org/xmlns/libvirt/nova/1.0">\n <nova:package version="13.1.1"/>\n <nova:name>ubuntu14</nova:name>\n <nova:creationTime>2016-08-11 15:01:09</nova:creationTime>\n <nova:flavor name="m1.medium">\n <nova:memory>4096</nova:memory>\n <nova:disk>40</nova:disk>\n <nova:swap>0</nova:swap>\n <nova:ephemeral>0</nova:ephemeral>\n <nova:vcpus>2</nova:vcpus>\n </nova:flavor>\n <nova:owner>\n <nova:user uuid="90cb07ccd2224bc68d1462d3fc339f28">admin</nova:user>\n <nova:project uuid="dfa0dd8586294d45b6ce518470e1f53a">admin</nova:project>\n </nova:owner>\n </nova:instance>\n </metadata>\n <sysinfo type="smbios">\n <system>\n <entry name="manufacturer">OpenStack Foundation</entry>\n <entry name="product">OpenStack Nova</entry>\n <entry name="version">13.1.1</entry>\n <entry name="serial">4c4c4544-0052-4710-8056-b9c04f395831</entry>\n <entry name="uuid">fe889ac9-0078-4441-a22d-94cdaa8a160d</entry>\n <entry name="family">Virtual Machine</entry>\n </system>\n </sysinfo>\n <os>\n <type>hvm</type>\n <boot dev="hd"/>\n <smbios mode="sysinfo"/>\n </os>\n <features>\n <acpi/>\n <apic/>\n </features>\n <cputune>\n <shares>2048</shares>\n </cputune>\n <clock offset="utc">\n <timer name="pit" tickpolicy="delay"/>\n <timer name="rtc" tickpolicy="catchup"/>\n <timer name="hpet" present="no"/>\n </clock>\n <cpu mode="host-model" match="exact">\n <topology sockets="2" cores="1" threads="1"/>\n </cpu>\n <devices>\n <disk type="network" device="disk">\n <driver name="qemu" type="raw" cache="writeback"/>\n <source protocol="rbd" name="volumes/volume-43eff600-4ccd-40dc-a2d5-323902dbdf6f">\n <host name="10.1.4.1" port="6789"/>\n <host name="10.1.4.2" port="6789"/>\n <host name="10.1.4.3" port="6789"/>\n </source>\n <auth username="cinder">\n <secret type="ceph" uuid="ad48149b-740a-46c5-951f-ddb117b33595"/>\n </auth>\n <target bus="virtio" dev="vda"/>\n <serial>43eff600-4ccd-40dc-a2d5-323902dbdf6f</serial>\n </disk>\n <interface type="bridge">\n <mac address="fa:16:3e:1a:4b:76"/>\n <model type="virtio"/>\n <source bridge="brq18df8b2f-2e"/>\n <target dev="tap9062d380-6c"/>\n </interface>\n <serial type="file">\n <source path="/var/lib/nova/instances/fe889ac9-0078-4441-a22d-94cdaa8a160d/console.log"/>\n </serial>\n <serial type="pty"/>\n <channel type="pty">\n <target type="virtio" name="com.redhat.spice.0"/>\n </channel>\n <graphics type="spice" autoport="yes" keymap="en-us" listen="172.16.116.16"/>\n <video>\n <model type="qxl"/>\n </video>\n <memballoon model="virtio">\n <stats period="10"/>\n </memballoon>\n </devices>\n</domain>\n',) to_xml /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/config.py:82
2016-08-11 12:01:09.761 8206 DEBUG nova.virt.libvirt.driver [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] End _get_guest_xml xml=<domain type="kvm">
<uuid>fe889ac9-0078-4441-a22d-94cdaa8a160d</uuid>
<name>instance-00000004</name>
<memory>4194304</memory>
<vcpu>2</vcpu>
<metadata>
<nova:instance xmlns:nova="http://openstack.org/xmlns/libvirt/nova/1.0">
<nova:package version="13.1.1"/>
<nova:name>ubuntu14</nova:name>
<nova:creationTime>2016-08-11 15:01:09</nova:creationTime>
<nova:flavor name="m1.medium">
<nova:memory>4096</nova:memory>
<nova:disk>40</nova:disk>
<nova:swap>0</nova:swap>
<nova:ephemeral>0</nova:ephemeral>
<nova:vcpus>2</nova:vcpus>
</nova:flavor>
<nova:owner>
<nova:user uuid="90cb07ccd2224bc68d1462d3fc339f28">admin</nova:user>
<nova:project uuid="dfa0dd8586294d45b6ce518470e1f53a">admin</nova:project>
</nova:owner>
</nova:instance>
</metadata>
<sysinfo type="smbios">
<system>
<entry name="manufacturer">OpenStack Foundation</entry>
<entry name="product">OpenStack Nova</entry>
<entry name="version">13.1.1</entry>
<entry name="serial">4c4c4544-0052-4710-8056-b9c04f395831</entry>
<entry name="uuid">fe889ac9-0078-4441-a22d-94cdaa8a160d</entry>
<entry name="family">Virtual Machine</entry>
</system>
</sysinfo>
<os>
<type>hvm</type>
<boot dev="hd"/>
<smbios mode="sysinfo"/>
</os>
<features>
<acpi/>
<apic/>
</features>
<cputune>
<shares>2048</shares>
</cputune>
<clock offset="utc">
<timer name="pit" tickpolicy="delay"/>
<timer name="rtc" tickpolicy="catchup"/>
<timer name="hpet" present="no"/>
</clock>
<cpu mode="host-model" match="exact">
<topology sockets="2" cores="1" threads="1"/>
</cpu>
<devices>
<disk type="network" device="disk">
<driver name="qemu" type="raw" cache="writeback"/>
<source protocol="rbd" name="volumes/volume-43eff600-4ccd-40dc-a2d5-323902dbdf6f">
<host name="10.1.4.1" port="6789"/>
<host name="10.1.4.2" port="6789"/>
<host name="10.1.4.3" port="6789"/>
</source>
<auth username="cinder">
<secret type="ceph" uuid="ad48149b-740a-46c5-951f-ddb117b33595"/>
</auth>
<target bus="virtio" dev="vda"/>
<serial>43eff600-4ccd-40dc-a2d5-323902dbdf6f</serial>
</disk>
<interface type="bridge">
<mac address="fa:16:3e:1a:4b:76"/>
<model type="virtio"/>
<source bridge="brq18df8b2f-2e"/>
<target dev="tap9062d380-6c"/>
</interface>
<serial type="file">
<source path="/var/lib/nova/instances/fe889ac9-0078-4441-a22d-94cdaa8a160d/console.log"/>
</serial>
<serial type="pty"/>
<channel type="pty">
<target type="virtio" name="com.redhat.spice.0"/>
</channel>
<graphics type="spice" autoport="yes" keymap="en-us" listen="172.16.116.16"/>
<video>
<model type="qxl"/>
</video>
<memballoon model="virtio">
<stats period="10"/>
</memballoon>
</devices>
</domain>
_get_guest_xml /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:4739
2016-08-11 12:01:09.769 8206 DEBUG nova.compute.manager [req-0667af2c-281d-4c4e-ab7f-5b179d015ae7 90cb07ccd2224bc68d1462d3fc339f28 dfa0dd8586294d45b6ce518470e1f53a - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Checking state _get_power_state /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:1347
2016-08-11 12:01:10.462 8206 DEBUG nova.compute.manager [req-d1b9daf5-ea87-4afb-93dc-4e7d1d7b95d5 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Received event network-vif-unplugged-9062d380-6c57-48ff-98f1-9ddf52051882 external_instance_event /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:6704
2016-08-11 12:01:10.464 8206 DEBUG oslo_concurrency.lockutils [req-d1b9daf5-ea87-4afb-93dc-4e7d1d7b95d5 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] Lock "fe889ac9-0078-4441-a22d-94cdaa8a160d-events" acquired by "nova.compute.manager._pop_event" :: waited 0.000s inner /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2016-08-11 12:01:10.465 8206 DEBUG nova.compute.manager [req-d1b9daf5-ea87-4afb-93dc-4e7d1d7b95d5 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Unexpected attempt to pop events during shutdown _pop_event /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:538
2016-08-11 12:01:10.466 8206 DEBUG oslo_concurrency.lockutils [req-d1b9daf5-ea87-4afb-93dc-4e7d1d7b95d5 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] Lock "fe889ac9-0078-4441-a22d-94cdaa8a160d-events" released by "nova.compute.manager._pop_event" :: held 0.002s inner /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2016-08-11 12:01:10.467 8206 DEBUG nova.compute.manager [req-d1b9daf5-ea87-4afb-93dc-4e7d1d7b95d5 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] No waiting events found dispatching network-vif-unplugged-9062d380-6c57-48ff-98f1-9ddf52051882 pop_instance_event /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:554
2016-08-11 12:01:11.556 8206 DEBUG nova.compute.manager [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Received event network-changed external_instance_event /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:6704
2016-08-11 12:01:11.557 8206 DEBUG oslo_concurrency.lockutils [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] Acquired semaphore "refresh_cache-fe889ac9-0078-4441-a22d-94cdaa8a160d" lock /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
2016-08-11 12:01:11.558 8206 DEBUG nova.network.neutronv2.api [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] _get_instance_nw_info() _get_instance_nw_info /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/network/neutronv2/api.py:910
2016-08-11 12:01:11.576 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/ports.json?tenant_id=dfa0dd8586294d45b6ce518470e1f53a&device_id=fe889ac9-0078-4441-a22d-94cdaa8a160d -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}de82ff82764446e5245295078c4da1edbf4c54de" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:11.614 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:11 GMT Content-Length: 876 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-a1a21f36-8db0-4a51-801a-36d627867a33
RESP BODY: {"ports": [{"status": "DOWN", "binding:host_id": "compute1", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T15:01:09", "device_owner": "compute:nova", "port_security_enabled": true, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.5"}], "id": "9062d380-6c57-48ff-98f1-9ddf52051882", "security_groups": ["58118527-c2d6-4925-9711-87f8399a9b0a"], "device_id": "fe889ac9-0078-4441-a22d-94cdaa8a160d", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:1a:4b:76", "created_at": "2016-08-11T12:33:35"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:11.616 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/networks.json?id=18df8b2f-2eb3-403b-b59c-15be601f5429 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}25772a34a8e132f3a8b4dd1075ff287289e7136a" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:11.672 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:11 GMT Content-Length: 660 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-4d672d1e-a6b9-4728-9bb1-df1fcc3678aa
RESP BODY: {"networks": [{"provider:physical_network": null, "ipv6_address_scope": null, "port_security_enabled": true, "mtu": 1450, "id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "router:external": false, "availability_zone_hints": [], "availability_zones": ["nova"], "ipv4_address_scope": null, "shared": false, "provider:segmentation_id": 4171, "status": "ACTIVE", "subnets": ["bb071108-ea70-4654-b423-771cb68e0540"], "description": "", "tags": [], "updated_at": "2016-08-11T12:30:25", "qos_policy_id": null, "name": "lan", "admin_state_up": true, "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "created_at": "2016-08-11T12:30:25", "provider:network_type": "vxlan"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:11.674 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/floatingips.json?fixed_ip_address=192.168.50.5&port_id=9062d380-6c57-48ff-98f1-9ddf52051882 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}de82ff82764446e5245295078c4da1edbf4c54de" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:11.693 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:11 GMT Content-Length: 19 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-83ef72b9-2f86-4e37-a22f-65cfe82b0d4c
RESP BODY: {"floatingips": []}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:11.694 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/subnets.json?id=bb071108-ea70-4654-b423-771cb68e0540 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}25772a34a8e132f3a8b4dd1075ff287289e7136a" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:11.748 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:11 GMT Content-Length: 574 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-9d5e279f-62a4-4f17-a4a0-d65ae335ffbf
RESP BODY: {"subnets": [{"description": "", "enable_dhcp": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "created_at": "2016-08-11T12:30:26", "dns_nameservers": ["8.8.8.8", "8.8.4.4"], "updated_at": "2016-08-11T12:30:26", "gateway_ip": "192.168.50.1", "ipv6_ra_mode": null, "allocation_pools": [{"start": "192.168.50.2", "end": "192.168.50.62"}], "host_routes": [], "ip_version": 4, "ipv6_address_mode": null, "cidr": "192.168.50.0/26", "id": "bb071108-ea70-4654-b423-771cb68e0540", "subnetpool_id": null, "name": "lan"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:11.750 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] REQ: curl -g -i -X GET http://172.16.116.101:9696/v2.0/ports.json?network_id=18df8b2f-2eb3-403b-b59c-15be601f5429&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}25772a34a8e132f3a8b4dd1075ff287289e7136a" _http_log_request /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:248
2016-08-11 12:01:11.783 8206 DEBUG keystoneauth.session [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] RESP: [200] Date: Thu, 11 Aug 2016 15:01:11 GMT Content-Length: 2720 Content-Type: application/json; charset=UTF-8 X-Openstack-Request-Id: req-3f2ba579-d51c-47f2-8803-f129aa0cc34d
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "infra1-neutron-agents-container-0eb59f4a", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T12:30:33", "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.4"}], "id": "41a98926-b5ff-4d04-b174-490518c2ff4b", "security_groups": [], "device_id": "dhcp0ad9d4cf-c9bc-5381-8c2c-60d51f7c4be8-18df8b2f-2eb3-403b-b59c-15be601f5429", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:55:1a:f1", "created_at": "2016-08-11T12:30:26"}, {"status": "ACTIVE", "binding:host_id": "infra3-neutron-agents-container-88ab550e", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T12:30:30", "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.3"}], "id": "61ce1aae-d06c-45aa-9695-57d856a43fc0", "security_groups": [], "device_id": "dhcp95ac1b17-f4a7-50a2-8702-dd2c38476ac6-18df8b2f-2eb3-403b-b59c-15be601f5429", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:97:08:22", "created_at": "2016-08-11T12:30:26"}, {"status": "ACTIVE", "binding:host_id": "infra2-neutron-agents-container-8f8746a4", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2016-08-11T12:30:30", "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "qos_policy_id": null, "fixed_ips": [{"subnet_id": "bb071108-ea70-4654-b423-771cb68e0540", "ip_address": "192.168.50.2"}], "id": "fa5f49bb-a540-4bce-90d0-af3dfbe8ca68", "security_groups": [], "device_id": "dhcpb8d52507-3975-5056-97ca-d5d74d51987e-18df8b2f-2eb3-403b-b59c-15be601f5429", "name": "", "admin_state_up": true, "network_id": "18df8b2f-2eb3-403b-b59c-15be601f5429", "dns_name": null, "binding:vif_details": {"port_filter": true}, "binding:vnic_type": "normal", "binding:vif_type": "bridge", "tenant_id": "dfa0dd8586294d45b6ce518470e1f53a", "mac_address": "fa:16:3e:01:31:20", "created_at": "2016-08-11T12:30:26"}]}
_http_log_response /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/keystoneauth1/session.py:277
2016-08-11 12:01:11.785 8206 DEBUG nova.network.base_api [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Updating instance_info_cache with network_info: [VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': u'brq18df8b2f-2e', 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'192.168.50.5'})], 'version': 4, 'meta': {'dhcp_server': u'192.168.50.2'}, 'dns': [IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.8.8'}), IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'8.8.4.4'})], 'routes': [], 'cidr': u'192.168.50.0/26', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'192.168.50.1'})})], 'meta': {'injected': False, 'tenant_id': u'dfa0dd8586294d45b6ce518470e1f53a', 'should_create_bridge': True, 'mtu': 1450}, 'id': u'18df8b2f-2eb3-403b-b59c-15be601f5429', 'label': u'lan'}), 'devname': u'tap9062d380-6c', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True}, 'address': u'fa:16:3e:1a:4b:76', 'active': False, 'type': u'bridge', 'id': u'9062d380-6c57-48ff-98f1-9ddf52051882', 'qbg_params': None})] update_instance_cache_with_nw_info /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/network/base_api.py:43
2016-08-11 12:01:11.805 8206 DEBUG oslo_concurrency.lockutils [req-ea81b107-7b5e-44a3-b439-d2c249d50c59 b735250536b043148771730acc8a3855 ba2a4bae74494750a808e9f16175be17 - - -] Releasing semaphore "refresh_cache-fe889ac9-0078-4441-a22d-94cdaa8a160d" lock /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
2016-08-11 12:01:15.044 8206 DEBUG oslo_service.periodic_task [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2016-08-11 12:01:15.045 8206 DEBUG nova.compute.manager [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:6413
2016-08-11 12:01:16.008 8206 DEBUG oslo_service.periodic_task [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2016-08-11 12:01:20.011 8206 DEBUG oslo_service.periodic_task [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Running periodic task ComputeManager._cleanup_incomplete_migrations run_periodic_tasks /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2016-08-11 12:01:20.012 8206 DEBUG nova.compute.manager [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Cleaning up deleted instances with incomplete migration _cleanup_incomplete_migrations /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:6783
2016-08-11 12:01:22.640 8206 DEBUG nova.virt.driver [-] Emitting event <LifecycleEvent: 1470927667.44, fe889ac9-0078-4441-a22d-94cdaa8a160d => Stopped> emit_event /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/virt/driver.py:1443
2016-08-11 12:01:22.641 8206 INFO nova.compute.manager [-] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] VM Stopped (Lifecycle Event)
2016-08-11 12:01:22.694 8206 DEBUG nova.compute.manager [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Checking state _get_power_state /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:1347
2016-08-11 12:01:22.703 8206 DEBUG nova.compute.manager [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Synchronizing instance power state after lifecycle event "Stopped"; current vm_state: active, current task_state: None, current DB power_state: 4, VM power_state: 4 handle_lifecycle_event /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:1276
2016-08-11 12:01:22.755 8206 WARNING nova.compute.manager [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Instance shutdown by itself. Calling the stop API. Current vm_state: active, current task_state: None, original DB power_state: 4, current VM power_state: 4
2016-08-11 12:01:22.757 8206 DEBUG nova.compute.api [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Going to try to stop instance force_stop /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/api.py:1954
2016-08-11 12:01:22.954 8206 DEBUG oslo_concurrency.lockutils [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] Lock "fe889ac9-0078-4441-a22d-94cdaa8a160d" acquired by "nova.compute.manager.do_stop_instance" :: waited 0.000s inner /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2016-08-11 12:01:22.956 8206 DEBUG nova.compute.manager [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Checking state _get_power_state /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:1347
2016-08-11 12:01:22.963 8206 DEBUG nova.compute.manager [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Stopping instance; current vm_state: active, current task_state: powering-off, current DB power_state: 4, current VM power_state: 4 do_stop_instance /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:2545
2016-08-11 12:01:22.964 8206 INFO nova.compute.manager [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Instance is already powered off in the hypervisor when stop is called.
2016-08-11 12:01:22.966 8206 DEBUG nova.objects.instance [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] Lazy-loading 'metadata' on Instance uuid fe889ac9-0078-4441-a22d-94cdaa8a160d obj_load_attr /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/objects/instance.py:895
2016-08-11 12:01:23.029 8206 DEBUG oslo_service.periodic_task [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2016-08-11 12:01:23.074 8206 INFO nova.compute.resource_tracker [req-a8503052-713f-4726-94ba-ddc23912e906 - - - - -] Auditing locally available compute resources for node compute1
2016-08-11 12:01:23.168 8206 INFO nova.virt.libvirt.driver [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Instance already shutdown.
2016-08-11 12:01:23.184 8206 INFO nova.virt.libvirt.driver [-] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Instance destroyed successfully.
2016-08-11 12:01:23.185 8206 DEBUG nova.compute.manager [req-a05c5885-1215-4412-bdbe-20314f6bcbf8 - - - - -] [instance: fe889ac9-0078-4441-a22d-94cdaa8a160d] Checking state _get_power_state /openstack/venvs/nova-13.3.0/lib/python2.7/site-packages/nova/compute/manager.py:1347
