source('F:/works.sinorail/operationlog/code/function.R')
Plog<-read_lines("G:/ztx/T2works/log/192.168.17.23/nova/nova-compute.log")
Plog<-paste.log(Plog)
Plog %>% grep("req-afa41633-f929-46b5-918c-e4ce717e8c4f",.,value = T)## [1] "2019-03-11 15:04:47.690 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"71e57a77-729f-4613-9e97-b4f63f9028d7\" acquired by \"nova.compute.manager._locked_do_build_and_run_instance\" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:253"
## [2] "2019-03-11 15:04:47.701 2303 INFO nova.compute.manager [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Starting instance..."
## [3] "2019-03-11 15:04:47.820 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"compute_resources\" acquired by \"nova.compute.resource_tracker.instance_claim\" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:253"
## [4] "2019-03-11 15:04:47.821 2303 DEBUG nova.compute.resource_tracker [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Memory overhead for 64 MB instance; 0 MB instance_claim /usr/lib/python2.7/site-packages/nova/compute/resource_tracker.py:170"
## [5] "2019-03-11 15:04:47.826 2303 INFO nova.compute.claims [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Attempting claim: memory 64 MB, disk 1 GB"
## [6] "2019-03-11 15:04:47.826 2303 INFO nova.compute.claims [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Total memory: 131043 MB, used: 98816.00 MB"
## [7] "2019-03-11 15:04:47.826 2303 INFO nova.compute.claims [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] memory limit: 131043.00 MB, free: 32227.00 MB"
## [8] "2019-03-11 15:04:47.827 2303 INFO nova.compute.claims [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Total disk: 60470 GB, used: 940.00 GB"
## [9] "2019-03-11 15:04:47.827 2303 INFO nova.compute.claims [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] disk limit not specified, defaulting to unlimited"
## [10] "2019-03-11 15:04:47.837 2303 DEBUG nova.compute.resources.vcpu [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Total CPUs: 32 VCPUs, used: 32.00 VCPUs test /usr/lib/python2.7/site-packages/nova/compute/resources/vcpu.py:52"
## [11] "2019-03-11 15:04:47.837 2303 DEBUG nova.compute.resources.vcpu [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] CPUs limit: 64.00 VCPUs, free: 32.00 VCPUs test /usr/lib/python2.7/site-packages/nova/compute/resources/vcpu.py:63"
## [12] "2019-03-11 15:04:47.838 2303 INFO nova.compute.claims [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Claim successful"
## [13] "2019-03-11 15:04:48.038 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"compute_resources\" released by \"nova.compute.resource_tracker.instance_claim\" :: held 0.218s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265"
## [14] "2019-03-11 15:04:48.149 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"compute_resources\" acquired by \"nova.compute.resource_tracker.update_usage\" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:253"
## [15] "2019-03-11 15:04:48.192 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"compute_resources\" released by \"nova.compute.resource_tracker.update_usage\" :: held 0.043s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265"
## [16] "2019-03-11 15:04:48.213 2303 DEBUG nova.block_device [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] block_device_list [] volume_in_mapping /usr/lib/python2.7/site-packages/nova/block_device.py:584"
## [17] "2019-03-11 15:04:48.444 2303 DEBUG nova.block_device [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] block_device_list [] volume_in_mapping /usr/lib/python2.7/site-packages/nova/block_device.py:584"
## [18] "2019-03-11 15:04:48.445 2303 INFO nova.virt.libvirt.driver [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Creating image"
## [19] "2019-03-11 15:04:48.477 2303 DEBUG nova.virt.libvirt.storage.rbd_utils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] rbd image 71e57a77-729f-4613-9e97-b4f63f9028d7_disk does not exist __init__ /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:67"
## [20] "2019-03-11 15:04:48.510 2303 DEBUG nova.virt.libvirt.storage.rbd_utils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] rbd image 71e57a77-729f-4613-9e97-b4f63f9028d7_disk does not exist __init__ /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:67"
## [21] "2019-03-11 15:04:48.513 2303 DEBUG fasteners.process_lock [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Acquired file lock `/var/lib/nova/instances/locks/nova-9d45a4c93703e50806334b135f1ab2e41b9cca30` after waiting 0.000s [1 attempts were required] acquire /usr/lib/python2.7/site-packages/fasteners/process_lock.py:163"
## [22] "2019-03-11 15:04:48.513 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"9d45a4c93703e50806334b135f1ab2e41b9cca30\" acquired by \"nova.virt.libvirt.imagebackend.fetch_func_sync\" :: waited 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:253"
## [23] "2019-03-11 15:04:48.664 2303 DEBUG nova.virt.libvirt.imagebackend [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Image locations are: [{u'url': u'rbd://8feb6dad-9ac9-4a0f-bb85-bbcafa906938/images/ad5af451-9bd2-47a8-8cde-50934b0d3bdf/snap', u'metadata': {}}, {'url': u'rbd://8feb6dad-9ac9-4a0f-bb85-bbcafa906938/images/ad5af451-9bd2-47a8-8cde-50934b0d3bdf/snap', 'metadata': {}}] clone /usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py:859"
## [24] "2019-03-11 15:04:48.810 2303 DEBUG nova.virt.libvirt.storage.rbd_utils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] cloning images/ad5af451-9bd2-47a8-8cde-50934b0d3bdf@snap to None/71e57a77-729f-4613-9e97-b4f63f9028d7_disk clone /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:221"
## [25] "2019-03-11 15:04:49.101 2303 DEBUG fasteners.process_lock [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Unlocked and closed file lock open on `/var/lib/nova/instances/locks/nova-9d45a4c93703e50806334b135f1ab2e41b9cca30` release /usr/lib/python2.7/site-packages/fasteners/process_lock.py:193"
## [26] "2019-03-11 15:04:49.104 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"9d45a4c93703e50806334b135f1ab2e41b9cca30\" released by \"nova.virt.libvirt.imagebackend.fetch_func_sync\" :: held 0.591s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265"
## [27] "2019-03-11 15:04:49.247 2303 DEBUG nova.virt.libvirt.storage.rbd_utils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] resizing rbd image 71e57a77-729f-4613-9e97-b4f63f9028d7_disk to 1073741824 resize /usr/lib/python2.7/site-packages/nova/virt/libvirt/storage/rbd_utils.py:245"
## [28] "2019-03-11 15:04:49.350 2303 INFO nova.virt.libvirt.driver [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Using config drive"
## [29] "2019-03-11 15:04:49.384 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Acquired semaphore \"neutron_admin_auth_token_lock\" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198"
## [30] "2019-03-11 15:04:49.385 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Releasing semaphore \"neutron_admin_auth_token_lock\" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211"
## [31] "2019-03-11 15:04:49.386 2303 DEBUG keystoneclient.session [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] REQ: curl -g -i -X GET http://192.168.17.102:9696/v2.0/ports.json?device_id=71e57a77-729f-4613-9e97-b4f63f9028d7 -H \"User-Agent: python-neutronclient\" -H \"Accept: application/json\" -H \"X-Auth-Token: {SHA1}b72e4de93e67b6ada54eeb71b1e03c8e1729126e\" _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198"
## [32] "2019-03-11 15:04:49.517 2303 DEBUG keystoneclient.session [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] RESP: [200] date: Mon, 11 Mar 2019 07:04:49 GMT connection: close content-type: application/json; charset=UTF-8 content-length: 903 x-openstack-request-id: req-c2422394-7839-46ae-89d5-3993590136c8 RESP BODY: {\"ports\": [{\"status\": \"DOWN\", \"binding:host_id\": \"compute7\", \"allowed_address_pairs\": [], \"extra_dhcp_opts\": [], \"dns_assignment\": [{\"hostname\": \"host-10-1-2-5\", \"ip_address\": \"10.1.2.5\", \"fqdn\": \"host-10-1-2-5.openstacklocal.\"}], \"device_owner\": \"compute:xkjtest:default_cluster\", \"port_security_enabled\": true, \"binding:profile\": {}, \"qos_policy_id\": null, \"fixed_ips\": [{\"subnet_id\": \"3468c599-c78b-4dea-a413-ab086b1f69e1\", \"ip_address\": \"10.1.2.5\"}], \"id\": \"beefc468-9316-4264-80bd-fef4c13899ca\", \"security_groups\": [\"737f063f-7aa9-4041-8129-2df5f1634525\"], \"device_id\": \"71e57a77-729f-4613-9e97-b4f63f9028d7\", \"name\": \"\", \"admin_state_up\": true, \"network_id\": \"4436194a-71da-431c-88b4-17b29b701355\", \"dns_name\": \"\", \"binding:vif_details\": {}, \"binding:vnic_type\": \"normal\", \"binding:vif_type\": \"binding_failed\", \"tenant_id\": \"c5a56983ad334846acf1b89d9fd01b4d\", \"mac_address\": \"fa:16:3e:d4:91:be\"}]} _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215"
## [33] "2019-03-11 15:04:49.518 2303 DEBUG keystoneclient.session [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] REQ: curl -g -i -X GET http://192.168.17.102:9696/v2.0/security-groups.json?id=737f063f-7aa9-4041-8129-2df5f1634525 -H \"User-Agent: python-neutronclient\" -H \"Accept: application/json\" -H \"X-Auth-Token: {SHA1}b72e4de93e67b6ada54eeb71b1e03c8e1729126e\" _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198"
## [34] "2019-03-11 15:04:49.550 2303 DEBUG keystoneclient.session [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] RESP: [200] date: Mon, 11 Mar 2019 07:04:49 GMT connection: close content-type: application/json; charset=UTF-8 content-length: 1491 x-openstack-request-id: req-d813215f-f676-479d-9cca-2de2a0b493d8 RESP BODY: {\"security_groups\": [{\"tenant_id\": \"c5a56983ad334846acf1b89d9fd01b4d\", \"description\": \"Default security group\", \"id\": \"737f063f-7aa9-4041-8129-2df5f1634525\", \"security_group_rules\": [{\"remote_group_id\": null, \"direction\": \"ingress\", \"remote_ip_prefix\": \"::/0\", \"protocol\": null, \"ethertype\": \"IPv6\", \"tenant_id\": \"c5a56983ad334846acf1b89d9fd01b4d\", \"port_range_max\": null, \"port_range_min\": null, \"id\": \"19f16e01-299d-491e-ad7f-edeea3b78073\", \"security_group_id\": \"737f063f-7aa9-4041-8129-2df5f1634525\"}, {\"remote_group_id\": null, \"direction\": \"egress\", \"remote_ip_prefix\": null, \"protocol\": null, \"ethertype\": \"IPv6\", \"tenant_id\": \"c5a56983ad334846acf1b89d9fd01b4d\", \"port_range_max\": null, \"port_range_min\": null, \"id\": \"35a3e4cf-476b-4a78-af26-931ecfbe3611\", \"security_group_id\": \"737f063f-7aa9-4041-8129-2df5f1634525\"}, {\"remote_group_id\": null, \"direction\": \"ingress\", \"remote_ip_prefix\": \"0.0.0.0/0\", \"protocol\": null, \"ethertype\": \"IPv4\", \"tenant_id\": \"c5a56983ad334846acf1b89d9fd01b4d\", \"port_range_max\": null, \"port_range_min\": null, \"id\": \"483cf29d-c5d2-405b-af0c-0815fe7a836e\", \"security_group_id\": \"737f063f-7aa9-4041-8129-2df5f1634525\"}, {\"remote_group_id\": null, \"direction\": \"egress\", \"remote_ip_prefix\": null, \"protocol\": null, \"ethertype\": \"IPv4\", \"tenant_id\": \"c5a56983ad334846acf1b89d9fd01b4d\", \"port_range_max\": null, \"port_range_min\": null, \"id\": \"e23a0ce5-d246-4330-9a36-00b0c4322a51\", \"security_group_id\": \"737f063f-7aa9-4041-8129-2df5f1634525\"}], \"name\": \"default\"}]} _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215"
## [35] "2019-03-11 15:04:59.843 2303 ERROR nova.compute.manager [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Instance failed to spawn"
## [36] "2019-03-11 15:04:59.873 2303 INFO nova.compute.manager [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Terminating instance"
## [37] "2019-03-11 15:04:59.982 2303 DEBUG oslo_concurrency.processutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Running cmd (subprocess): mv /var/lib/nova/instances/71e57a77-729f-4613-9e97-b4f63f9028d7 /var/lib/nova/instances/71e57a77-729f-4613-9e97-b4f63f9028d7_del execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:297"
## [38] "2019-03-11 15:05:00.004 2303 DEBUG oslo_concurrency.processutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] CMD \"mv /var/lib/nova/instances/71e57a77-729f-4613-9e97-b4f63f9028d7 /var/lib/nova/instances/71e57a77-729f-4613-9e97-b4f63f9028d7_del\" returned: 0 in 0.022s execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:327"
## [39] "2019-03-11 15:05:00.005 2303 INFO nova.virt.libvirt.driver [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Deleting instance files /var/lib/nova/instances/71e57a77-729f-4613-9e97-b4f63f9028d7_del"
## [40] "2019-03-11 15:05:00.005 2303 INFO nova.virt.libvirt.driver [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Deletion of /var/lib/nova/instances/71e57a77-729f-4613-9e97-b4f63f9028d7_del complete"
## [41] "2019-03-11 15:05:00.143 2303 DEBUG nova.compute.manager [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Deallocating network for instance _deallocate_network /usr/lib/python2.7/site-packages/nova/compute/manager.py:1840"
## [42] "2019-03-11 15:05:00.144 2303 DEBUG nova.network.neutronv2.api [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] deallocate_for_instance() deallocate_for_instance /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:837"
## [43] "2019-03-11 15:05:00.145 2303 DEBUG keystoneclient.session [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] REQ: curl -g -i -X GET http://192.168.17.102:9696/v2.0/ports.json?device_id=71e57a77-729f-4613-9e97-b4f63f9028d7 -H \"User-Agent: python-neutronclient\" -H \"Accept: application/json\" -H \"X-Auth-Token: {SHA1}e8e0d4b9e85d7808088da406c8443e1fededdf65\" _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198"
## [44] "2019-03-11 15:05:00.179 2303 DEBUG keystoneclient.session [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] RESP: [200] date: Mon, 11 Mar 2019 07:05:00 GMT connection: close content-type: application/json; charset=UTF-8 content-length: 13 x-openstack-request-id: req-03e76d1d-df2d-44e9-a1cd-9e76edae668c RESP BODY: {\"ports\": []} _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215"
## [45] "2019-03-11 15:05:00.180 2303 DEBUG nova.network.neutronv2.api [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1702"
## [46] "2019-03-11 15:05:00.181 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Acquired semaphore \"neutron_admin_auth_token_lock\" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198"
## [47] "2019-03-11 15:05:00.181 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Releasing semaphore \"neutron_admin_auth_token_lock\" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211"
## [48] "2019-03-11 15:05:00.182 2303 DEBUG nova.network.base_api [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:43"
## [49] "2019-03-11 15:05:00.194 2303 DEBUG nova.compute.claims [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Aborting claim: [Claim: 64 MB memory, 1 GB disk] abort /usr/lib/python2.7/site-packages/nova/compute/claims.py:112"
## [50] "2019-03-11 15:05:00.194 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"compute_resources\" acquired by \"nova.compute.resource_tracker.abort_instance_claim\" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:253"
## [51] "2019-03-11 15:05:00.241 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"compute_resources\" released by \"nova.compute.resource_tracker.abort_instance_claim\" :: held 0.046s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265"
## [52] "2019-03-11 15:05:00.242 2303 DEBUG nova.compute.utils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Binding failed for port 0468e30a-15cb-47f5-b8f6-3be344d053b9, please check neutron logs for more information. notify_about_instance_usage /usr/lib/python2.7/site-packages/nova/compute/utils.py:284"
## [53] "2019-03-11 15:05:00.247 2303 DEBUG nova.compute.manager [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Retry info not present, will not reschedule _do_build_and_run_instance /usr/lib/python2.7/site-packages/nova/compute/manager.py:1944"
## [54] "2019-03-11 15:05:00.247 2303 DEBUG nova.compute.manager [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Deallocating network for instance _deallocate_network /usr/lib/python2.7/site-packages/nova/compute/manager.py:1840"
## [55] "2019-03-11 15:05:00.247 2303 DEBUG nova.network.neutronv2.api [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] deallocate_for_instance() deallocate_for_instance /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:837"
## [56] "2019-03-11 15:05:00.248 2303 DEBUG keystoneclient.session [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] REQ: curl -g -i -X GET http://192.168.17.102:9696/v2.0/ports.json?device_id=71e57a77-729f-4613-9e97-b4f63f9028d7 -H \"User-Agent: python-neutronclient\" -H \"Accept: application/json\" -H \"X-Auth-Token: {SHA1}e8e0d4b9e85d7808088da406c8443e1fededdf65\" _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:198"
## [57] "2019-03-11 15:05:00.281 2303 DEBUG keystoneclient.session [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] RESP: [200] date: Mon, 11 Mar 2019 07:05:00 GMT connection: close content-type: application/json; charset=UTF-8 content-length: 13 x-openstack-request-id: req-b6f53e3c-ede3-4545-b370-20298e55109d RESP BODY: {\"ports\": []} _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:215"
## [58] "2019-03-11 15:05:00.281 2303 DEBUG nova.network.neutronv2.api [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Instance cache missing network info. _get_preexisting_port_ids /usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1702"
## [59] "2019-03-11 15:05:00.282 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Acquired semaphore \"neutron_admin_auth_token_lock\" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:198"
## [60] "2019-03-11 15:05:00.282 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Releasing semaphore \"neutron_admin_auth_token_lock\" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:211"
## [61] "2019-03-11 15:05:00.283 2303 DEBUG nova.network.base_api [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] [instance: 71e57a77-729f-4613-9e97-b4f63f9028d7] Updating instance_info_cache with network_info: [] update_instance_cache_with_nw_info /usr/lib/python2.7/site-packages/nova/network/base_api.py:43"
## [62] "2019-03-11 15:05:00.561 2303 DEBUG oslo_concurrency.lockutils [req-afa41633-f929-46b5-918c-e4ce717e8c4f 24d2188097bd4ac1a1c9b3ce2198d892 c5a56983ad334846acf1b89d9fd01b4d - - -] Lock \"71e57a77-729f-4613-9e97-b4f63f9028d7\" released by \"nova.compute.manager._locked_do_build_and_run_instance\" :: held 12.871s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265"