2015-09-26 08:51:39.201 [00;32mDEBUG oslo_service.periodic_task [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRunning periodic task ComputeManager.update_available_resource[00m [00;33mfrom (pid=2811) run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:213[00m
2015-09-26 08:51:39.239 [00;36mINFO nova.compute.resource_tracker [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;36m] [01;35m[00;36mAuditing locally available compute resources for node devstack2[00m
2015-09-26 08:51:39.282 [00;32mDEBUG nova.compute.resource_tracker [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mHypervisor: free VCPUs: 1[00m [00;33mfrom (pid=2811) _report_hypervisor_resource_view /home/stack/src/cloud/nova/nova/compute/resource_tracker.py:570[00m
2015-09-26 08:51:39.282 [00;32mDEBUG nova.compute.resource_tracker [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mHypervisor: assignable PCI devices: [{"dev_id": "pci_0000_00_00_0", "product_id": "1237", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_1237", "address": "0000:00:00.0"}, {"dev_id": "pci_0000_00_01_0", "product_id": "7000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7000", "address": "0000:00:01.0"}, {"dev_id": "pci_0000_00_01_1", "product_id": "7010", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7010", "address": "0000:00:01.1"}, {"dev_id": "pci_0000_00_01_3", "product_id": "7113", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7113", "address": "0000:00:01.3"}, {"dev_id": "pci_0000_00_02_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:02.0"}, {"dev_id": "pci_0000_00_03_0", "product_id": "1003", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1003", "address": "0000:00:03.0"}, {"dev_id": "pci_0000_00_04_0", "product_id": "2934", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2934", "address": "0000:00:04.0"}, {"dev_id": "pci_0000_00_04_1", "product_id": "2935", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2935", "address": "0000:00:04.1"}, {"dev_id": "pci_0000_00_04_2", "product_id": "2936", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2936", "address": "0000:00:04.2"}, {"dev_id": "pci_0000_00_04_7", "product_id": "293a", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_293a", "address": "0000:00:04.7"}, {"dev_id": "pci_0000_00_05_0", "product_id": "1001", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1001", "address": "0000:00:05.0"}, {"dev_id": "pci_0000_00_06_0", "product_id": "1002", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1002", "address": "0000:00:06.0"}][00m [00;33mfrom (pid=2811) _report_hypervisor_resource_view /home/stack/src/cloud/nova/nova/compute/resource_tracker.py:578[00m
2015-09-26 08:51:39.283 [00;32mDEBUG nova.compute.resource_tracker [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mHypervisor/Node resource view: name=devstack2 free_ram=7583MB free_disk=2GB free_vcpus=1 pci_devices=[{"dev_id": "pci_0000_00_00_0", "product_id": "1237", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_1237", "address": "0000:00:00.0"}, {"dev_id": "pci_0000_00_01_0", "product_id": "7000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7000", "address": "0000:00:01.0"}, {"dev_id": "pci_0000_00_01_1", "product_id": "7010", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7010", "address": "0000:00:01.1"}, {"dev_id": "pci_0000_00_01_3", "product_id": "7113", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_7113", "address": "0000:00:01.3"}, {"dev_id": "pci_0000_00_02_0", "product_id": "1000", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1000", "address": "0000:00:02.0"}, {"dev_id": "pci_0000_00_03_0", "product_id": "1003", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1003", "address": "0000:00:03.0"}, {"dev_id": "pci_0000_00_04_0", "product_id": "2934", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2934", "address": "0000:00:04.0"}, {"dev_id": "pci_0000_00_04_1", "product_id": "2935", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2935", "address": "0000:00:04.1"}, {"dev_id": "pci_0000_00_04_2", "product_id": "2936", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_2936", "address": "0000:00:04.2"}, {"dev_id": "pci_0000_00_04_7", "product_id": "293a", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "8086", "label": "label_8086_293a", "address": "0000:00:04.7"}, {"dev_id": "pci_0000_00_05_0", "product_id": "1001", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1001", "address": "0000:00:05.0"}, {"dev_id": "pci_0000_00_06_0", "product_id": "1002", "dev_type": "type-PCI", "numa_node": null, "vendor_id": "1af4", "label": "label_1af4_1002", "address": "0000:00:06.0"}][00m [00;33mfrom (pid=2811) _report_hypervisor_resource_view /home/stack/src/cloud/nova/nova/compute/resource_tracker.py:592[00m
2015-09-26 08:51:39.284 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mLock "compute_resources" acquired by "nova.compute.resource_tracker._update_available_resource" :: waited 0.000s[00m [00;33mfrom (pid=2811) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:253[00m
2015-09-26 08:51:39.391 [00;36mINFO nova.compute.resource_tracker [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;36m] [01;35m[00;36mTotal usable vcpus: 1, total allocated vcpus: 0[00m
2015-09-26 08:51:39.391 [00;36mINFO nova.compute.resource_tracker [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;36m] [01;35m[00;36mFinal resource view: name=devstack2 phys_ram=7984MB used_ram=512MB phys_disk=4GB used_disk=0GB total_vcpus=1 used_vcpus=0 pci_stats=None[00m
2015-09-26 08:51:39.482 [00;36mINFO nova.compute.resource_tracker [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;36m] [01;35m[00;36mCompute_service record updated for devstack2:devstack2[00m
2015-09-26 08:51:39.483 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mLock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.199s[00m [00;33mfrom (pid=2811) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265[00m
2015-09-26 08:51:55.426 [00;32mDEBUG oslo_service.periodic_task [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRunning periodic task ComputeManager._reclaim_queued_deletes[00m [00;33mfrom (pid=2811) run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:213[00m
2015-09-26 08:51:55.426 [00;32mDEBUG nova.compute.manager [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mCONF.reclaim_instance_interval <= 0, skipping...[00m [00;33mfrom (pid=2811) _reclaim_queued_deletes /home/stack/src/cloud/nova/nova/compute/manager.py:6084[00m
2015-09-26 08:51:56.138 [00;32mDEBUG oslo_service.periodic_task [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRunning periodic task ComputeManager._check_instance_build_time[00m [00;33mfrom (pid=2811) run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:213[00m
2015-09-26 08:52:00.259 [00;32mDEBUG nova.objects.instance [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mLazy-loading `vcpu_model' on Instance uuid 3d6a16d5-6678-474e-9710-682473d1d98c[00m [00;33mfrom (pid=2811) obj_load_attr /home/stack/src/cloud/nova/nova/objects/instance.py:845[00m
2015-09-26 08:52:00.281 [00;36mINFO nova.virt.libvirt.driver [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;36m] [01;35m[00;36mInstance launched has CPU info: {"vendor": "Intel", "model": "Nehalem", "arch": "x86_64", "features": ["pge", "avx", "clflush", "sep", "syscall", "tsc-deadline", "invpcid", "tsc", "fsgsbase", "xsave", "vmx", "erms", "cmov", "smep", "pcid", "pat", "lm", "msr", "nx", "fxsr", "sse4.1", "pae", "sse4.2", "pclmuldq", "fma", "vme", "mmx", "osxsave", "cx8", "mce", "de", "mca", "pse", "lahf_lm", "abm", "popcnt", "pdpe1gb", "apic", "sse", "f16c", "pni", "rdtscp", "avx2", "sse2", "ss", "hypervisor", "bmi1", "bmi2", "ssse3", "fpu", "cx16", "pse36", "mtrr", "movbe", "rdrand", "x2apic"], "topology": {"cores": 1, "threads": 1, "sockets": 1}}[00m
2015-09-26 08:52:00.284 [00;32mDEBUG nova.virt.libvirt.config [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mGenerated XML ('\n x86_64\n Nehalem\n Intel\n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n\n',) [00m [00;33mfrom (pid=2811) to_xml /home/stack/src/cloud/nova/nova/virt/libvirt/config.py:82[00m
2015-09-26 08:52:00.287 [00;32mDEBUG nova.virt.libvirt.driver [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCreating tmpfile /home/stack/src/cloud/data/nova/instances/tmpQkTrUY to notify to other compute nodes that they should mount the same storage.[00m [00;33mfrom (pid=2811) _create_shared_storage_test_file /home/stack/src/cloud/nova/nova/virt/libvirt/driver.py:5331[00m
2015-09-26 08:52:01.538 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mAcquired semaphore "refresh_cache-3d6a16d5-6678-474e-9710-682473d1d98c"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:01.538 [00;32mDEBUG nova.network.neutronv2.api [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32m_get_instance_nw_info()[00m [00;33mfrom (pid=2811) _get_instance_nw_info /home/stack/src/cloud/nova/nova/network/neutronv2/api.py:922[00m
2015-09-26 08:52:01.555 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mAcquired semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:01.556 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mReleasing semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:01.557 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?tenant_id=c392e44c09ce4cc9b3e77e79df76a81f&device_id=3d6a16d5-6678-474e-9710-682473d1d98c -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:01.794 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:01 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1006 x-openstack-request-id: req-26c7d4df-d50c-4a83-89f6-66f1615bb09f
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-3", "ip_address": "10.1.0.3", "fqdn": "host-10-1-0-3.openstacklocal."}], "device_owner": "compute:None", "port_security_enabled": true, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.3"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa"}], "id": "da4ab1e3-be0d-4c24-8a90-d863aa189577", "security_groups": ["81ff7d2b-1c00-4afb-ae1c-a73085b2ba65"], "device_id": "3d6a16d5-6678-474e-9710-682473d1d98c", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:83:44:aa"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:01.796 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/networks.json?id=c16b9c17-a4c6-41ec-adcc-2800accbb727 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}1dfc72f2e3e9d672a27584e71053295433ff0461"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:01.832 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:01 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 454 x-openstack-request-id: req-271f2f1d-f555-4aac-a66a-def1649120ce
RESP BODY: {"networks": [{"status": "ACTIVE", "subnets": ["288075d8-b675-44d1-a50b-8832986c7d96", "ef534dcc-7e40-461c-865f-b64199d5a8a0"], "name": "private", "provider:physical_network": null, "admin_state_up": true, "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mtu": 0, "router:external": false, "shared": false, "port_security_enabled": true, "provider:network_type": "vxlan", "id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "provider:segmentation_id": 1041}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:01.834 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/floatingips.json?fixed_ip_address=10.1.0.3&port_id=da4ab1e3-be0d-4c24-8a90-d863aa189577 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:01.845 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:01 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 19 x-openstack-request-id: req-f8295dda-d9cb-4c11-85ee-eb0de1799b54
RESP BODY: {"floatingips": []}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:01.846 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/floatingips.json?fixed_ip_address=fdbd%3A4e3b%3Ace09%3A0%3Af816%3A3eff%3Afe83%3A44aa&port_id=da4ab1e3-be0d-4c24-8a90-d863aa189577 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:01.862 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:01 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 19 x-openstack-request-id: req-a055172a-966c-46f9-be19-2321107e1ee8
RESP BODY: {"floatingips": []}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:01.863 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/subnets.json?id=288075d8-b675-44d1-a50b-8832986c7d96&id=ef534dcc-7e40-461c-865f-b64199d5a8a0 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}1dfc72f2e3e9d672a27584e71053295433ff0461"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:01.953 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:01 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 964 x-openstack-request-id: req-88e8f6c8-19d7-4f85-ad5b-3362d8aff9af
RESP BODY: {"subnets": [{"name": "private-subnet", "enable_dhcp": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "dns_nameservers": [], "gateway_ip": "10.1.0.1", "ipv6_ra_mode": null, "allocation_pools": [{"start": "10.1.0.2", "end": "10.1.0.254"}], "host_routes": [], "ip_version": 4, "ipv6_address_mode": null, "cidr": "10.1.0.0/24", "id": "288075d8-b675-44d1-a50b-8832986c7d96", "subnetpool_id": null}, {"name": "ipv6-private-subnet", "enable_dhcp": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "dns_nameservers": [], "gateway_ip": "fdbd:4e3b:ce09::1", "ipv6_ra_mode": "slaac", "allocation_pools": [{"start": "fdbd:4e3b:ce09::2", "end": "fdbd:4e3b:ce09:0:ffff:ffff:ffff:ffff"}], "host_routes": [], "ip_version": 6, "ipv6_address_mode": "slaac", "cidr": "fdbd:4e3b:ce09::/64", "id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "subnetpool_id": null}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:01.955 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?network_id=c16b9c17-a4c6-41ec-adcc-2800accbb727&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}1dfc72f2e3e9d672a27584e71053295433ff0461"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:02.090 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:01 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1010 x-openstack-request-id: req-9a34cb25-1538-407d-8ec1-3365bb699443
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-2", "ip_address": "10.1.0.2", "fqdn": "host-10-1-0-2.openstacklocal."}], "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.2"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8"}], "id": "22c20e9c-12e9-4b52-9103-fca0e9a47013", "security_groups": [], "device_id": "dhcp6d13ba27-f5a3-57ff-8437-9fbb02a7daef-c16b9c17-a4c6-41ec-adcc-2800accbb727", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:fa:be:c8"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:02.092 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?network_id=c16b9c17-a4c6-41ec-adcc-2800accbb727&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}1dfc72f2e3e9d672a27584e71053295433ff0461"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:02.179 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:01 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1010 x-openstack-request-id: req-a1e4a535-4880-48ae-9158-258425267268
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-2", "ip_address": "10.1.0.2", "fqdn": "host-10-1-0-2.openstacklocal."}], "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.2"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8"}], "id": "22c20e9c-12e9-4b52-9103-fca0e9a47013", "security_groups": [], "device_id": "dhcp6d13ba27-f5a3-57ff-8437-9fbb02a7daef-c16b9c17-a4c6-41ec-adcc-2800accbb727", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:fa:be:c8"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:02.181 [00;32mDEBUG nova.network.base_api [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mUpdating instance_info_cache with network_info: [VIF({'profile': {}, 'ovs_interfaceid': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'preserve_on_delete': False, 'network': Network({'bridge': 'br-int', 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'10.1.0.3'})], 'version': 4, 'meta': {'dhcp_server': u'10.1.0.2'}, 'dns': [], 'routes': [], 'cidr': u'10.1.0.0/24', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.1.0.1'})}), Subnet({'ips': [FixedIP({'meta': {}, 'version': 6, 'type': 'fixed', 'floating_ips': [], 'address': u'fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa'})], 'version': 6, 'meta': {'dhcp_server': u'fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8'}, 'dns': [], 'routes': [], 'cidr': u'fdbd:4e3b:ce09::/64', 'gateway': IP({'meta': {}, 'version': 6, 'type': 'gateway', 'address': u'fdbd:4e3b:ce09::1'})})], 'meta': {'injected': False, 'tenant_id': u'c392e44c09ce4cc9b3e77e79df76a81f'}, 'id': u'c16b9c17-a4c6-41ec-adcc-2800accbb727', 'label': u'private'}), 'devname': u'tapda4ab1e3-be', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True, u'ovs_hybrid_plug': True}, 'address': u'fa:16:3e:83:44:aa', 'active': True, 'type': u'ovs', 'id': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'qbg_params': None})][00m [00;33mfrom (pid=2811) update_instance_cache_with_nw_info /home/stack/src/cloud/nova/nova/network/base_api.py:43[00m
2015-09-26 08:52:02.201 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mReleasing semaphore "refresh_cache-3d6a16d5-6678-474e-9710-682473d1d98c"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:02.201 [00;32mDEBUG nova.objects.instance [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mLazy-loading `flavor' on Instance uuid 3d6a16d5-6678-474e-9710-682473d1d98c[00m [00;33mfrom (pid=2811) obj_load_attr /home/stack/src/cloud/nova/nova/objects/instance.py:845[00m
2015-09-26 08:52:02.282 [00;32mDEBUG nova.virt.libvirt.driver [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mmigrate_data in pre_live_migration: {u'disk_over_commit': False, u'disk_available_mb': 2048, u'image_type': u'default', u'is_shared_instance_path': False, u'filename': u'tmpQkTrUY', u'instance_relative_path': u'3d6a16d5-6678-474e-9710-682473d1d98c', u'block_migration': True, u'is_shared_block_storage': False, u'is_volume_backed': False, u'is_shared_storage': False}[00m [00;33mfrom (pid=2811) pre_live_migration /home/stack/src/cloud/nova/nova/virt/libvirt/driver.py:6140[00m
2015-09-26 08:52:02.283 [00;32mDEBUG nova.virt.libvirt.driver [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mCreating instance directory: /home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c[00m [00;33mfrom (pid=2811) pre_live_migration /home/stack/src/cloud/nova/nova/virt/libvirt/driver.py:6173[00m
2015-09-26 08:52:02.283 [00;32mDEBUG nova.virt.libvirt.driver [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mChecking to make sure images and backing files are present before live migration.[00m [00;33mfrom (pid=2811) pre_live_migration /home/stack/src/cloud/nova/nova/virt/libvirt/driver.py:6179[00m
2015-09-26 08:52:02.284 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mLock "/home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c/disk.info" acquired by "nova.virt.libvirt.imagebackend.write_to_disk_info_file" :: waited 0.000s[00m [00;33mfrom (pid=2811) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:253[00m
2015-09-26 08:52:02.285 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mLock "/home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c/disk.info" released by "nova.virt.libvirt.imagebackend.write_to_disk_info_file" :: held 0.001s[00m [00;33mfrom (pid=2811) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265[00m
2015-09-26 08:52:02.286 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): env LC_ALL=C LANG=C qemu-img info /home/stack/src/cloud/data/nova/instances/_base/7eb0bb2db79ba82008d71f9d6a295006c45db4ea[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:02.379 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "env LC_ALL=C LANG=C qemu-img info /home/stack/src/cloud/data/nova/instances/_base/7eb0bb2db79ba82008d71f9d6a295006c45db4ea" returned: 0 in 0.093s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:02.381 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mLock "7eb0bb2db79ba82008d71f9d6a295006c45db4ea" acquired by "nova.virt.libvirt.imagebackend.copy_qcow2_image" :: waited 0.000s[00m [00;33mfrom (pid=2811) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:253[00m
2015-09-26 08:52:02.381 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): env LC_ALL=C LANG=C qemu-img info /home/stack/src/cloud/data/nova/instances/_base/7eb0bb2db79ba82008d71f9d6a295006c45db4ea[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:02.471 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "env LC_ALL=C LANG=C qemu-img info /home/stack/src/cloud/data/nova/instances/_base/7eb0bb2db79ba82008d71f9d6a295006c45db4ea" returned: 0 in 0.090s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:02.473 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): qemu-img create -f qcow2 -o backing_file=/home/stack/src/cloud/data/nova/instances/_base/7eb0bb2db79ba82008d71f9d6a295006c45db4ea /home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c/disk[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:02.650 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "qemu-img create -f qcow2 -o backing_file=/home/stack/src/cloud/data/nova/instances/_base/7eb0bb2db79ba82008d71f9d6a295006c45db4ea /home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c/disk" returned: 0 in 0.177s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:02.651 [00;32mDEBUG nova.virt.disk.api [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mChecking if we can resize image /home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c/disk. size=1073741824[00m [00;33mfrom (pid=2811) can_resize_image /home/stack/src/cloud/nova/nova/virt/disk/api.py:229[00m
2015-09-26 08:52:02.652 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): env LC_ALL=C LANG=C qemu-img info /home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c/disk[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:02.747 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "env LC_ALL=C LANG=C qemu-img info /home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c/disk" returned: 0 in 0.095s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:02.748 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): qemu-img resize /home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c/disk 1073741824[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:02.949 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "qemu-img resize /home/stack/src/cloud/data/nova/instances/3d6a16d5-6678-474e-9710-682473d1d98c/disk 1073741824" returned: 0 in 0.201s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:02.951 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mLock "7eb0bb2db79ba82008d71f9d6a295006c45db4ea" released by "nova.virt.libvirt.imagebackend.copy_qcow2_image" :: held 0.570s[00m [00;33mfrom (pid=2811) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265[00m
2015-09-26 08:52:02.952 [00;32mDEBUG nova.virt.libvirt.driver [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mPlugging VIFs before live migration.[00m [00;33mfrom (pid=2811) pre_live_migration /home/stack/src/cloud/nova/nova/virt/libvirt/driver.py:6229[00m
2015-09-26 08:52:02.953 [00;32mDEBUG nova.virt.libvirt.vif [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mvif_type=ovs instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=False,availability_zone=None,cell_name=None,cleaned=True,config_drive='',created_at=2015-09-21T14:30:15Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,disable_terminate=False,display_description='vm1',display_name='vm1',ec2_ids=>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=>,flavor=Flavor(2),host='devstack1',hostname='vm1',id=1,image_ref='8a2538dc-00a2-42bf-9f9e-6747235ea0db',info_cache=InstanceInfoCache,instance_type_id=2,kernel_id='',key_data='ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCf2XROOJlSLcFyoGJYecfQGaVa8hSyrnvq4SyVkZ78IpLsgKDp1BoZl3pIHpjaHNPrxbsOaAGno2V/Ux+4JGku9cBrmHtDJ5CzPTE74uffqxayGeM0MYmcJ+Z5cGlQFUxLzYmhSnZtrT9jG+V2lu7HI+ORX6YKQaFlPCWWdTTt0Bty8jgVvAyc9L+isGYcouMWj8/CTWpY0UmIflNhuVeQl7LCG06DdohQtnEjUWrasgY8G8Cz0zIke6OWAzYREN+6L+M++D+9SvPFANdDJ0xV3RXp1FJ9iwNg6YUJrnq5f+nJol3GjwgegbMz6/eaOeiPpm5q0Ldg/wTez3SyBaPX Generated-by-Nova',key_name='oskey1',launch_index=0,launched_at=2015-09-21T14:30:26Z,launched_on='devstack1',locked=False,locked_by=None,memory_mb=512,metadata={},migration_context=>,new_flavor=None,node='devstack1',numa_topology=>,old_flavor=None,os_type=None,pci_devices=>,pci_requests=>,power_state=1,progress=0,project_id='c392e44c09ce4cc9b3e77e79df76a81f',ramdisk_id='',reservation_id='r-oi2xpo6i',root_device_name='/dev/vda',root_gb=1,security_groups=SecurityGroupList,shutdown_terminate=False,system_metadata={clean_attempts='2',image_base_image_ref='8a2538dc-00a2-42bf-9f9e-6747235ea0db',image_container_format='bare',image_disk_format='qcow2',image_min_disk='1',image_min_ram='0'},tags=>,task_state='migrating',terminated_at=None,updated_at=2015-09-26T12:47:29Z,user_data=None,user_id='0457270a4f9a461b8b3d6599ce31f96b',uuid=3d6a16d5-6678-474e-9710-682473d1d98c,vcpu_model=>,vcpus=1,vm_mode=None,vm_state='active') vif=VIF({'profile': {}, 'ovs_interfaceid': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'preserve_on_delete': False, 'network': Network({'bridge': 'br-int', 'subnets': [Subnet({'ips': [FixedIP({'version': 4, 'vif_mac': u'fa:16:3e:83:44:aa', 'floating_ips': [], 'label': u'private', 'meta': {}, 'address': u'10.1.0.3', 'type': 'fixed'})], 'version': 4, 'meta': {'dhcp_server': u'10.1.0.2'}, 'dns': [], 'routes': [], 'cidr': u'10.1.0.0/24', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.1.0.1'})}), Subnet({'ips': [FixedIP({'version': 6, 'vif_mac': u'fa:16:3e:83:44:aa', 'floating_ips': [], 'label': u'private', 'meta': {}, 'address': u'fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa', 'type': 'fixed'})], 'version': 6, 'meta': {'dhcp_server': u'fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8'}, 'dns': [], 'routes': [], 'cidr': u'fdbd:4e3b:ce09::/64', 'gateway': IP({'meta': {}, 'version': 6, 'type': 'gateway', 'address': u'fdbd:4e3b:ce09::1'})})], 'meta': {'injected': False, 'tenant_id': u'c392e44c09ce4cc9b3e77e79df76a81f'}, 'id': u'c16b9c17-a4c6-41ec-adcc-2800accbb727', 'label': u'private'}), 'devname': u'tapda4ab1e3-be', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True, u'ovs_hybrid_plug': True}, 'address': u'fa:16:3e:83:44:aa', 'active': True, 'type': u'ovs', 'id': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'qbg_params': None})[00m [00;33mfrom (pid=2811) plug /home/stack/src/cloud/nova/nova/virt/libvirt/vif.py:717[00m
2015-09-26 08:52:02.958 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf brctl addbr qbrda4ab1e3-be[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.069 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf brctl addbr qbrda4ab1e3-be" returned: 0 in 0.111s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.070 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf brctl setfd qbrda4ab1e3-be 0[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.154 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf brctl setfd qbrda4ab1e3-be 0" returned: 0 in 0.084s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.156 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf brctl stp qbrda4ab1e3-be off[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.235 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf brctl stp qbrda4ab1e3-be off" returned: 0 in 0.079s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.236 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf tee /sys/class/net/qbrda4ab1e3-be/bridge/multicast_snooping[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.314 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf tee /sys/class/net/qbrda4ab1e3-be/bridge/multicast_snooping" returned: 0 in 0.078s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.315 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf ip link add qvbda4ab1e3-be type veth peer name qvoda4ab1e3-be[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.416 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf ip link add qvbda4ab1e3-be type veth peer name qvoda4ab1e3-be" returned: 0 in 0.101s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.417 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvbda4ab1e3-be up[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.539 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvbda4ab1e3-be up" returned: 0 in 0.122s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.540 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvbda4ab1e3-be promisc on[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.637 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvbda4ab1e3-be promisc on" returned: 0 in 0.097s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.639 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvoda4ab1e3-be up[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.722 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvoda4ab1e3-be up" returned: 0 in 0.083s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.723 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvoda4ab1e3-be promisc on[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.802 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvoda4ab1e3-be promisc on" returned: 0 in 0.079s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.804 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qbrda4ab1e3-be up[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.887 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qbrda4ab1e3-be up" returned: 0 in 0.083s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:03.889 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf brctl addif qbrda4ab1e3-be qvbda4ab1e3-be[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:03.988 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf brctl addif qbrda4ab1e3-be qvbda4ab1e3-be" returned: 0 in 0.099s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:04.000 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRunning cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf ovs-vsctl --timeout=120 -- --if-exists del-port qvoda4ab1e3-be -- add-port br-int qvoda4ab1e3-be -- set Interface qvoda4ab1e3-be external-ids:iface-id=da4ab1e3-be0d-4c24-8a90-d863aa189577 external-ids:iface-status=active external-ids:attached-mac=fa:16:3e:83:44:aa external-ids:vm-uuid=3d6a16d5-6678-474e-9710-682473d1d98c[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:230[00m
2015-09-26 08:52:04.161 [00;32mDEBUG oslo_concurrency.processutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mCMD "sudo nova-rootwrap /etc/nova/rootwrap.conf ovs-vsctl --timeout=120 -- --if-exists del-port qvoda4ab1e3-be -- add-port br-int qvoda4ab1e3-be -- set Interface qvoda4ab1e3-be external-ids:iface-id=da4ab1e3-be0d-4c24-8a90-d863aa189577 external-ids:iface-status=active external-ids:attached-mac=fa:16:3e:83:44:aa external-ids:vm-uuid=3d6a16d5-6678-474e-9710-682473d1d98c" returned: 0 in 0.160s[00m [00;33mfrom (pid=2811) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:260[00m
2015-09-26 08:52:05.848 [00;32mDEBUG nova.virt.driver [[00;36m-[00;32m] [01;35m[00;32mEmitting event Started>[00m [00;33mfrom (pid=2811) emit_event /home/stack/src/cloud/nova/nova/virt/driver.py:1303[00m
2015-09-26 08:52:05.848 [00;36mINFO nova.compute.manager [[00;36m-[00;36m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;36mVM Started (Lifecycle Event)[00m
2015-09-26 08:52:06.133 [00;32mDEBUG nova.compute.manager [[01;36mreq-3d02fa4d-4d8f-4fbf-87bf-93a241b0506e [00;36mNone None[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mChecking state[00m [00;33mfrom (pid=2811) _get_power_state /home/stack/src/cloud/nova/nova/compute/manager.py:1328[00m
2015-09-26 08:52:08.147 [00;32mDEBUG nova.virt.driver [[01;36mreq-3d02fa4d-4d8f-4fbf-87bf-93a241b0506e [00;36mNone None[00;32m] [01;35m[00;32mEmitting event Resumed>[00m [00;33mfrom (pid=2811) emit_event /home/stack/src/cloud/nova/nova/virt/driver.py:1303[00m
2015-09-26 08:52:08.148 [00;36mINFO nova.compute.manager [[01;36mreq-3d02fa4d-4d8f-4fbf-87bf-93a241b0506e [00;36mNone None[00;36m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;36mVM Resumed (Lifecycle Event)[00m
2015-09-26 08:52:08.450 [00;32mDEBUG nova.compute.manager [[01;36mreq-3d02fa4d-4d8f-4fbf-87bf-93a241b0506e [00;36mNone None[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mChecking state[00m [00;33mfrom (pid=2811) _get_power_state /home/stack/src/cloud/nova/nova/compute/manager.py:1328[00m
2015-09-26 08:52:08.456 [00;32mDEBUG nova.compute.manager [[01;36mreq-3d02fa4d-4d8f-4fbf-87bf-93a241b0506e [00;36mNone None[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mSynchronizing instance power state after lifecycle event "Resumed"; current vm_state: active, current task_state: migrating, current DB power_state: 1, VM power_state: 1[00m [00;33mfrom (pid=2811) handle_lifecycle_event /home/stack/src/cloud/nova/nova/compute/manager.py:1257[00m
2015-09-26 08:52:08.614 [00;36mINFO nova.compute.manager [[01;36mreq-3d02fa4d-4d8f-4fbf-87bf-93a241b0506e [00;36mNone None[00;36m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;36mDuring the sync_power process the instance has moved from host devstack1 to host devstack2[00m
2015-09-26 08:52:10.794 [00;36mINFO nova.compute.manager [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;36m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;36mPost operation of migration started[00m
2015-09-26 08:52:10.795 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/extensions.json -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}1dfc72f2e3e9d672a27584e71053295433ff0461"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:10.805 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:10 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 4074 x-openstack-request-id: req-f2b37527-daec-4545-9f0f-9876d631b6ed
RESP BODY: {"extensions": [{"alias": "dns-integration", "updated": "2015-08-15T18:00:00-00:00", "name": "DNS Integration", "links": [], "description": "Provides integration with internal DNS."}, {"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": "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": "external-net", "updated": "2013-01-14T10:00:00-00:00", "name": "Neutron external network", "links": [], "description": "Adds external network attribute to network resource."}, {"alias": "flavors", "updated": "2014-07-06T10:00:00-00:00", "name": "Neutron Service Flavors", "links": [], "description": "Service specification for advanced services"}, {"alias": "net-mtu", "updated": "2015-03-25T10:00:00-00:00", "name": "Network MTU", "links": [], "description": "Provides MTU attribute for a network resource."}, {"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": "extraroute", "updated": "2013-02-01T10:00:00-00:00", "name": "Neutron Extra Route", "links": [], "description": "Extra routes configuration for L3 router"}, {"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": "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": "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": "rbac-policies", "updated": "2015-06-17T12:15:12-30:00", "name": "RBAC Policies", "links": [], "description": "Allows creation and modification of policies that control tenant access to resources."}, {"alias": "port-security", "updated": "2012-07-23T10:00:00-00:00", "name": "Port Security", "links": [], "description": "Provides port security"}, {"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."}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:10.807 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mAcquired semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:10.808 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mReleasing semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:10.809 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?tenant_id=c392e44c09ce4cc9b3e77e79df76a81f&device_id=3d6a16d5-6678-474e-9710-682473d1d98c -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:10.996 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:10 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1006 x-openstack-request-id: req-244776b7-315a-4251-b3fe-315774d08d45
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-3", "ip_address": "10.1.0.3", "fqdn": "host-10-1-0-3.openstacklocal."}], "device_owner": "compute:None", "port_security_enabled": true, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.3"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa"}], "id": "da4ab1e3-be0d-4c24-8a90-d863aa189577", "security_groups": ["81ff7d2b-1c00-4afb-ae1c-a73085b2ba65"], "device_id": "3d6a16d5-6678-474e-9710-682473d1d98c", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:83:44:aa"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:10.997 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X PUT http://192.169.143.120:9696/v2.0/ports/da4ab1e3-be0d-4c24-8a90-d863aa189577.json -H "User-Agent: python-neutronclient" -H "Content-Type: application/json" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643" -d '{"port": {"binding:host_id": "devstack2"}}'[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:11.958 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:11 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 885 x-openstack-request-id: req-2ce21579-28c0-4e5a-ad63-d094bad68211
RESP BODY: {"port": {"status": "ACTIVE", "binding:host_id": "devstack2", "allowed_address_pairs": [], "extra_dhcp_opts": [], "device_owner": "compute:None", "port_security_enabled": true, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.3"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa"}], "id": "da4ab1e3-be0d-4c24-8a90-d863aa189577", "security_groups": ["81ff7d2b-1c00-4afb-ae1c-a73085b2ba65"], "device_id": "3d6a16d5-6678-474e-9710-682473d1d98c", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:83:44:aa"}}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:11.959 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mAcquired semaphore "refresh_cache-3d6a16d5-6678-474e-9710-682473d1d98c"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:11.960 [00;32mDEBUG nova.network.neutronv2.api [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32m_get_instance_nw_info()[00m [00;33mfrom (pid=2811) _get_instance_nw_info /home/stack/src/cloud/nova/nova/network/neutronv2/api.py:922[00m
2015-09-26 08:52:12.009 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mAcquired semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:12.009 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mReleasing semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:12.010 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?tenant_id=c392e44c09ce4cc9b3e77e79df76a81f&device_id=3d6a16d5-6678-474e-9710-682473d1d98c -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:12.197 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:11 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1006 x-openstack-request-id: req-e93044ab-970a-438f-98c1-d7476eb022a8
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack2", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-3", "ip_address": "10.1.0.3", "fqdn": "host-10-1-0-3.openstacklocal."}], "device_owner": "compute:None", "port_security_enabled": true, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.3"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa"}], "id": "da4ab1e3-be0d-4c24-8a90-d863aa189577", "security_groups": ["81ff7d2b-1c00-4afb-ae1c-a73085b2ba65"], "device_id": "3d6a16d5-6678-474e-9710-682473d1d98c", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:83:44:aa"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:12.198 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/networks.json?id=c16b9c17-a4c6-41ec-adcc-2800accbb727 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}1dfc72f2e3e9d672a27584e71053295433ff0461"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:12.265 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:12 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 454 x-openstack-request-id: req-4d4174ae-9847-44ab-a009-b706750ba205
RESP BODY: {"networks": [{"status": "ACTIVE", "subnets": ["288075d8-b675-44d1-a50b-8832986c7d96", "ef534dcc-7e40-461c-865f-b64199d5a8a0"], "name": "private", "provider:physical_network": null, "admin_state_up": true, "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mtu": 0, "router:external": false, "shared": false, "port_security_enabled": true, "provider:network_type": "vxlan", "id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "provider:segmentation_id": 1041}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:12.267 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/floatingips.json?fixed_ip_address=10.1.0.3&port_id=da4ab1e3-be0d-4c24-8a90-d863aa189577 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:12.286 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:12 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 19 x-openstack-request-id: req-0b016bb9-3aba-49f7-89e4-73fe8e2cc51d
RESP BODY: {"floatingips": []}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:12.287 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/floatingips.json?fixed_ip_address=fdbd%3A4e3b%3Ace09%3A0%3Af816%3A3eff%3Afe83%3A44aa&port_id=da4ab1e3-be0d-4c24-8a90-d863aa189577 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:12.298 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:12 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 19 x-openstack-request-id: req-6a686eb8-448c-4117-ac7f-4d8a9ea8ca88
RESP BODY: {"floatingips": []}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:12.299 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/subnets.json?id=288075d8-b675-44d1-a50b-8832986c7d96&id=ef534dcc-7e40-461c-865f-b64199d5a8a0 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}1dfc72f2e3e9d672a27584e71053295433ff0461"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:12.346 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:12 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 964 x-openstack-request-id: req-b8f97bb6-200b-411b-8e91-5b3f7c88e571
RESP BODY: {"subnets": [{"name": "private-subnet", "enable_dhcp": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "dns_nameservers": [], "gateway_ip": "10.1.0.1", "ipv6_ra_mode": null, "allocation_pools": [{"start": "10.1.0.2", "end": "10.1.0.254"}], "host_routes": [], "ip_version": 4, "ipv6_address_mode": null, "cidr": "10.1.0.0/24", "id": "288075d8-b675-44d1-a50b-8832986c7d96", "subnetpool_id": null}, {"name": "ipv6-private-subnet", "enable_dhcp": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "dns_nameservers": [], "gateway_ip": "fdbd:4e3b:ce09::1", "ipv6_ra_mode": "slaac", "allocation_pools": [{"start": "fdbd:4e3b:ce09::2", "end": "fdbd:4e3b:ce09:0:ffff:ffff:ffff:ffff"}], "host_routes": [], "ip_version": 6, "ipv6_address_mode": "slaac", "cidr": "fdbd:4e3b:ce09::/64", "id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "subnetpool_id": null}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:12.348 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?network_id=c16b9c17-a4c6-41ec-adcc-2800accbb727&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}1dfc72f2e3e9d672a27584e71053295433ff0461"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:12.435 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:12 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1010 x-openstack-request-id: req-68fc567d-6b93-4d5f-8457-215734fae961
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-2", "ip_address": "10.1.0.2", "fqdn": "host-10-1-0-2.openstacklocal."}], "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.2"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8"}], "id": "22c20e9c-12e9-4b52-9103-fca0e9a47013", "security_groups": [], "device_id": "dhcp6d13ba27-f5a3-57ff-8437-9fbb02a7daef-c16b9c17-a4c6-41ec-adcc-2800accbb727", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:fa:be:c8"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:12.436 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?network_id=c16b9c17-a4c6-41ec-adcc-2800accbb727&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}1dfc72f2e3e9d672a27584e71053295433ff0461"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:12.522 [00;32mDEBUG keystoneclient.session [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:12 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1010 x-openstack-request-id: req-fc826a32-8771-49bd-9390-dc55fd8fb822
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-2", "ip_address": "10.1.0.2", "fqdn": "host-10-1-0-2.openstacklocal."}], "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.2"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8"}], "id": "22c20e9c-12e9-4b52-9103-fca0e9a47013", "security_groups": [], "device_id": "dhcp6d13ba27-f5a3-57ff-8437-9fbb02a7daef-c16b9c17-a4c6-41ec-adcc-2800accbb727", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:fa:be:c8"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:12.524 [00;32mDEBUG nova.network.base_api [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mUpdating instance_info_cache with network_info: [VIF({'profile': {}, 'ovs_interfaceid': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'preserve_on_delete': False, 'network': Network({'bridge': 'br-int', 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'10.1.0.3'})], 'version': 4, 'meta': {'dhcp_server': u'10.1.0.2'}, 'dns': [], 'routes': [], 'cidr': u'10.1.0.0/24', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.1.0.1'})}), Subnet({'ips': [FixedIP({'meta': {}, 'version': 6, 'type': 'fixed', 'floating_ips': [], 'address': u'fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa'})], 'version': 6, 'meta': {'dhcp_server': u'fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8'}, 'dns': [], 'routes': [], 'cidr': u'fdbd:4e3b:ce09::/64', 'gateway': IP({'meta': {}, 'version': 6, 'type': 'gateway', 'address': u'fdbd:4e3b:ce09::1'})})], 'meta': {'injected': False, 'tenant_id': u'c392e44c09ce4cc9b3e77e79df76a81f'}, 'id': u'c16b9c17-a4c6-41ec-adcc-2800accbb727', 'label': u'private'}), 'devname': u'tapda4ab1e3-be', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True, u'ovs_hybrid_plug': True}, 'address': u'fa:16:3e:83:44:aa', 'active': True, 'type': u'ovs', 'id': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'qbg_params': None})][00m [00;33mfrom (pid=2811) update_instance_cache_with_nw_info /home/stack/src/cloud/nova/nova/network/base_api.py:43[00m
2015-09-26 08:52:12.547 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mReleasing semaphore "refresh_cache-3d6a16d5-6678-474e-9710-682473d1d98c"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:12.565 [00;32mDEBUG nova.block_device [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mblock_device_list [][00m [00;33mfrom (pid=2811) volume_in_mapping /home/stack/src/cloud/nova/nova/block_device.py:584[00m
2015-09-26 08:52:12.566 [00;32mDEBUG nova.virt.libvirt.driver [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mStart _get_guest_xml network_info=[VIF({'profile': {}, 'ovs_interfaceid': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'preserve_on_delete': False, 'network': Network({'bridge': 'br-int', 'subnets': [Subnet({'ips': [FixedIP({'version': 4, 'vif_mac': u'fa:16:3e:83:44:aa', 'floating_ips': [], 'label': u'private', 'meta': {}, 'address': u'10.1.0.3', 'type': 'fixed'})], 'version': 4, 'meta': {'dhcp_server': u'10.1.0.2'}, 'dns': [], 'routes': [], 'cidr': u'10.1.0.0/24', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.1.0.1'})}), Subnet({'ips': [FixedIP({'version': 6, 'vif_mac': u'fa:16:3e:83:44:aa', 'floating_ips': [], 'label': u'private', 'meta': {}, 'address': u'fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa', 'type': 'fixed'})], 'version': 6, 'meta': {'dhcp_server': u'fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8'}, 'dns': [], 'routes': [], 'cidr': u'fdbd:4e3b:ce09::/64', 'gateway': IP({'meta': {}, 'version': 6, 'type': 'gateway', 'address': u'fdbd:4e3b:ce09::1'})})], 'meta': {'injected': False, 'tenant_id': u'c392e44c09ce4cc9b3e77e79df76a81f'}, 'id': u'c16b9c17-a4c6-41ec-adcc-2800accbb727', 'label': u'private'}), 'devname': u'tapda4ab1e3-be', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True, u'ovs_hybrid_plug': True}, 'address': u'fa:16:3e:83:44:aa', 'active': True, 'type': u'ovs', 'id': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'qbg_params': None})] disk_info={'disk_bus': 'virtio', 'cdrom_bus': 'ide', 'mapping': {'disk': {'bus': 'virtio', 'boot_index': '1', 'type': 'disk', 'dev': u'vda'}, 'root': {'bus': 'virtio', 'boot_index': '1', 'type': 'disk', 'dev': u'vda'}}} image_meta=ImageMeta(checksum=>,container_format='bare',created_at=>,direct_url=>,disk_format='qcow2',id=>,min_disk=1,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': []}[00m [00;33mfrom (pid=2811) _get_guest_xml /home/stack/src/cloud/nova/nova/virt/libvirt/driver.py:4320[00m
2015-09-26 08:52:12.567 [00;32mDEBUG nova.objects.instance [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mLazy-loading `pci_devices' on Instance uuid 3d6a16d5-6678-474e-9710-682473d1d98c[00m [00;33mfrom (pid=2811) obj_load_attr /home/stack/src/cloud/nova/nova/objects/instance.py:845[00m
2015-09-26 08:52:12.672 [00;32mDEBUG nova.objects.instance [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mLazy-loading `numa_topology' on Instance uuid 3d6a16d5-6678-474e-9710-682473d1d98c[00m [00;33mfrom (pid=2811) obj_load_attr /home/stack/src/cloud/nova/nova/objects/instance.py:845[00m
2015-09-26 08:52:12.705 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mGetting desirable topologies for flavor Flavor(created_at=None,deleted=False,deleted_at=None,disabled=False,ephemeral_gb=0,extra_specs={},flavorid='1',id=2,is_public=True,memory_mb=512,name='m1.tiny',projects=>,root_gb=1,rxtx_factor=1.0,swap=0,updated_at=None,vcpu_weight=0,vcpus=1) and image_meta ImageMeta(checksum=>,container_format='bare',created_at=>,direct_url=>,disk_format='qcow2',id=>,min_disk=1,min_ram=0,name=>,owner=>,properties=ImageMetaProps,protected=>,size=>,status=>,tags=>,updated_at=>,virtual_size=>,visibility=>), allow threads: True[00m [00;33mfrom (pid=2811) _get_desirable_cpu_topologies /home/stack/src/cloud/nova/nova/virt/hardware.py:564[00m
2015-09-26 08:52:12.706 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mFlavor limits 65536:65536:65536[00m [00;33mfrom (pid=2811) _get_cpu_topology_constraints /home/stack/src/cloud/nova/nova/virt/hardware.py:308[00m
2015-09-26 08:52:12.707 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mImage limits 65536:65536:65536[00m [00;33mfrom (pid=2811) _get_cpu_topology_constraints /home/stack/src/cloud/nova/nova/virt/hardware.py:319[00m
2015-09-26 08:52:12.708 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mFlavor pref -1:-1:-1[00m [00;33mfrom (pid=2811) _get_cpu_topology_constraints /home/stack/src/cloud/nova/nova/virt/hardware.py:342[00m
2015-09-26 08:52:12.708 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mImage pref -1:-1:-1[00m [00;33mfrom (pid=2811) _get_cpu_topology_constraints /home/stack/src/cloud/nova/nova/virt/hardware.py:361[00m
2015-09-26 08:52:12.709 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mChosen -1:-1:-1 limits 65536:65536:65536[00m [00;33mfrom (pid=2811) _get_cpu_topology_constraints /home/stack/src/cloud/nova/nova/virt/hardware.py:390[00m
2015-09-26 08:52:12.709 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mTopology preferred VirtCPUTopology(cores=-1,sockets=-1,threads=-1), maximum VirtCPUTopology(cores=65536,sockets=65536,threads=65536)[00m [00;33mfrom (pid=2811) _get_desirable_cpu_topologies /home/stack/src/cloud/nova/nova/virt/hardware.py:568[00m
2015-09-26 08:52:12.710 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mBuild topologies for 1 vcpu(s) 1:1:1[00m [00;33mfrom (pid=2811) _get_possible_cpu_topologies /home/stack/src/cloud/nova/nova/virt/hardware.py:429[00m
2015-09-26 08:52:12.710 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mGot 1 possible topologies[00m [00;33mfrom (pid=2811) _get_possible_cpu_topologies /home/stack/src/cloud/nova/nova/virt/hardware.py:456[00m
2015-09-26 08:52:12.711 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mPossible topologies [VirtCPUTopology(cores=1,sockets=1,threads=1)][00m [00;33mfrom (pid=2811) _get_desirable_cpu_topologies /home/stack/src/cloud/nova/nova/virt/hardware.py:573[00m
2015-09-26 08:52:12.711 [00;32mDEBUG nova.virt.hardware [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mSorted desired topologies [VirtCPUTopology(cores=1,sockets=1,threads=1)][00m [00;33mfrom (pid=2811) _get_desirable_cpu_topologies /home/stack/src/cloud/nova/nova/virt/hardware.py:598[00m
2015-09-26 08:52:12.712 [00;32mDEBUG nova.objects.instance [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mLazy-loading `vcpu_model' on Instance uuid 3d6a16d5-6678-474e-9710-682473d1d98c[00m [00;33mfrom (pid=2811) obj_load_attr /home/stack/src/cloud/nova/nova/objects/instance.py:845[00m
2015-09-26 08:52:12.733 [00;32mDEBUG nova.virt.libvirt.driver [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mPath '/home/stack/src/cloud/data/nova/instances' supports direct I/O[00m [00;33mfrom (pid=2811) _supports_direct_io /home/stack/src/cloud/nova/nova/virt/libvirt/driver.py:2619[00m
2015-09-26 08:52:12.736 [00;32mDEBUG nova.virt.libvirt.vif [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mvif_type=ovs instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=False,availability_zone=None,cell_name=None,cleaned=True,config_drive='',created_at=2015-09-21T14:30:15Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,disable_terminate=False,display_description='vm1',display_name='vm1',ec2_ids=>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=>,flavor=Flavor(2),host='devstack1',hostname='vm1',id=1,image_ref='8a2538dc-00a2-42bf-9f9e-6747235ea0db',info_cache=InstanceInfoCache,instance_type_id=2,kernel_id='',key_data='ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCf2XROOJlSLcFyoGJYecfQGaVa8hSyrnvq4SyVkZ78IpLsgKDp1BoZl3pIHpjaHNPrxbsOaAGno2V/Ux+4JGku9cBrmHtDJ5CzPTE74uffqxayGeM0MYmcJ+Z5cGlQFUxLzYmhSnZtrT9jG+V2lu7HI+ORX6YKQaFlPCWWdTTt0Bty8jgVvAyc9L+isGYcouMWj8/CTWpY0UmIflNhuVeQl7LCG06DdohQtnEjUWrasgY8G8Cz0zIke6OWAzYREN+6L+M++D+9SvPFANdDJ0xV3RXp1FJ9iwNg6YUJrnq5f+nJol3GjwgegbMz6/eaOeiPpm5q0Ldg/wTez3SyBaPX Generated-by-Nova',key_name='oskey1',launch_index=0,launched_at=2015-09-21T14:30:26Z,launched_on='devstack1',locked=False,locked_by=None,memory_mb=512,metadata={},migration_context=>,new_flavor=None,node='devstack1',numa_topology=None,old_flavor=None,os_type=None,pci_devices=PciDeviceList,pci_requests=>,power_state=1,progress=0,project_id='c392e44c09ce4cc9b3e77e79df76a81f',ramdisk_id='',reservation_id='r-oi2xpo6i',root_device_name='/dev/vda',root_gb=1,security_groups=SecurityGroupList,shutdown_terminate=False,system_metadata={clean_attempts='2',image_base_image_ref='8a2538dc-00a2-42bf-9f9e-6747235ea0db',image_container_format='bare',image_disk_format='qcow2',image_min_disk='1',image_min_ram='0'},tags=>,task_state='migrating',terminated_at=None,updated_at=2015-09-26T12:51:59Z,user_data=None,user_id='0457270a4f9a461b8b3d6599ce31f96b',uuid=3d6a16d5-6678-474e-9710-682473d1d98c,vcpu_model=VirtCPUModel,vcpus=1,vm_mode=None,vm_state='active') vif=VIF({'profile': {}, 'ovs_interfaceid': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'preserve_on_delete': False, 'network': Network({'bridge': 'br-int', 'subnets': [Subnet({'ips': [FixedIP({'version': 4, 'vif_mac': u'fa:16:3e:83:44:aa', 'floating_ips': [], 'label': u'private', 'meta': {}, 'address': u'10.1.0.3', 'type': 'fixed'})], 'version': 4, 'meta': {'dhcp_server': u'10.1.0.2'}, 'dns': [], 'routes': [], 'cidr': u'10.1.0.0/24', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.1.0.1'})}), Subnet({'ips': [FixedIP({'version': 6, 'vif_mac': u'fa:16:3e:83:44:aa', 'floating_ips': [], 'label': u'private', 'meta': {}, 'address': u'fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa', 'type': 'fixed'})], 'version': 6, 'meta': {'dhcp_server': u'fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8'}, 'dns': [], 'routes': [], 'cidr': u'fdbd:4e3b:ce09::/64', 'gateway': IP({'meta': {}, 'version': 6, 'type': 'gateway', 'address': u'fdbd:4e3b:ce09::1'})})], 'meta': {'injected': False, 'tenant_id': u'c392e44c09ce4cc9b3e77e79df76a81f'}, 'id': u'c16b9c17-a4c6-41ec-adcc-2800accbb727', 'label': u'private'}), 'devname': u'tapda4ab1e3-be', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True, u'ovs_hybrid_plug': True}, 'address': u'fa:16:3e:83:44:aa', 'active': True, 'type': u'ovs', 'id': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'qbg_params': None}) virt_typekvm[00m [00;33mfrom (pid=2811) get_config /home/stack/src/cloud/nova/nova/virt/libvirt/vif.py:448[00m
2015-09-26 08:52:12.740 [00;32mDEBUG nova.virt.libvirt.config [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[00;32mGenerated XML ('\n 3d6a16d5-6678-474e-9710-682473d1d98c\n instance-00000001\n 524288\n 1\n \n \n \n vm1\n 2015-09-26 12:52:12\n \n 512\n 1\n 0\n 0\n 1\n \n \n admin\n demo\n \n \n \n \n \n \n OpenStack Foundation\n OpenStack Nova\n 12.0.0\n 464493d4-7872-43c0-b9c2-5f5085d5dc5b\n 3d6a16d5-6678-474e-9710-682473d1d98c\n Virtual Machine\n \n \n \n hvm\n \n \n \n \n \n \n \n \n 1024\n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n \n\n',) [00m [00;33mfrom (pid=2811) to_xml /home/stack/src/cloud/nova/nova/virt/libvirt/config.py:82[00m
2015-09-26 08:52:12.741 [00;32mDEBUG nova.virt.libvirt.driver [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mEnd _get_guest_xml xml=
3d6a16d5-6678-474e-9710-682473d1d98c
instance-00000001
524288
1
vm1
2015-09-26 12:52:12
512
1
0
0
1
admin
demo
OpenStack Foundation
OpenStack Nova
12.0.0
464493d4-7872-43c0-b9c2-5f5085d5dc5b
3d6a16d5-6678-474e-9710-682473d1d98c
Virtual Machine
hvm
1024
[00m [00;33mfrom (pid=2811) _get_guest_xml /home/stack/src/cloud/nova/nova/virt/libvirt/driver.py:4332[00m
2015-09-26 08:52:12.802 [00;32mDEBUG nova.compute.manager [[01;36mreq-166192f8-72f2-4967-a4ff-608fd6455917 [00;36madmin demo[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mChecking state[00m [00;33mfrom (pid=2811) _get_power_state /home/stack/src/cloud/nova/nova/compute/manager.py:1328[00m
2015-09-26 08:52:14.455 [00;32mDEBUG nova.compute.manager [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mReceived event network-changed[00m [00;33mfrom (pid=2811) external_instance_event /home/stack/src/cloud/nova/nova/compute/manager.py:6376[00m
2015-09-26 08:52:14.456 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mAcquired semaphore "refresh_cache-3d6a16d5-6678-474e-9710-682473d1d98c"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:14.457 [00;32mDEBUG nova.network.neutronv2.api [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32m_get_instance_nw_info()[00m [00;33mfrom (pid=2811) _get_instance_nw_info /home/stack/src/cloud/nova/nova/network/neutronv2/api.py:922[00m
2015-09-26 08:52:14.489 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mAcquired semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:14.490 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mReleasing semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:14.491 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?tenant_id=c392e44c09ce4cc9b3e77e79df76a81f&device_id=3d6a16d5-6678-474e-9710-682473d1d98c -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:14.656 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:14 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1006 x-openstack-request-id: req-62673df0-5584-4888-b648-a586b591657d
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack2", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-3", "ip_address": "10.1.0.3", "fqdn": "host-10-1-0-3.openstacklocal."}], "device_owner": "compute:None", "port_security_enabled": true, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.3"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa"}], "id": "da4ab1e3-be0d-4c24-8a90-d863aa189577", "security_groups": ["81ff7d2b-1c00-4afb-ae1c-a73085b2ba65"], "device_id": "3d6a16d5-6678-474e-9710-682473d1d98c", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:83:44:aa"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:14.657 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/networks.json?id=c16b9c17-a4c6-41ec-adcc-2800accbb727 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}63b5ff8c3561146933098ebb9f44b37be371b5e5"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:14.825 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:14 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 454 x-openstack-request-id: req-4f5b1a38-6352-49d3-93ab-300ffae6f376
RESP BODY: {"networks": [{"status": "ACTIVE", "subnets": ["ef534dcc-7e40-461c-865f-b64199d5a8a0", "288075d8-b675-44d1-a50b-8832986c7d96"], "name": "private", "provider:physical_network": null, "admin_state_up": true, "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mtu": 0, "router:external": false, "shared": false, "port_security_enabled": true, "provider:network_type": "vxlan", "id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "provider:segmentation_id": 1041}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:14.826 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/floatingips.json?fixed_ip_address=10.1.0.3&port_id=da4ab1e3-be0d-4c24-8a90-d863aa189577 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:14.846 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:14 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 19 x-openstack-request-id: req-f01c160f-8712-4955-b230-f4c16e5f5674
RESP BODY: {"floatingips": []}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:14.847 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/floatingips.json?fixed_ip_address=fdbd%3A4e3b%3Ace09%3A0%3Af816%3A3eff%3Afe83%3A44aa&port_id=da4ab1e3-be0d-4c24-8a90-d863aa189577 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:14.869 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:14 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 19 x-openstack-request-id: req-be6e821a-ae06-40fd-9755-916898c4d6be
RESP BODY: {"floatingips": []}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:14.870 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/subnets.json?id=288075d8-b675-44d1-a50b-8832986c7d96&id=ef534dcc-7e40-461c-865f-b64199d5a8a0 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}63b5ff8c3561146933098ebb9f44b37be371b5e5"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:14.929 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:14 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 964 x-openstack-request-id: req-ba965ead-cdee-4fcc-a733-6c0d106422e0
RESP BODY: {"subnets": [{"name": "private-subnet", "enable_dhcp": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "dns_nameservers": [], "gateway_ip": "10.1.0.1", "ipv6_ra_mode": null, "allocation_pools": [{"start": "10.1.0.2", "end": "10.1.0.254"}], "host_routes": [], "ip_version": 4, "ipv6_address_mode": null, "cidr": "10.1.0.0/24", "id": "288075d8-b675-44d1-a50b-8832986c7d96", "subnetpool_id": null}, {"name": "ipv6-private-subnet", "enable_dhcp": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "dns_nameservers": [], "gateway_ip": "fdbd:4e3b:ce09::1", "ipv6_ra_mode": "slaac", "allocation_pools": [{"start": "fdbd:4e3b:ce09::2", "end": "fdbd:4e3b:ce09:0:ffff:ffff:ffff:ffff"}], "host_routes": [], "ip_version": 6, "ipv6_address_mode": "slaac", "cidr": "fdbd:4e3b:ce09::/64", "id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "subnetpool_id": null}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:14.930 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?network_id=c16b9c17-a4c6-41ec-adcc-2800accbb727&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}63b5ff8c3561146933098ebb9f44b37be371b5e5"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:15.034 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:14 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1010 x-openstack-request-id: req-7994d591-6659-4b07-8f33-b4a3cfba82c2
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-2", "ip_address": "10.1.0.2", "fqdn": "host-10-1-0-2.openstacklocal."}], "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.2"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8"}], "id": "22c20e9c-12e9-4b52-9103-fca0e9a47013", "security_groups": [], "device_id": "dhcp6d13ba27-f5a3-57ff-8437-9fbb02a7daef-c16b9c17-a4c6-41ec-adcc-2800accbb727", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:fa:be:c8"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:15.036 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?network_id=c16b9c17-a4c6-41ec-adcc-2800accbb727&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}63b5ff8c3561146933098ebb9f44b37be371b5e5"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:15.115 [00;32mDEBUG keystoneclient.session [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:14 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1010 x-openstack-request-id: req-4a02477e-9b36-48de-9d44-300f7e732ef1
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-2", "ip_address": "10.1.0.2", "fqdn": "host-10-1-0-2.openstacklocal."}], "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.2"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8"}], "id": "22c20e9c-12e9-4b52-9103-fca0e9a47013", "security_groups": [], "device_id": "dhcp6d13ba27-f5a3-57ff-8437-9fbb02a7daef-c16b9c17-a4c6-41ec-adcc-2800accbb727", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:fa:be:c8"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:15.117 [00;32mDEBUG nova.network.base_api [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mUpdating instance_info_cache with network_info: [VIF({'profile': {}, 'ovs_interfaceid': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'preserve_on_delete': False, 'network': Network({'bridge': 'br-int', 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'10.1.0.3'})], 'version': 4, 'meta': {'dhcp_server': u'10.1.0.2'}, 'dns': [], 'routes': [], 'cidr': u'10.1.0.0/24', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.1.0.1'})}), Subnet({'ips': [FixedIP({'meta': {}, 'version': 6, 'type': 'fixed', 'floating_ips': [], 'address': u'fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa'})], 'version': 6, 'meta': {'dhcp_server': u'fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8'}, 'dns': [], 'routes': [], 'cidr': u'fdbd:4e3b:ce09::/64', 'gateway': IP({'meta': {}, 'version': 6, 'type': 'gateway', 'address': u'fdbd:4e3b:ce09::1'})})], 'meta': {'injected': False, 'tenant_id': u'c392e44c09ce4cc9b3e77e79df76a81f'}, 'id': u'c16b9c17-a4c6-41ec-adcc-2800accbb727', 'label': u'private'}), 'devname': u'tapda4ab1e3-be', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {u'port_filter': True, u'ovs_hybrid_plug': True}, 'address': u'fa:16:3e:83:44:aa', 'active': True, 'type': u'ovs', 'id': u'da4ab1e3-be0d-4c24-8a90-d863aa189577', 'qbg_params': None})][00m [00;33mfrom (pid=2811) update_instance_cache_with_nw_info /home/stack/src/cloud/nova/nova/network/base_api.py:43[00m
2015-09-26 08:52:15.141 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-09a789e6-139c-4ffa-bda5-a3ae9a0f6011 [00;36mnova service[00;32m] [01;35m[00;32mReleasing semaphore "refresh_cache-3d6a16d5-6678-474e-9710-682473d1d98c"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:16.386 [00;32mDEBUG nova.compute.manager [[01;36mreq-4ab48438-31bc-4046-b783-a7b1aea2d306 [00;36mnova service[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mReceived event network-vif-plugged-da4ab1e3-be0d-4c24-8a90-d863aa189577[00m [00;33mfrom (pid=2811) external_instance_event /home/stack/src/cloud/nova/nova/compute/manager.py:6376[00m
2015-09-26 08:52:16.387 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-4ab48438-31bc-4046-b783-a7b1aea2d306 [00;36mnova service[00;32m] [01;35m[00;32mLock "3d6a16d5-6678-474e-9710-682473d1d98c-events" acquired by "nova.compute.manager._pop_event" :: waited 0.000s[00m [00;33mfrom (pid=2811) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:253[00m
2015-09-26 08:52:16.387 [00;32mDEBUG nova.compute.manager [[01;36mreq-4ab48438-31bc-4046-b783-a7b1aea2d306 [00;36mnova service[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mUnexpected attempt to pop events during shutdown[00m [00;33mfrom (pid=2811) _pop_event /home/stack/src/cloud/nova/nova/compute/manager.py:527[00m
2015-09-26 08:52:16.388 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-4ab48438-31bc-4046-b783-a7b1aea2d306 [00;36mnova service[00;32m] [01;35m[00;32mLock "3d6a16d5-6678-474e-9710-682473d1d98c-events" released by "nova.compute.manager._pop_event" :: held 0.001s[00m [00;33mfrom (pid=2811) inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265[00m
2015-09-26 08:52:16.388 [00;32mDEBUG nova.compute.manager [[01;36mreq-4ab48438-31bc-4046-b783-a7b1aea2d306 [00;36mnova service[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32mNo waiting events found dispatching network-vif-plugged-da4ab1e3-be0d-4c24-8a90-d863aa189577[00m [00;33mfrom (pid=2811) pop_instance_event /home/stack/src/cloud/nova/nova/compute/manager.py:543[00m
2015-09-26 08:52:19.143 [00;32mDEBUG oslo_service.periodic_task [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRunning periodic task ComputeManager._poll_unconfirmed_resizes[00m [00;33mfrom (pid=2811) run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:213[00m
2015-09-26 08:52:23.143 [00;32mDEBUG oslo_service.periodic_task [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRunning periodic task ComputeManager._poll_rebooting_instances[00m [00;33mfrom (pid=2811) run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:213[00m
2015-09-26 08:52:26.142 [00;32mDEBUG oslo_service.periodic_task [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRunning periodic task ComputeManager._heal_instance_info_cache[00m [00;33mfrom (pid=2811) run_periodic_tasks /usr/lib/python2.7/site-packages/oslo_service/periodic_task.py:213[00m
2015-09-26 08:52:26.142 [00;32mDEBUG nova.compute.manager [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mStarting heal instance info cache[00m [00;33mfrom (pid=2811) _heal_instance_info_cache /home/stack/src/cloud/nova/nova/compute/manager.py:5412[00m
2015-09-26 08:52:26.143 [00;32mDEBUG nova.compute.manager [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRebuilding the list of instances to heal[00m [00;33mfrom (pid=2811) _heal_instance_info_cache /home/stack/src/cloud/nova/nova/compute/manager.py:5416[00m
2015-09-26 08:52:26.202 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mAcquired semaphore "refresh_cache-3d6a16d5-6678-474e-9710-682473d1d98c"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:26.203 [00;32mDEBUG nova.network.neutronv2.api [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[instance: 3d6a16d5-6678-474e-9710-682473d1d98c] [00;32m_get_instance_nw_info()[00m [00;33mfrom (pid=2811) _get_instance_nw_info /home/stack/src/cloud/nova/nova/network/neutronv2/api.py:922[00m
2015-09-26 08:52:26.204 [00;32mDEBUG nova.objects.instance [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mLazy-loading `info_cache' on Instance uuid 3d6a16d5-6678-474e-9710-682473d1d98c[00m [00;33mfrom (pid=2811) obj_load_attr /home/stack/src/cloud/nova/nova/objects/instance.py:845[00m
2015-09-26 08:52:26.301 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mAcquired semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:26.302 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mReleasing semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:26.303 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?tenant_id=c392e44c09ce4cc9b3e77e79df76a81f&device_id=3d6a16d5-6678-474e-9710-682473d1d98c -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:26.395 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:26 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1006 x-openstack-request-id: req-d6cb2408-31ce-469f-aefe-a8377f09de17
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack2", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-3", "ip_address": "10.1.0.3", "fqdn": "host-10-1-0-3.openstacklocal."}], "device_owner": "compute:None", "port_security_enabled": true, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.3"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fe83:44aa"}], "id": "da4ab1e3-be0d-4c24-8a90-d863aa189577", "security_groups": ["81ff7d2b-1c00-4afb-ae1c-a73085b2ba65"], "device_id": "3d6a16d5-6678-474e-9710-682473d1d98c", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:83:44:aa"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:26.396 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mAcquired semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:26.397 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mReleasing semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:26.397 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/networks.json?id=c16b9c17-a4c6-41ec-adcc-2800accbb727 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:26.436 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:26 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 454 x-openstack-request-id: req-54d98049-c920-4976-a060-cfe6b3a8ddb6
RESP BODY: {"networks": [{"status": "ACTIVE", "subnets": ["288075d8-b675-44d1-a50b-8832986c7d96", "ef534dcc-7e40-461c-865f-b64199d5a8a0"], "name": "private", "provider:physical_network": null, "admin_state_up": true, "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mtu": 0, "router:external": false, "shared": false, "port_security_enabled": true, "provider:network_type": "vxlan", "id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "provider:segmentation_id": 1041}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:26.437 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/floatingips.json?fixed_ip_address=10.1.0.3&port_id=da4ab1e3-be0d-4c24-8a90-d863aa189577 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:26.449 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:26 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 19 x-openstack-request-id: req-8abcf86b-bac9-4ee9-8a2b-ed5fe6acb056
RESP BODY: {"floatingips": []}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:26.450 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/floatingips.json?fixed_ip_address=fdbd%3A4e3b%3Ace09%3A0%3Af816%3A3eff%3Afe83%3A44aa&port_id=da4ab1e3-be0d-4c24-8a90-d863aa189577 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:26.467 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:26 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 19 x-openstack-request-id: req-f9eb795a-e9b7-499f-894b-d2b29fae8513
RESP BODY: {"floatingips": []}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:26.468 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mAcquired semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:26.469 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mReleasing semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:26.470 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/subnets.json?id=288075d8-b675-44d1-a50b-8832986c7d96&id=ef534dcc-7e40-461c-865f-b64199d5a8a0 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:26.518 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:26 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 964 x-openstack-request-id: req-1e12ae25-cb8a-493f-b4a0-0ac4dae6f34e
RESP BODY: {"subnets": [{"name": "private-subnet", "enable_dhcp": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "dns_nameservers": [], "gateway_ip": "10.1.0.1", "ipv6_ra_mode": null, "allocation_pools": [{"start": "10.1.0.2", "end": "10.1.0.254"}], "host_routes": [], "ip_version": 4, "ipv6_address_mode": null, "cidr": "10.1.0.0/24", "id": "288075d8-b675-44d1-a50b-8832986c7d96", "subnetpool_id": null}, {"name": "ipv6-private-subnet", "enable_dhcp": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "dns_nameservers": [], "gateway_ip": "fdbd:4e3b:ce09::1", "ipv6_ra_mode": "slaac", "allocation_pools": [{"start": "fdbd:4e3b:ce09::2", "end": "fdbd:4e3b:ce09:0:ffff:ffff:ffff:ffff"}], "host_routes": [], "ip_version": 6, "ipv6_address_mode": "slaac", "cidr": "fdbd:4e3b:ce09::/64", "id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "subnetpool_id": null}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:26.519 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mAcquired semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:26.520 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mReleasing semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:26.521 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?network_id=c16b9c17-a4c6-41ec-adcc-2800accbb727&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:26.623 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:26 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1010 x-openstack-request-id: req-b72c7169-3628-49fa-8625-3e8004c8a450
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-2", "ip_address": "10.1.0.2", "fqdn": "host-10-1-0-2.openstacklocal."}], "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.2"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8"}], "id": "22c20e9c-12e9-4b52-9103-fca0e9a47013", "security_groups": [], "device_id": "dhcp6d13ba27-f5a3-57ff-8437-9fbb02a7daef-c16b9c17-a4c6-41ec-adcc-2800accbb727", "name": "", "admin_state_up": true, "network_id": "c16b9c17-a4c6-41ec-adcc-2800accbb727", "dns_name": "", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "c392e44c09ce4cc9b3e77e79df76a81f", "mac_address": "fa:16:3e:fa:be:c8"}]}
[00m [00;33mfrom (pid=2811) _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215[00m
2015-09-26 08:52:26.624 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mAcquired semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198[00m
2015-09-26 08:52:26.625 [00;32mDEBUG oslo_concurrency.lockutils [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mReleasing semaphore "neutron_admin_auth_token_lock"[00m [00;33mfrom (pid=2811) lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211[00m
2015-09-26 08:52:26.626 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mREQ: curl -g -i -X GET http://192.169.143.120:9696/v2.0/ports.json?network_id=c16b9c17-a4c6-41ec-adcc-2800accbb727&device_owner=network%3Adhcp -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}c1352f1d1baaa74f1a64a38d127d0dd3b76ab643"[00m [00;33mfrom (pid=2811) _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198[00m
2015-09-26 08:52:26.721 [00;32mDEBUG keystoneclient.session [[01;36mreq-f8952808-bb0c-4052-ac05-720c0a7744b8 [00;36mNone None[00;32m] [01;35m[00;32mRESP: [200] date: Sat, 26 Sep 2015 12:52:26 GMT connection: keep-alive content-type: application/json; charset=UTF-8 content-length: 1010 x-openstack-request-id: req-be9d024b-53c3-4539-a70b-cc453d1237a9
RESP BODY: {"ports": [{"status": "ACTIVE", "binding:host_id": "devstack1", "allowed_address_pairs": [], "extra_dhcp_opts": [], "dns_assignment": [{"hostname": "host-10-1-0-2", "ip_address": "10.1.0.2", "fqdn": "host-10-1-0-2.openstacklocal."}], "device_owner": "network:dhcp", "port_security_enabled": false, "binding:profile": {}, "fixed_ips": [{"subnet_id": "288075d8-b675-44d1-a50b-8832986c7d96", "ip_address": "10.1.0.2"}, {"subnet_id": "ef534dcc-7e40-461c-865f-b64199d5a8a0", "ip_address": "fdbd:4e3b:ce09:0:f816:3eff:fefa:bec8"}], "id": "22c20e9c-12e9-4b52-9103-fca0e9a47013", "security_groups": [], "device_i