O032、Nova reboot 和 lock 操作
前面通过日志详细分析了 nova 的 launch、shutoff 、start 操作。
本节来体验两个比较简单的操作：reboot 和 lock/unlock 。
Soft/Hard Reboot
soft reboot 与 hard reboot 的区别在于：
1、soft reboot 只是重启操作系统，整个过程中，instance 依然处于运行状态。相当于在linux中执行reboot
2、hard reboot 是重启 instance ，相当于关机之后再开机
ps：
1、reboot 操作的日志在 n-api.log 中找不到，因为这个操作不输出日志，但是也可以通过 过滤关键字 reboot 找到蛛丝马迹
2、但是在n-cpu.log 日志中可以找到 soft reboot 或者 hard reboot相关的日志
Lock / Unlock
为了避免误操作，比如以外重启或删除 instance，可以将 instance 加锁。
对于被加锁（Lock）的instance执行重启等改变状态的操作都是无效的。只有解锁（Unlock）后才可以。Lock 和 Unlock 都是nova-api负责的，所以只查看 n-api.log 就可以了 。
注意：
1、admin 角色的用户不受 lock 的影响，无论锁不锁都能执行重启等操作
2、根据默认 policy的配置，任何用户都可以 unlock 。也就是说如果发现 instance 被加锁了，所有人都可以进行 Unlock解锁，然后进行操作
soft reboot
root@DevStack-Controller:/opt/stack/logs# cat n-api.log | grep req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b
2019-05-23 23:17:19.857 DEBUG nova.api.openstack.wsgi [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] Action: 'action', calling method: <bound method ServersController._action_reboot of <nova.api.openstack.compute.servers.ServersController object at 0x7fb2f89b4fd0>>, body: {"reboot": {"type": "SOFT"}} from (pid=28283) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:623
2019-05-23 23:17:19.860 DEBUG nova.compute.api [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Fetching instance by UUID from (pid=28283) get /opt/stack/nova/nova/compute/api.py:2397
2019-05-23 23:17:19.866 DEBUG oslo_concurrency.lockutils [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] Lock "5fd8cdfc-e20e-46da-8c1a-88e1c5ce2790" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s from (pid=28283) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:270
2019-05-23 23:17:19.867 DEBUG oslo_concurrency.lockutils [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] Lock "5fd8cdfc-e20e-46da-8c1a-88e1c5ce2790" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.000s from (pid=28283) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282
2019-05-23 23:17:20.037 DEBUG oslo_messaging._drivers.amqpdriver [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] CAST unique_id: 436d8df770e34a06a85abec51663e586 exchange 'nova' topic 'compute.DevStack-Controller' from (pid=28283) _send /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:550
2019-05-23 23:17:20.039 INFO nova.osapi_compute.wsgi.server [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] 10.12.31.241 "POST /v2.1/servers/a0e2b485-f40c-43e4-beb6-049b6399f0ec/action HTTP/1.1" status: 202 len: 337 time: 0.2120390
root@DevStack-Controller:/opt/stack/logs# cat n-cpu.log | grep req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b | grep -v oslo
2019-05-23 23:17:20.089 INFO nova.compute.manager [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Rebooting instance
2019-05-23 23:17:20.106 DEBUG nova.network.neutronv2.api [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] _get_instance_nw_info() from (pid=4613) _get_instance_nw_info /opt/stack/nova/nova/network/neutronv2/api.py:1295
2019-05-23 23:17:20.194 DEBUG neutronclient.v2_0.client [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/ports.json?tenant_id=c2b9e5f4a15d43218f3fca6e13c49a3a&device_id=a0e2b485-f40c-43e4-beb6-049b6399f0ec used request id req-92ffcc5f-9f68-4a36-ab20-5daa5c974427 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:17:20.321 DEBUG neutronclient.v2_0.client [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/networks.json?id=32740d6a-8119-4c8e-9828-fe5da5b6e7ac used request id req-f5ec5270-a132-46b6-8db2-6f7c47739b2f from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:17:20.369 DEBUG neutronclient.v2_0.client [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/floatingips.json?fixed_ip_address=172.24.4.16&port_id=ef41d30d-862f-4342-919a-95ed7a0587e3 used request id req-b06eccba-f6fb-4a71-975b-94c6c01b23ec from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:17:20.421 DEBUG neutronclient.v2_0.client [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/floatingips.json?fixed_ip_address=2001%3Adb8%3A%3A3&port_id=ef41d30d-862f-4342-919a-95ed7a0587e3 used request id req-0248b249-3c33-47c3-b572-653584f928a3 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:17:20.499 DEBUG neutronclient.v2_0.client [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/subnets.json?id=ad734c80-f28b-42d4-8b58-ddcec7bdb594&id=72d0d730-4827-47b5-b98e-bd5c0108f3c9 used request id req-f66c5445-4381-406f-8f25-6fd1739ad638 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:17:20.563 DEBUG neutronclient.v2_0.client [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/ports.json?network_id=32740d6a-8119-4c8e-9828-fe5da5b6e7ac&device_owner=network%3Adhcp used request id req-4ef4b60c-c06b-45f2-8676-45230b6c01eb from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:17:20.630 DEBUG neutronclient.v2_0.client [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/ports.json?network_id=32740d6a-8119-4c8e-9828-fe5da5b6e7ac&device_owner=network%3Adhcp used request id req-15dd6956-204a-4d01-b815-943169c3ae8c from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:17:20.631 DEBUG nova.network.base_api [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Updating instance_info_cache with network_info: [{"profile": {}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": "brq32740d6a-81", "subnets": [{"ips": [{"meta": {}, "version": 6, "type": "fixed", "floating_ips": [], "address": "2001:db8::3"}], "version": 6, "meta": {}, "dns": [], "routes": [], "cidr": "2001:db8::/64", "gateway": {"meta": {}, "version": 6, "type": "gateway", "address": "2001:db8::2"}}, {"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "172.24.4.16"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "172.24.4.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "172.24.4.1"}}], "meta": {"injected": false, "tenant_id": "c2b9e5f4a15d43218f3fca6e13c49a3a", "should_create_bridge": true, "mtu": 1500}, "id": "32740d6a-8119-4c8e-9828-fe5da5b6e7ac", "label": "public"}, "devname": "tapef41d30d-86", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true}, "address": "fa:16:3e:7c:d6:21", "active": true, "type": "bridge", "id": "ef41d30d-862f-4342-919a-95ed7a0587e3", "qbg_params": null}] from (pid=4613) update_instance_cache_with_nw_info /opt/stack/nova/nova/network/base_api.py:48
2019-05-23 23:17:20.655 DEBUG nova.compute.manager [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Checking state from (pid=4613) _get_power_state /opt/stack/nova/nova/compute/manager.py:1184
2019-05-23 23:17:23.893 INFO nova.virt.libvirt.driver [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Instance shutdown successfully.
2019-05-23 23:17:25.921 INFO nova.virt.libvirt.driver [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Instance soft rebooted successfully.
2019-05-23 23:17:25.922 DEBUG nova.compute.manager [req-fbec4b4e-b9a5-48ed-bf5d-9c2c5f57ba8b admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Checking state from (pid=4613) _get_power_state /opt/stack/nova/nova/compute/manager.py:1184
hard reboot
root@DevStack-Controller:/opt/stack/logs# cat n-api.log | grep req-5a5313c8-d588-4c85-a599-2763cd6489e3
2019-05-23 23:22:13.600 DEBUG nova.api.openstack.wsgi [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Action: 'action', calling method: <bound method ServersController._action_reboot of <nova.api.openstack.compute.servers.ServersController object at 0x7fb2f89b4fd0>>, body: {"reboot": {"type": "HARD"}} from (pid=28282) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:623
2019-05-23 23:22:13.603 DEBUG nova.compute.api [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Fetching instance by UUID from (pid=28282) get /opt/stack/nova/nova/compute/api.py:2397
2019-05-23 23:22:13.609 DEBUG oslo_concurrency.lockutils [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Lock "5fd8cdfc-e20e-46da-8c1a-88e1c5ce2790" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s from (pid=28282) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:270
2019-05-23 23:22:13.610 DEBUG oslo_concurrency.lockutils [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Lock "5fd8cdfc-e20e-46da-8c1a-88e1c5ce2790" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.000s from (pid=28282) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282
2019-05-23 23:22:13.741 DEBUG oslo_messaging._drivers.amqpdriver [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] CAST unique_id: ad6d7c3a6ff74aa39c108676cbbe098b exchange 'nova' topic 'compute.DevStack-Controller' from (pid=28282) _send /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:550
2019-05-23 23:22:13.744 INFO nova.osapi_compute.wsgi.server [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] 10.12.31.241 "POST /v2.1/servers/a0e2b485-f40c-43e4-beb6-049b6399f0ec/action HTTP/1.1" status: 202 len: 337 time: 0.1711242
root@DevStack-Controller:/opt/stack/logs# cat n-cpu.log | grep req-5a5313c8-d588-4c85-a599-2763cd6489e3 | grep -v oslo | grep -v os_brick
2019-05-23 23:22:13.778 INFO nova.compute.manager [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Rebooting instance
2019-05-23 23:22:13.789 DEBUG nova.network.neutronv2.api [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] _get_instance_nw_info() from (pid=4613) _get_instance_nw_info /opt/stack/nova/nova/network/neutronv2/api.py:1295
2019-05-23 23:22:13.885 DEBUG neutronclient.v2_0.client [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/ports.json?tenant_id=c2b9e5f4a15d43218f3fca6e13c49a3a&device_id=a0e2b485-f40c-43e4-beb6-049b6399f0ec used request id req-94b0d9ba-6d15-4ac0-8ec8-de74d5c7d5d0 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:22:14.011 DEBUG neutronclient.v2_0.client [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/networks.json?id=32740d6a-8119-4c8e-9828-fe5da5b6e7ac used request id req-91838cca-50c7-4dd3-a8e4-1e14058aee83 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:22:14.059 DEBUG neutronclient.v2_0.client [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/floatingips.json?fixed_ip_address=172.24.4.16&port_id=ef41d30d-862f-4342-919a-95ed7a0587e3 used request id req-35b35eb3-1acd-40f7-9716-3003488931a9 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:22:14.134 DEBUG neutronclient.v2_0.client [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/floatingips.json?fixed_ip_address=2001%3Adb8%3A%3A3&port_id=ef41d30d-862f-4342-919a-95ed7a0587e3 used request id req-bc35a896-8736-4844-890e-3856a11fa776 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:22:14.241 DEBUG neutronclient.v2_0.client [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/subnets.json?id=ad734c80-f28b-42d4-8b58-ddcec7bdb594&id=72d0d730-4827-47b5-b98e-bd5c0108f3c9 used request id req-9a6c02a3-d6d2-4f82-862c-5e0b018980b9 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:22:14.403 DEBUG neutronclient.v2_0.client [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/ports.json?network_id=32740d6a-8119-4c8e-9828-fe5da5b6e7ac&device_owner=network%3Adhcp used request id req-526db7b4-1d62-4f47-ab5f-e356c7569651 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:22:14.466 DEBUG neutronclient.v2_0.client [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/ports.json?network_id=32740d6a-8119-4c8e-9828-fe5da5b6e7ac&device_owner=network%3Adhcp used request id req-adcf531e-233c-4842-a50a-035cb2d39461 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:22:14.467 DEBUG nova.network.base_api [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Updating instance_info_cache with network_info: [{"profile": {}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": "brq32740d6a-81", "subnets": [{"ips": [{"meta": {}, "version": 6, "type": "fixed", "floating_ips": [], "address": "2001:db8::3"}], "version": 6, "meta": {}, "dns": [], "routes": [], "cidr": "2001:db8::/64", "gateway": {"meta": {}, "version": 6, "type": "gateway", "address": "2001:db8::2"}}, {"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "172.24.4.16"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "172.24.4.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "172.24.4.1"}}], "meta": {"injected": false, "tenant_id": "c2b9e5f4a15d43218f3fca6e13c49a3a", "should_create_bridge": true, "mtu": 1500}, "id": "32740d6a-8119-4c8e-9828-fe5da5b6e7ac", "label": "public"}, "devname": "tapef41d30d-86", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true}, "address": "fa:16:3e:7c:d6:21", "active": true, "type": "bridge", "id": "ef41d30d-862f-4342-919a-95ed7a0587e3", "qbg_params": null}] from (pid=4613) update_instance_cache_with_nw_info /opt/stack/nova/nova/network/base_api.py:48
2019-05-23 23:22:14.486 DEBUG nova.compute.manager [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Checking state from (pid=4613) _get_power_state /opt/stack/nova/nova/compute/manager.py:1184
2019-05-23 23:22:15.610 DEBUG nova.virt.libvirt.vif [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] vif_type=bridge instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=True,availability_zone='nova',cell_name=None,cleaned=True,config_drive='',created_at=2019-05-23T08:34:42Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,device_metadata=<?>,disable_terminate=False,display_description='admin-test03',display_name='admin-test03',ec2_ids=<?>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,flavor=Flavor(1),host='DevStack-Controller',hostname='admin-test03',id=3,image_ref='',info_cache=InstanceInfoCache,instance_type_id=1,kernel_id='c3f9bfb6-f089-4a0a-b410-e128284761f8',key_data=None,key_name=None,keypairs=<?>,launch_index=0,launched_at=2019-05-23T08:35:24Z,launched_on='DevStack-Controller',locked=False,locked_by=None,memory_mb=256,metadata={},migration_context=<?>,new_flavor=None,node='DevStack-Controller',numa_topology=None,old_flavor=None,os_type=None,pci_devices=PciDeviceList,pci_requests=<?>,power_state=1,progress=0,project_id='c2b9e5f4a15d43218f3fca6e13c49a3a',ramdisk_id='16b087bd-8aa5-48fa-968b-6d8986ee2434',reservation_id='r-m4xc1dvw',root_device_name='/dev/vda',root_gb=0,security_groups=SecurityGroupList,services=<?>,shutdown_terminate=False,system_metadata={boot_roles='admin',image_base_image_ref='',image_container_format='ami',image_disk_format='ami',image_kernel_id='c3f9bfb6-f089-4a0a-b410-e128284761f8',image_min_disk='0',image_min_ram='0',image_ramdisk_id='16b087bd-8aa5-48fa-968b-6d8986ee2434',owner_project_name='admin',owner_user_name='admin'},tags=<?>,task_state='reboot_started_hard',terminated_at=None,updated_at=2019-05-23T15:22:15Z,user_data=None,user_id='c23652fbcaa74c1e8becc960e2210820',uuid=a0e2b485-f40c-43e4-beb6-049b6399f0ec,vcpu_model=<?>,vcpus=1,vm_mode=None,vm_state='active') vif={"profile": {}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": "brq32740d6a-81", "subnets": [{"ips": [{"meta": {}, "version": 6, "type": "fixed", "floating_ips": [], "address": "2001:db8::3"}], "version": 6, "meta": {}, "dns": [], "routes": [], "cidr": "2001:db8::/64", "gateway": {"meta": {}, "version": 6, "type": "gateway", "address": "2001:db8::2"}}, {"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "172.24.4.16"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "172.24.4.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "172.24.4.1"}}], "meta": {"injected": false, "tenant_id": "c2b9e5f4a15d43218f3fca6e13c49a3a", "should_create_bridge": true, "mtu": 1500}, "id": "32740d6a-8119-4c8e-9828-fe5da5b6e7ac", "label": "public"}, "devname": "tapef41d30d-86", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true}, "address": "fa:16:3e:7c:d6:21", "active": true, "type": "bridge", "id": "ef41d30d-862f-4342-919a-95ed7a0587e3", "qbg_params": null} from (pid=4613) unplug /opt/stack/nova/nova/virt/libvirt/vif.py:966
2019-05-23 23:22:15.611 DEBUG nova.network.os_vif_util [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Converting VIF {"profile": {}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": "brq32740d6a-81", "subnets": [{"ips": [{"meta": {}, "version": 6, "type": "fixed", "floating_ips": [], "address": "2001:db8::3"}], "version": 6, "meta": {}, "dns": [], "routes": [], "cidr": "2001:db8::/64", "gateway": {"meta": {}, "version": 6, "type": "gateway", "address": "2001:db8::2"}}, {"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "172.24.4.16"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "172.24.4.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "172.24.4.1"}}], "meta": {"injected": false, "tenant_id": "c2b9e5f4a15d43218f3fca6e13c49a3a", "should_create_bridge": true, "mtu": 1500}, "id": "32740d6a-8119-4c8e-9828-fe5da5b6e7ac", "label": "public"}, "devname": "tapef41d30d-86", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true}, "address": "fa:16:3e:7c:d6:21", "active": true, "type": "bridge", "id": "ef41d30d-862f-4342-919a-95ed7a0587e3", "qbg_params": null} from (pid=4613) nova_to_osvif_vif /opt/stack/nova/nova/network/os_vif_util.py:439
2019-05-23 23:22:15.613 DEBUG nova.network.os_vif_util [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Converted object VIFBridge(active=True,address=fa:16:3e:7c:d6:21,bridge_name='brq32740d6a-81',has_traffic_filtering=True,id=ef41d30d-862f-4342-919a-95ed7a0587e3,network=Network(32740d6a-8119-4c8e-9828-fe5da5b6e7ac),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapef41d30d-86') from (pid=4613) nova_to_osvif_vif /opt/stack/nova/nova/network/os_vif_util.py:451
2019-05-23 23:22:15.614 DEBUG os_vif [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Unplugging vif VIFBridge(active=True,address=fa:16:3e:7c:d6:21,bridge_name='brq32740d6a-81',has_traffic_filtering=True,id=ef41d30d-862f-4342-919a-95ed7a0587e3,network=Network(32740d6a-8119-4c8e-9828-fe5da5b6e7ac),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapef41d30d-86') from (pid=4613) unplug /usr/local/lib/python2.7/dist-packages/os_vif/__init__.py:112
2019-05-23 23:22:15.615 INFO os_vif [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Successfully unplugged vif VIFBridge(active=True,address=fa:16:3e:7c:d6:21,bridge_name='brq32740d6a-81',has_traffic_filtering=True,id=ef41d30d-862f-4342-919a-95ed7a0587e3,network=Network(32740d6a-8119-4c8e-9828-fe5da5b6e7ac),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapef41d30d-86')
2019-05-23 23:22:15.615 DEBUG nova.virt.libvirt.volume.iscsi [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] calling os-brick to detach iSCSI Volume from (pid=4613) disconnect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:72
2019-05-23 23:22:16.201 DEBUG nova.virt.libvirt.volume.iscsi [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Disconnected iSCSI Volume vda from (pid=4613) disconnect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:78
2019-05-23 23:22:16.209 DEBUG nova.virt.libvirt.driver [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Start _get_guest_xml network_info=[{"profile": {}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": "brq32740d6a-81", "subnets": [{"ips": [{"meta": {}, "version": 6, "type": "fixed", "floating_ips": [], "address": "2001:db8::3"}], "version": 6, "meta": {}, "dns": [], "routes": [], "cidr": "2001:db8::/64", "gateway": {"meta": {}, "version": 6, "type": "gateway", "address": "2001:db8::2"}}, {"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "172.24.4.16"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "172.24.4.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "172.24.4.1"}}], "meta": {"injected": false, "tenant_id": "c2b9e5f4a15d43218f3fca6e13c49a3a", "should_create_bridge": true, "mtu": 1500}, "id": "32740d6a-8119-4c8e-9828-fe5da5b6e7ac", "label": "public"}, "devname": "tapef41d30d-86", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true}, "address": "fa:16:3e:7c:d6:21", "active": true, "type": "bridge", "id": "ef41d30d-862f-4342-919a-95ed7a0587e3", "qbg_params": null}] disk_info={'disk_bus': 'virtio', 'cdrom_bus': 'ide', 'mapping': {u'/dev/vda': {'bus': u'virtio', 'boot_index': '1', 'type': u'disk', 'dev': u'vda'}, 'root': {'bus': u'virtio', 'boot_index': '1', 'type': u'disk', 'dev': u'vda'}}} image_meta=ImageMeta(checksum=<?>,container_format='ami',created_at=<?>,direct_url=<?>,disk_format='ami',id=<?>,min_disk=0,min_ram=0,name=<?>,owner=<?>,properties=ImageMetaProps,protected=<?>,size=<?>,status=<?>,tags=<?>,updated_at=<?>,virtual_size=<?>,visibility=<?>) rescue=None block_device_info={'swap': None, 'root_device_name': u'/dev/vda', 'ephemerals': [], 'block_device_mapping': [{'guest_format': None, 'boot_index': 0, 'mount_device': u'/dev/vda', 'connection_info': {u'driver_volume_type': u'iscsi', u'connector': {u'initiator': u'iqn.1993-08.org.debian:01:1997f5bacda', u'ip': u'10.12.31.241', u'platform': u'x86_64', u'host': u'DevStack-Controller', u'do_local_attach': False, u'os_type': u'linux2', u'multipath': False}, u'serial': u'2ba40932-cabc-40b1-9011-87354ac29fc1', u'data': {u'device_path': u'/dev/disk/by-path/ip-10.12.31.241:3260-iscsi-iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1-lun-1', u'target_discovered': False, u'encrypted': False, u'access_mode': u'rw', u'qos_specs': None, u'target_iqn': u'iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1', u'target_portal': u'10.12.31.241:3260', u'volume_id': u'2ba40932-cabc-40b1-9011-87354ac29fc1', u'target_lun': 1, u'auth_password': u'***', u'auth_username': u'Nto8maSrg6QoWcwQ6bQ7', u'auth_method': u'CHAP'}}, 'disk_bus': u'virtio', 'device_type': u'disk', 'delete_on_termination': False}]} from (pid=4613) _get_guest_xml /opt/stack/nova/nova/virt/libvirt/driver.py:5062
2019-05-23 23:22:16.229 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Getting desirable topologies for flavor Flavor(created_at=2019-05-21T17:12:37Z,deleted=False,deleted_at=None,disabled=False,ephemeral_gb=0,extra_specs={},flavorid='c1',id=1,is_public=True,memory_mb=256,name='cirros256',projects=<?>,root_gb=0,rxtx_factor=1.0,swap=0,updated_at=None,vcpu_weight=0,vcpus=1) and image_meta ImageMeta(checksum=<?>,container_format='ami',created_at=<?>,direct_url=<?>,disk_format='ami',id=<?>,min_disk=0,min_ram=0,name=<?>,owner=<?>,properties=ImageMetaProps,protected=<?>,size=<?>,status=<?>,tags=<?>,updated_at=<?>,virtual_size=<?>,visibility=<?>), allow threads: True from (pid=4613) _get_desirable_cpu_topologies /opt/stack/nova/nova/virt/hardware.py:560
2019-05-23 23:22:16.230 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Flavor limits 65536:65536:65536 from (pid=4613) _get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:306
2019-05-23 23:22:16.230 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Image limits 65536:65536:65536 from (pid=4613) _get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:317
2019-05-23 23:22:16.230 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Flavor pref -1:-1:-1 from (pid=4613) _get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:340
2019-05-23 23:22:16.230 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Image pref -1:-1:-1 from (pid=4613) _get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:359
2019-05-23 23:22:16.231 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Chosen -1:-1:-1 limits 65536:65536:65536 from (pid=4613) _get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:388
2019-05-23 23:22:16.231 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Topology preferred VirtCPUTopology(cores=-1,sockets=-1,threads=-1), maximum VirtCPUTopology(cores=65536,sockets=65536,threads=65536) from (pid=4613) _get_desirable_cpu_topologies /opt/stack/nova/nova/virt/hardware.py:564
2019-05-23 23:22:16.231 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Build topologies for 1 vcpu(s) 1:1:1 from (pid=4613) _get_possible_cpu_topologies /opt/stack/nova/nova/virt/hardware.py:427
2019-05-23 23:22:16.232 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Got 1 possible topologies from (pid=4613) _get_possible_cpu_topologies /opt/stack/nova/nova/virt/hardware.py:454
2019-05-23 23:22:16.232 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Possible topologies [VirtCPUTopology(cores=1,sockets=1,threads=1)] from (pid=4613) _get_desirable_cpu_topologies /opt/stack/nova/nova/virt/hardware.py:569
2019-05-23 23:22:16.232 DEBUG nova.virt.hardware [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Sorted desired topologies [VirtCPUTopology(cores=1,sockets=1,threads=1)] from (pid=4613) _get_desirable_cpu_topologies /opt/stack/nova/nova/virt/hardware.py:594
2019-05-23 23:22:16.233 DEBUG nova.objects.instance [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Lazy-loading 'vcpu_model' on Instance uuid a0e2b485-f40c-43e4-beb6-049b6399f0ec from (pid=4613) obj_load_attr /opt/stack/nova/nova/objects/instance.py:1058
2019-05-23 23:22:16.245 DEBUG nova.virt.libvirt.volume.iscsi [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Calling os-brick to attach iSCSI Volume from (pid=4613) connect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:63
2019-05-23 23:22:18.604 DEBUG nova.virt.libvirt.volume.iscsi [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Attached iSCSI volume {'path': u'/dev/disk/by-path/ip-10.12.31.241:3260-iscsi-iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1-lun-1', 'scsi_wwn': u'360000000000000000e00000000030001', 'type': 'block'} from (pid=4613) connect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:65
2019-05-23 23:22:18.639 DEBUG nova.virt.libvirt.vif [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] vif_type=bridge instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=True,availability_zone='nova',cell_name=None,cleaned=True,config_drive='',created_at=2019-05-23T08:34:42Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,device_metadata=<?>,disable_terminate=False,display_description='admin-test03',display_name='admin-test03',ec2_ids=<?>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,flavor=Flavor(1),host='DevStack-Controller',hostname='admin-test03',id=3,image_ref='',info_cache=InstanceInfoCache,instance_type_id=1,kernel_id='c3f9bfb6-f089-4a0a-b410-e128284761f8',key_data=None,key_name=None,keypairs=<?>,launch_index=0,launched_at=2019-05-23T08:35:24Z,launched_on='DevStack-Controller',locked=False,locked_by=None,memory_mb=256,metadata={},migration_context=<?>,new_flavor=None,node='DevStack-Controller',numa_topology=None,old_flavor=None,os_type=None,pci_devices=PciDeviceList,pci_requests=<?>,power_state=1,progress=0,project_id='c2b9e5f4a15d43218f3fca6e13c49a3a',ramdisk_id='16b087bd-8aa5-48fa-968b-6d8986ee2434',reservation_id='r-m4xc1dvw',root_device_name='/dev/vda',root_gb=0,security_groups=SecurityGroupList,services=<?>,shutdown_terminate=False,system_metadata={boot_roles='admin',image_base_image_ref='',image_container_format='ami',image_disk_format='ami',image_kernel_id='c3f9bfb6-f089-4a0a-b410-e128284761f8',image_min_disk='0',image_min_ram='0',image_ramdisk_id='16b087bd-8aa5-48fa-968b-6d8986ee2434',owner_project_name='admin',owner_user_name='admin'},tags=<?>,task_state='reboot_started_hard',terminated_at=None,updated_at=2019-05-23T15:22:15Z,user_data=None,user_id='c23652fbcaa74c1e8becc960e2210820',uuid=a0e2b485-f40c-43e4-beb6-049b6399f0ec,vcpu_model=VirtCPUModel,vcpus=1,vm_mode=None,vm_state='active') vif={"profile": {}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": "brq32740d6a-81", "subnets": [{"ips": [{"meta": {}, "version": 6, "type": "fixed", "floating_ips": [], "address": "2001:db8::3"}], "version": 6, "meta": {}, "dns": [], "routes": [], "cidr": "2001:db8::/64", "gateway": {"meta": {}, "version": 6, "type": "gateway", "address": "2001:db8::2"}}, {"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "172.24.4.16"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "172.24.4.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "172.24.4.1"}}], "meta": {"injected": false, "tenant_id": "c2b9e5f4a15d43218f3fca6e13c49a3a", "should_create_bridge": true, "mtu": 1500}, "id": "32740d6a-8119-4c8e-9828-fe5da5b6e7ac", "label": "public"}, "devname": "tapef41d30d-86", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true}, "address": "fa:16:3e:7c:d6:21", "active": true, "type": "bridge", "id": "ef41d30d-862f-4342-919a-95ed7a0587e3", "qbg_params": null} virt_type=kvm from (pid=4613) get_config /opt/stack/nova/nova/virt/libvirt/vif.py:529
2019-05-23 23:22:18.640 DEBUG nova.network.os_vif_util [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Converting VIF {"profile": {}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": "brq32740d6a-81", "subnets": [{"ips": [{"meta": {}, "version": 6, "type": "fixed", "floating_ips": [], "address": "2001:db8::3"}], "version": 6, "meta": {}, "dns": [], "routes": [], "cidr": "2001:db8::/64", "gateway": {"meta": {}, "version": 6, "type": "gateway", "address": "2001:db8::2"}}, {"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "172.24.4.16"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "172.24.4.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "172.24.4.1"}}], "meta": {"injected": false, "tenant_id": "c2b9e5f4a15d43218f3fca6e13c49a3a", "should_create_bridge": true, "mtu": 1500}, "id": "32740d6a-8119-4c8e-9828-fe5da5b6e7ac", "label": "public"}, "devname": "tapef41d30d-86", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true}, "address": "fa:16:3e:7c:d6:21", "active": true, "type": "bridge", "id": "ef41d30d-862f-4342-919a-95ed7a0587e3", "qbg_params": null} from (pid=4613) nova_to_osvif_vif /opt/stack/nova/nova/network/os_vif_util.py:439
2019-05-23 23:22:18.642 DEBUG nova.network.os_vif_util [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Converted object VIFBridge(active=True,address=fa:16:3e:7c:d6:21,bridge_name='brq32740d6a-81',has_traffic_filtering=True,id=ef41d30d-862f-4342-919a-95ed7a0587e3,network=Network(32740d6a-8119-4c8e-9828-fe5da5b6e7ac),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapef41d30d-86') from (pid=4613) nova_to_osvif_vif /opt/stack/nova/nova/network/os_vif_util.py:451
2019-05-23 23:22:18.654 DEBUG nova.virt.libvirt.driver [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] End _get_guest_xml xml=<domain type="kvm">
2019-05-23 23:22:18.655 DEBUG nova.virt.libvirt.driver [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] skipping disk /dev/disk/by-path/ip-10.12.31.241:3260-iscsi-iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1-lun-1 (vda) as it is a volume from (pid=4613) _get_instance_disk_info /opt/stack/nova/nova/virt/libvirt/driver.py:7178
2019-05-23 23:22:18.657 DEBUG nova.virt.libvirt.vif [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] vif_type=bridge instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=True,availability_zone='nova',cell_name=None,cleaned=True,config_drive='',created_at=2019-05-23T08:34:42Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,device_metadata=<?>,disable_terminate=False,display_description='admin-test03',display_name='admin-test03',ec2_ids=<?>,ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,flavor=Flavor(1),host='DevStack-Controller',hostname='admin-test03',id=3,image_ref='',info_cache=InstanceInfoCache,instance_type_id=1,kernel_id='c3f9bfb6-f089-4a0a-b410-e128284761f8',key_data=None,key_name=None,keypairs=<?>,launch_index=0,launched_at=2019-05-23T08:35:24Z,launched_on='DevStack-Controller',locked=False,locked_by=None,memory_mb=256,metadata={},migration_context=<?>,new_flavor=None,node='DevStack-Controller',numa_topology=None,old_flavor=None,os_type=None,pci_devices=PciDeviceList,pci_requests=<?>,power_state=1,progress=0,project_id='c2b9e5f4a15d43218f3fca6e13c49a3a',ramdisk_id='16b087bd-8aa5-48fa-968b-6d8986ee2434',reservation_id='r-m4xc1dvw',root_device_name='/dev/vda',root_gb=0,security_groups=SecurityGroupList,services=<?>,shutdown_terminate=False,system_metadata={boot_roles='admin',image_base_image_ref='',image_container_format='ami',image_disk_format='ami',image_kernel_id='c3f9bfb6-f089-4a0a-b410-e128284761f8',image_min_disk='0',image_min_ram='0',image_ramdisk_id='16b087bd-8aa5-48fa-968b-6d8986ee2434',owner_project_name='admin',owner_user_name='admin'},tags=<?>,task_state='reboot_started_hard',terminated_at=None,updated_at=2019-05-23T15:22:15Z,user_data=None,user_id='c23652fbcaa74c1e8becc960e2210820',uuid=a0e2b485-f40c-43e4-beb6-049b6399f0ec,vcpu_model=VirtCPUModel,vcpus=1,vm_mode=None,vm_state='active') vif={"profile": {}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": "brq32740d6a-81", "subnets": [{"ips": [{"meta": {}, "version": 6, "type": "fixed", "floating_ips": [], "address": "2001:db8::3"}], "version": 6, "meta": {}, "dns": [], "routes": [], "cidr": "2001:db8::/64", "gateway": {"meta": {}, "version": 6, "type": "gateway", "address": "2001:db8::2"}}, {"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "172.24.4.16"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "172.24.4.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "172.24.4.1"}}], "meta": {"injected": false, "tenant_id": "c2b9e5f4a15d43218f3fca6e13c49a3a", "should_create_bridge": true, "mtu": 1500}, "id": "32740d6a-8119-4c8e-9828-fe5da5b6e7ac", "label": "public"}, "devname": "tapef41d30d-86", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true}, "address": "fa:16:3e:7c:d6:21", "active": true, "type": "bridge", "id": "ef41d30d-862f-4342-919a-95ed7a0587e3", "qbg_params": null} from (pid=4613) plug /opt/stack/nova/nova/virt/libvirt/vif.py:776
2019-05-23 23:22:18.658 DEBUG nova.network.os_vif_util [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Converting VIF {"profile": {}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": "brq32740d6a-81", "subnets": [{"ips": [{"meta": {}, "version": 6, "type": "fixed", "floating_ips": [], "address": "2001:db8::3"}], "version": 6, "meta": {}, "dns": [], "routes": [], "cidr": "2001:db8::/64", "gateway": {"meta": {}, "version": 6, "type": "gateway", "address": "2001:db8::2"}}, {"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "172.24.4.16"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "172.24.4.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "172.24.4.1"}}], "meta": {"injected": false, "tenant_id": "c2b9e5f4a15d43218f3fca6e13c49a3a", "should_create_bridge": true, "mtu": 1500}, "id": "32740d6a-8119-4c8e-9828-fe5da5b6e7ac", "label": "public"}, "devname": "tapef41d30d-86", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true}, "address": "fa:16:3e:7c:d6:21", "active": true, "type": "bridge", "id": "ef41d30d-862f-4342-919a-95ed7a0587e3", "qbg_params": null} from (pid=4613) nova_to_osvif_vif /opt/stack/nova/nova/network/os_vif_util.py:439
2019-05-23 23:22:18.659 DEBUG nova.network.os_vif_util [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Converted object VIFBridge(active=True,address=fa:16:3e:7c:d6:21,bridge_name='brq32740d6a-81',has_traffic_filtering=True,id=ef41d30d-862f-4342-919a-95ed7a0587e3,network=Network(32740d6a-8119-4c8e-9828-fe5da5b6e7ac),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapef41d30d-86') from (pid=4613) nova_to_osvif_vif /opt/stack/nova/nova/network/os_vif_util.py:451
2019-05-23 23:22:18.660 DEBUG os_vif [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Plugging vif VIFBridge(active=True,address=fa:16:3e:7c:d6:21,bridge_name='brq32740d6a-81',has_traffic_filtering=True,id=ef41d30d-862f-4342-919a-95ed7a0587e3,network=Network(32740d6a-8119-4c8e-9828-fe5da5b6e7ac),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapef41d30d-86') from (pid=4613) plug /usr/local/lib/python2.7/dist-packages/os_vif/__init__.py:79
2019-05-23 23:22:18.662 DEBUG vif_plug_linux_bridge.linux_net [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Ensuring filtering brq32740d6a-81 to True from (pid=4613) _ensure_bridge_filtering /usr/local/lib/python2.7/dist-packages/vif_plug_linux_bridge/linux_net.py:193
2019-05-23 23:22:18.663 INFO os_vif [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] Successfully plugged vif VIFBridge(active=True,address=fa:16:3e:7c:d6:21,bridge_name='brq32740d6a-81',has_traffic_filtering=True,id=ef41d30d-862f-4342-919a-95ed7a0587e3,network=Network(32740d6a-8119-4c8e-9828-fe5da5b6e7ac),plugin='linux_bridge',port_profile=<?>,preserve_on_delete=False,vif_name='tapef41d30d-86')
2019-05-23 23:22:20.856 DEBUG nova.compute.manager [req-5a5313c8-d588-4c85-a599-2763cd6489e3 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Checking state from (pid=4613) _get_power_state /opt/stack/nova/nova/compute/manager.py:1184
Lock
root@DevStack-Controller:/opt/stack/logs# cat n-api.log | grep req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19
2019-05-23 23:28:05.684 DEBUG nova.api.openstack.wsgi [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] Calling method '<bound method ServersController.detail of <nova.api.openstack.compute.servers.ServersController object at 0x7fb2f89b4fd0>>' from (pid=28283) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:626
2019-05-23 23:28:05.687 DEBUG nova.compute.api [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] Searching by: {'deleted': False, u'project_id': u'c2b9e5f4a15d43218f3fca6e13c49a3a'} from (pid=28283) get_all /opt/stack/nova/nova/compute/api.py:2429
2019-05-23 23:28:05.693 DEBUG oslo_concurrency.lockutils [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s from (pid=28283) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:270
2019-05-23 23:28:05.694 DEBUG oslo_concurrency.lockutils [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.000s from (pid=28283) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282
2019-05-23 23:28:05.729 DEBUG nova.compute.api [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] Skipping already-collected cell0 list from (pid=28283) _get_instances_by_filters_all_cells /opt/stack/nova/nova/compute/api.py:2625
2019-05-23 23:28:05.729 DEBUG nova.compute.api [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] Listing 21 instances in cell None from (pid=28283) _get_instances_by_filters_all_cells /opt/stack/nova/nova/compute/api.py:2628
2019-05-23 23:28:05.730 DEBUG oslo_concurrency.lockutils [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] Lock "5fd8cdfc-e20e-46da-8c1a-88e1c5ce2790" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s from (pid=28283) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:270
2019-05-23 23:28:05.730 DEBUG oslo_concurrency.lockutils [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] Lock "5fd8cdfc-e20e-46da-8c1a-88e1c5ce2790" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.000s from (pid=28283) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282
2019-05-23 23:28:05.894 DEBUG neutronclient.v2_0.client [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/ports.json?device_id=a0e2b485-f40c-43e4-beb6-049b6399f0ec&device_id=7b56d1e5-235e-4b95-a2fe-74017f744042&device_id=60958b71-e535-4241-a2a8-bf59c3e36abe used request id req-ce220321-e245-4fa6-a352-c6885860c42d from (pid=28283) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:28:06.012 DEBUG neutronclient.v2_0.client [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] GET call to neutron for http://10.12.31.241:9696/v2.0/security-groups.json?id=ce515117-ecc7-4a1a-a948-1c585c1b3787 used request id req-1db64495-dd5c-42bb-9f7a-14eabc572fac from (pid=28283) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 23:28:06.022 DEBUG nova.policy [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] Policy check for os_compute_api:os-hide-server-addresses failed with credentials {'service_roles': [], 'user_id': u'c23652fbcaa74c1e8becc960e2210820', 'roles': [u'admin'], 'user_domain_id': u'default', 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': True, 'project_id': u'c2b9e5f4a15d43218f3fca6e13c49a3a', 'project_domain_id': u'default'} from (pid=28283) authorize /opt/stack/nova/nova/policy.py:168
2019-05-23 23:28:06.031 INFO nova.osapi_compute.wsgi.server [req-b8bd1a5d-834b-4fca-8c1d-abe7f7e82e19 admin admin] 10.12.31.241 "GET /v2.1/servers/detail?limit=21&project_id=c2b9e5f4a15d43218f3fca6e13c49a3a HTTP/1.1" status: 200 len: 5346 time: 0.3838229
Unlock
root@DevStack-Controller:/opt/stack/logs# cat n-api.log | grep req-e9e4991c-52ca-47a0-aa7b-7ce7203b8f4f
2019-05-23 23:29:28.601 DEBUG nova.api.openstack.wsgi [req-e9e4991c-52ca-47a0-aa7b-7ce7203b8f4f admin admin] Action: 'action', calling method: <bound method LockServerController._unlock of <nova.api.openstack.compute.lock_server.LockServerController object at 0x7fb2f82ee290>>, body: {"unlock": null} from (pid=28283) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:623
2019-05-23 23:29:28.605 DEBUG nova.compute.api [req-e9e4991c-52ca-47a0-aa7b-7ce7203b8f4f admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Fetching instance by UUID from (pid=28283) get /opt/stack/nova/nova/compute/api.py:2397
2019-05-23 23:29:28.611 DEBUG oslo_concurrency.lockutils [req-e9e4991c-52ca-47a0-aa7b-7ce7203b8f4f admin admin] Lock "5fd8cdfc-e20e-46da-8c1a-88e1c5ce2790" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s from (pid=28283) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:270
2019-05-23 23:29:28.612 DEBUG oslo_concurrency.lockutils [req-e9e4991c-52ca-47a0-aa7b-7ce7203b8f4f admin admin] Lock "5fd8cdfc-e20e-46da-8c1a-88e1c5ce2790" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.000s from (pid=28283) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282
2019-05-23 23:29:28.651 DEBUG nova.compute.api [req-e9e4991c-52ca-47a0-aa7b-7ce7203b8f4f admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Unlocking from (pid=28283) unlock /opt/stack/nova/nova/compute/api.py:3714
2019-05-23 23:29:28.713 INFO nova.osapi_compute.wsgi.server [req-e9e4991c-52ca-47a0-aa7b-7ce7203b8f4f admin admin] 10.12.31.241 "POST /v2.1/servers/a0e2b485-f40c-43e4-beb6-049b6399f0ec/action HTTP/1.1" status: 202 len: 337 time: 0.1484101
end
