O031、Start Instance 操作详解
本节将通过日志文件分析 instance start 的操作过程，下面是 start instance 的流程图
①用户向 nova-api 发送开机请求
1、先 tailf n-api.log
2、然后执行 instance start 操作
3、从屏幕上找到开机相关的字段，比如 start
4、从步骤3 中定位到开机的日志，提取 Requests ID
5、从 n-api.log 中用RequestsID 过滤开机事件的日志
root@DevStack-Controller:/opt/stack/logs# cat n-api.log | grep req-96f95637-5d57-4b20-8515-a5af1d1419c2
2019-05-23 22:40:12.577 DEBUG nova.api.openstack.wsgi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Action: 'action', calling method: <bound method ServersController._start_server of <nova.api.openstack.compute.servers.ServersController object at 0x7fb2f89b4fd0>>, body: {"os-start": null} from (pid=28283) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:623
2019-05-23 22:40:12.616 DEBUG nova.compute.api [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Going to try to start instance from (pid=28283) start /opt/stack/nova/nova/compute/api.py:2307
下面的日志属于② nova-api 向 Messaging 发送一个开机机的消息
2019-05-23 22:40:12.723 DEBUG oslo_messaging._drivers.amqpdriver [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] CAST unique_id: 20a56f6286e44b108e64728bcf90cc03 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 22:40:12.725 INFO nova.osapi_compute.wsgi.server [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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.1780329
②nova-api 向 Messaging 发送一个开机机的消息
③nova-compute 从Messaging 获取到开机的消息后执行开机操作
用Requests ID 去 n-cpu.log 中过滤开机事件相关的日志
从下面的日志中可以看到在 instance start 的过程中，准备了 网络、磁盘、cpu 、镜像文件、xml等信息
root@DevStack-Controller:/opt/stack/logs# cat n-cpu.log | grep req-96f95637-5d57-4b20-8515-a5af1d1419c2 | grep -v oslo
2019-05-23 22:40:12.751 DEBUG nova.objects.instance [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Lazy-loading 'flavor' 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 22:40:12.800 DEBUG nova.objects.instance [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Lazy-loading 'info_cache' 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 22:40:12.844 DEBUG nova.network.neutronv2.api [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:12.936 DEBUG neutronclient.v2_0.client [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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-fd7cdd94-a4a9-418c-bd4b-25dcafbc95cc from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 22:40:13.059 DEBUG neutronclient.v2_0.client [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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-bf7cf00c-0917-4f89-a9cd-b6ee17294796 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 22:40:13.108 DEBUG neutronclient.v2_0.client [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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-cf1dca23-4bb7-4c43-8cd3-2030b30871dd from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 22:40:13.178 DEBUG neutronclient.v2_0.client [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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-41d540ab-ae55-4fb2-8569-dde4409089b8 from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 22:40:13.294 DEBUG neutronclient.v2_0.client [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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-aa761c5b-6145-4a5e-9246-8e5f8f6ec2dd from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 22:40:13.358 DEBUG neutronclient.v2_0.client [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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-db52a270-2441-4ce5-a90c-2f988bf7c6ea from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 22:40:13.427 DEBUG neutronclient.v2_0.client [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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-f5709c3b-e3de-4d40-869c-8fc9d8c7283f from (pid=4613) _append_request_id /usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:128
2019-05-23 22:40:13.428 DEBUG nova.network.base_api [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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": false, "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 22:40:13.470 DEBUG nova.virt.libvirt.vif [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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=<?>,old_flavor=None,os_type=None,pci_devices=<?>,pci_requests=<?>,power_state=4,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=<?>,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='powering-on',terminated_at=None,updated_at=2019-05-23T13:21:26Z,user_data=None,user_id='c23652fbcaa74c1e8becc960e2210820',uuid=a0e2b485-f40c-43e4-beb6-049b6399f0ec,vcpu_model=<?>,vcpus=1,vm_mode=None,vm_state='stopped') 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": false, "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 22:40:13.470 DEBUG nova.network.os_vif_util [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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": false, "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 22:40:13.472 DEBUG nova.network.os_vif_util [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Converted object VIFBridge(active=False,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 22:40:13.473 DEBUG os_vif [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Unplugging vif VIFBridge(active=False,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 22:40:13.473 INFO os_vif [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Successfully unplugged vif VIFBridge(active=False,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 22:40:13.474 DEBUG nova.virt.libvirt.volume.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:13.474 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] ==> disconnect_volume: call u"{'args': (<os_brick.initiator.connectors.iscsi.ISCSIConnector object at 0x7fb95a4af250>, {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'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'auth_password': u'***', u'target_lun': 1, u'access_mode': u'rw', u'auth_username': u'Nto8maSrg6QoWcwQ6bQ7', u'auth_method': u'CHAP'}, None), 'kwargs': {}}" from (pid=4613) trace_logging_wrapper /usr/local/lib/python2.7/dist-packages/os_brick/utils.py:146
2019-05-23 22:40:13.475 DEBUG os_brick.initiator.linuxscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Flushing IO for device /dev/sdd from (pid=4613) flush_device_io /usr/local/lib/python2.7/dist-packages/os_brick/initiator/linuxscsi.py:146
2019-05-23 22:40:13.500 DEBUG os_brick.initiator.linuxscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Remove SCSI device /dev/sdd with /sys/block/sdd/device/delete from (pid=4613) remove_scsi_device /usr/local/lib/python2.7/dist-packages/os_brick/initiator/linuxscsi.py:69
2019-05-23 22:40:13.554 DEBUG os_brick.initiator.linuxscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Checking to see if SCSI volume /dev/disk/by-path/ip-10.12.31.241:3260-iscsi-iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1-lun-1 has been removed. from (pid=4613) wait_for_volume_removal /usr/local/lib/python2.7/dist-packages/os_brick/initiator/linuxscsi.py:77
2019-05-23 22:40:13.555 DEBUG os_brick.initiator.linuxscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] SCSI volume /dev/disk/by-path/ip-10.12.31.241:3260-iscsi-iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1-lun-1 has been removed. from (pid=4613) wait_for_volume_removal /usr/local/lib/python2.7/dist-packages/os_brick/initiator/linuxscsi.py:83
2019-05-23 22:40:13.577 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'manual'): stdout= stderr= from (pid=4613) _run_iscsiadm /usr/local/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:598
2019-05-23 22:40:14.090 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--logout',): stdout=Logging out of session [sid: 3, target: iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1, portal: 10.12.31.241,3260]
2019-05-23 22:40:14.096 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--op', 'delete'): stdout= stderr= from (pid=4613) _run_iscsiadm /usr/local/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:598
2019-05-23 22:40:14.097 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] <== disconnect_volume: return (621ms) None from (pid=4613) trace_logging_wrapper /usr/local/lib/python2.7/dist-packages/os_brick/utils.py:170
2019-05-23 22:40:14.097 DEBUG nova.virt.libvirt.volume.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Disconnected iSCSI Volume vda from (pid=4613) disconnect_volume /opt/stack/nova/nova/virt/libvirt/volume/iscsi.py:78
2019-05-23 22:40:14.109 DEBUG nova.virt.libvirt.driver [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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": false, "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'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'auth_password': u'***', u'target_lun': 1, u'access_mode': u'rw', 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 22:40:14.109 DEBUG nova.objects.instance [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Lazy-loading 'numa_topology' 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 22:40:14.142 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.143 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.143 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.144 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.144 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.145 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.146 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.146 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.147 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Got 1 possible topologies from (pid=4613) _get_possible_cpu_topologies /opt/stack/nova/nova/virt/hardware.py:454
2019-05-23 22:40:14.147 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.148 DEBUG nova.virt.hardware [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.149 DEBUG nova.objects.instance [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.166 DEBUG nova.virt.libvirt.volume.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:14.167 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] ==> connect_volume: call u"{'args': (<os_brick.initiator.connectors.iscsi.ISCSIConnector object at 0x7fb95a4af250>, {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'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'auth_password': u'***', u'target_lun': 1, u'access_mode': u'rw', u'auth_username': u'Nto8maSrg6QoWcwQ6bQ7', u'auth_method': u'CHAP'}), 'kwargs': {}}" from (pid=4613) trace_logging_wrapper /usr/local/lib/python2.7/dist-packages/os_brick/utils.py:146
2019-05-23 22:40:14.169 INFO os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Multipath discovery for iSCSI not enabled.
2019-05-23 22:40:14.169 INFO os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Trying to connect to iSCSI portal 10.12.31.241:3260
2019-05-23 22:40:14.184 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--interface', 'default', '--op', 'new'): stdout=New iSCSI node [tcp:[hw=,ip=,net_if=,iscsi_if=default] 10.12.31.241,3260,-1 iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1] added
2019-05-23 22:40:14.191 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--op', 'update', '-n', 'node.session.auth.authmethod', '-v', u'CHAP'): stdout= stderr= from (pid=4613) _run_iscsiadm /usr/local/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:598
2019-05-23 22:40:14.197 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--op', 'update', '-n', 'node.session.auth.username', '-v', u'Nto8maSrg6QoWcwQ6bQ7'): stdout= stderr= from (pid=4613) _run_iscsiadm /usr/local/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:598
2019-05-23 22:40:14.203 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--op', 'update', '-n', 'node.session.auth.password', '-v', u'***'): stdout= stderr= from (pid=4613) _run_iscsiadm /usr/local/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:598
2019-05-23 22:40:14.210 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ['-m', 'session']: stdout=tcp: [1] 10.12.31.241:3260,1 iqn.2010-10.org.openstack:volume-2d8e47c4-7d52-4192-8f47-e1dcd68d8a6b (non-flash)
2019-05-23 22:40:15.483 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--login',): stdout=Logging in to [iface: default, target: iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1, portal: 10.12.31.241,3260] (multiple)
2019-05-23 22:40:15.489 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--op', 'update', '-n', 'node.startup', '-v', 'automatic'): stdout= stderr= from (pid=4613) _run_iscsiadm /usr/local/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:598
2019-05-23 22:40:15.489 INFO os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] ISCSI volume not yet found at: [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']. Will rescan & retry. Try number: 0.
2019-05-23 22:40:15.499 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] iscsiadm ('--rescan',): stdout=Rescanning session [sid: 4, target: iqn.2010-10.org.openstack:volume-2ba40932-cabc-40b1-9011-87354ac29fc1, portal: 10.12.31.241,3260]
2019-05-23 22:40:15.499 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Found iSCSI node [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'] (after 1 rescans) from (pid=4613) connect_volume /usr/local/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:437
2019-05-23 22:40:15.504 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Device WWN = '360000000000000000e00000000030001' from (pid=4613) connect_volume /usr/local/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:444
2019-05-23 22:40:15.504 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] connect_volume returning {'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 /usr/local/lib/python2.7/dist-packages/os_brick/initiator/connectors/iscsi.py:456
2019-05-23 22:40:15.505 DEBUG os_brick.initiator.connectors.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] <== connect_volume: return (1336ms) {'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': u'block'} from (pid=4613) trace_logging_wrapper /usr/local/lib/python2.7/dist-packages/os_brick/utils.py:170
2019-05-23 22:40:15.505 DEBUG nova.virt.libvirt.volume.iscsi [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:15.536 DEBUG nova.virt.libvirt.vif [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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=<?>,pci_requests=<?>,power_state=4,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=<?>,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='powering-on',terminated_at=None,updated_at=2019-05-23T13:21:26Z,user_data=None,user_id='c23652fbcaa74c1e8becc960e2210820',uuid=a0e2b485-f40c-43e4-beb6-049b6399f0ec,vcpu_model=VirtCPUModel,vcpus=1,vm_mode=None,vm_state='stopped') 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": false, "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 22:40:15.537 DEBUG nova.network.os_vif_util [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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": false, "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 22:40:15.539 DEBUG nova.network.os_vif_util [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Converted object VIFBridge(active=False,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 22:40:15.546 DEBUG nova.objects.instance [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Lazy-loading 'pci_devices' 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 22:40:15.556 DEBUG nova.virt.libvirt.driver [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] End _get_guest_xml xml=<domain type="kvm">
2019-05-23 22:40:15.557 DEBUG nova.virt.libvirt.driver [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:15.558 DEBUG nova.virt.libvirt.vif [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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=4,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=<?>,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='powering-on',terminated_at=None,updated_at=2019-05-23T13:21:26Z,user_data=None,user_id='c23652fbcaa74c1e8becc960e2210820',uuid=a0e2b485-f40c-43e4-beb6-049b6399f0ec,vcpu_model=VirtCPUModel,vcpus=1,vm_mode=None,vm_state='stopped') 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": false, "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 22:40:15.559 DEBUG nova.network.os_vif_util [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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": false, "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 22:40:15.560 DEBUG nova.network.os_vif_util [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Converted object VIFBridge(active=False,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 22:40:15.561 DEBUG os_vif [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Plugging vif VIFBridge(active=False,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 22:40:15.563 DEBUG vif_plug_linux_bridge.linux_net [req-96f95637-5d57-4b20-8515-a5af1d1419c2 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 22:40:15.564 INFO os_vif [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] Successfully plugged vif VIFBridge(active=False,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 22:40:17.649 DEBUG nova.compute.manager [req-96f95637-5d57-4b20-8515-a5af1d1419c2 admin admin] [instance: a0e2b485-f40c-43e4-beb6-049b6399f0ec] Checking state from (pid=4613) _get_power_state /opt/stack/nova/nova/compute/manager.py:1184
