| 2021-02-25 11:30:27 |
Bartosz Bezak |
description |
Description
===========
Centos 8.3 Host - failed to attach second NIC on 1 vcpu ubuntu guests with qemu-kvm-5.1.0-14.el8.1.x86_64
Downgrading to qemu-kvm-4.2.0-29.el8.3.x86_64 fixes the problem.
First seen in Octavia:
http://lists.openstack.org/pipermail/openstack-discuss/2021-February/020218.html
https://storyboard.openstack.org/#!/story/2008651
Steps to reproduce
==================
Kayobe (kolla-ansible under the hood) deployed all-in-one on baremetal:
https://docs.openstack.org/kayobe/latest/contributor/automated.html#overcloud
ubuntu images - https://cloud-images.ubuntu.com/focal/current/focal-server-cloudimg-amd64.img
Problem reproduced on bionic, focal, groovy and hirsute.
Failing flavor - 1 VCPU - 16G RAM
Working flavor - 2 VCPUs - 1G RAM
openstack server create --flavor 16g --image focal --config-drive True --key-name test --network demo-net testvm16g
openstack --debug server add port testvm16g testvm1port
Expected result
===============
Proper attachment of NIC to VM
Actual result
=============
novaclient.exceptions.ClientException: Unknown Error (HTTP 504)
clean_up AddPort: Unknown Error (HTTP 504)
Environment
===========
1. Openstack Ussuri
openstack-nova-compute-21.1.2-1.el8.noarch
openstack-nova-common-21.1.2-1.el8.noarch
2. Which hypervisor did you use?
Centos 8.3 - Libvirt + KVM
2. Which storage type did you use?
SSD with ext4
3. Which networking type did you use?
Tested on Neutron with OpenVSwitch, and Neutron with OVN
Logs & Configs
==============
openstack --debug server add port testvm16g testvm1port
Network client initialized using OpenStack SDK: <openstack.network.v2._proxy.Proxy object at 0x7ff4d30e7cf8>
REQ: curl -g -i -X GET http://192.168.33.2:9696/v2.0/ports/testvm1port -H "User-Agent: openstacksdk/0.46.0 keystoneauth1/4.0.0 python-requests/2.23.0 CPython/3.6.8" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d"
Starting new HTTP connection (1): 192.168.33.2:9696
http://192.168.33.2:9696 "GET /v2.0/ports/testvm1port HTTP/1.1" 404 107
RESP: [404] Connection: keep-alive Content-Length: 107 Content-Type: application/json Date: Thu, 25 Feb 2021 11:03:44 GMT X-Openstack-Request-Id: req-ba52034b-d259-44dc-a87f-93a26c9479f0
RESP BODY: {"NeutronError": {"type": "PortNotFound", "message": "Port testvm1port could not be found.", "detail": ""}}
GET call to network for http://192.168.33.2:9696/v2.0/ports/testvm1port used request id req-ba52034b-d259-44dc-a87f-93a26c9479f0
REQ: curl -g -i -X GET "http://192.168.33.2:9696/v2.0/ports?name=testvm1port" -H "Accept: application/json" -H "User-Agent: openstacksdk/0.46.0 keystoneauth1/4.0.0 python-requests/2.23.0 CPython/3.6.8" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d"
http://192.168.33.2:9696 "GET /v2.0/ports?name=testvm1port HTTP/1.1" 200 805
RESP: [200] Connection: keep-alive Content-Length: 805 Content-Type: application/json Date: Thu, 25 Feb 2021 11:03:44 GMT X-Openstack-Request-Id: req-68eebc47-6a29-4c0c-ab35-26bd8138676c
RESP BODY: {"ports":[{"id":"409113d5-b275-48e8-8429-d08a06eb4caa","name":"testvm1port","network_id":"45c000ba-d770-48e3-8a83-5950c60e8a1d","tenant_id":"19303d9afcc4447b8985e7011add0d3d","mac_address":"fa:16:3e:aa:ce:9a","admin_state_up":true,"status":"DOWN","device_id":"","device_owner":"","fixed_ips":[{"subnet_id":"19164ffe-2c52-4233-b916-8448ee1e42a0","ip_address":"192.0.2.178"}],"allowed_address_pairs":[],"extra_dhcp_opts":[],"security_groups":["c997fbce-9065-47f5-9738-e311969c1db6"],"description":"","binding:vnic_type":"normal","binding:profile":{},"binding:host_id":"","binding:vif_type":"unbound","binding:vif_details":{},"port_security_enabled":true,"tags":[],"created_at":"2021-02-24T13:45:38Z","updated_at":"2021-02-25T10:06:27Z","revision_number":91,"project_id":"19303d9afcc4447b8985e7011add0d3d"}]}
GET call to network for http://192.168.33.2:9696/v2.0/ports?name=testvm1port used request id req-68eebc47-6a29-4c0c-ab35-26bd8138676c
REQ: curl -g -i -X POST http://192.168.33.2:8774/v2.1/servers/d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f/os-interface -H "Accept: application/json" -H "Content-Type: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d" -H "X-OpenStack-Nova-API-Version: 2.1" -d '{"interfaceAttachment": {"port_id": "409113d5-b275-48e8-8429-d08a06eb4caa"}}'
http://192.168.33.2:8774 "POST /v2.1/servers/d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f/os-interface HTTP/1.1" 504 None
RESP: [504] Cache-Control: no-cache Connection: close Content-Type: text/html
RESP BODY: Omitted, Content-Type is set to text/html. Only application/json responses have their bodies logged.
Unknown Error (HTTP 504)
Traceback (most recent call last):
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/cliff/app.py", line 401, in run_subcommand
result = cmd.run(parsed_args)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/osc_lib/command/command.py", line 41, in run
return super(Command, self).run(parsed_args)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/cliff/command.py", line 185, in run
return_code = self.take_action(parsed_args) or 0
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/openstackclient/compute/v2/server.py", line 359, in take_action
server.interface_attach(port_id=port_id, net_id=None, fixed_ip=None)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/api_versions.py", line 393, in substitution
return methods[-1].func(obj, *args, **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/v2/servers.py", line 610, in interface_attach
return self.manager.interface_attach(self, port_id, net_id, fixed_ip)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/api_versions.py", line 393, in substitution
return methods[-1].func(obj, *args, **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/v2/servers.py", line 2063, in interface_attach
obj_class=NetworkInterface)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/base.py", line 363, in _create
resp, body = self.api.client.post(url, body=body)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/keystoneauth1/adapter.py", line 392, in post
return self.request(url, 'POST', **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/client.py", line 78, in request
raise exceptions.from_response(resp, body, url, method)
novaclient.exceptions.ClientException: Unknown Error (HTTP 504)
clean_up AddPort: Unknown Error (HTTP 504)
END return value: 1
nova-compute:
2021-02-25 11:03:46.549 7 DEBUG nova.network.os_vif_util [req-f47d8eee-0beb-4890-af38-e0d78cbfae88 8d64a09fc978483a9c9a64d71d863fb8 19303d9afcc4447b8985e7011add0d3d - default default] Converted object VIFOpenVSwitch(active=False,address=fa:16:3e:aa:ce:9a,bridge_name='br-int',has_traffic_filtering=True,id=409113d5-b275-48e8-8429-d08a06eb4caa,network=Network(45c000ba-d770-48e3-8a83-5950c60e8a1d),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap409113d5-b2') nova_to_osvif_vif /usr/lib/python3.6/site-packages/nova/network/os_vif_util.py:538
2021-02-25 11:03:46.567 7 DEBUG nova.virt.libvirt.guest [req-f47d8eee-0beb-4890-af38-e0d78cbfae88 8d64a09fc978483a9c9a64d71d863fb8 19303d9afcc4447b8985e7011add0d3d - default default] attach device xml: <interface type="bridge">
<mac address="fa:16:3e:aa:ce:9a"/>
<model type="virtio"/>
<driver name="qemu"/>
<source bridge="br-int"/>
<mtu size="1442"/>
<target dev="tap409113d5-b2"/>
<virtualport type="openvswitch">
<parameters interfaceid="409113d5-b275-48e8-8429-d08a06eb4caa"/>
</virtualport>
</interface>
attach_device /usr/lib/python3.6/site-packages/nova/virt/libvirt/guest.py:292
2021-02-25 11:03:47.004 7 DEBUG nova.network.neutron [req-9ec4dc24-3aec-44c9-bb3d-3b4f9a398bc9 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Updated VIF entry in instance network info cache for port 409113d5-b275-48e8-8429-d08a06eb4caa. _build_network_info_model /usr/lib/python3.6/site-packages/nova/network/neutron.py:3157
2021-02-25 11:03:47.005 7 DEBUG nova.network.neutron [req-9ec4dc24-3aec-44c9-bb3d-3b4f9a398bc9 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Updating instance_info_cache with network_info: [{"id": "3dd3e38a-45ad-4e67-8b04-a9bb18ed372a", "address": "fa:16:3e:7d:98:04", "network": {"id": "dac630c1-4d4d-42b7-b2c7-f110697dc999", "bridge": "br-int", "label": "demo-net", "subnets": [{"cidr": "10.0.0.0/24", "dns": [{"address": "8.8.8.8", "type": "dns", "version": 4, "meta": {}}], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.174", "type": "fixed", "version": 4, "meta": {}, "floating_ips": [{"address": "192.168.33.96", "type": "floating", "version": 4, "meta": {}}]}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.2"}}], "meta": {"injected": false, "tenant_id": "19303d9afcc4447b8985e7011add0d3d", "mtu": null, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true}, "devname": "tap3dd3e38a-45", "ovs_interfaceid": "3dd3e38a-45ad-4e67-8b04-a9bb18ed372a", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "meta": {}}, {"id": "409113d5-b275-48e8-8429-d08a06eb4caa", "address": "fa:16:3e:aa:ce:9a", "network": {"id": "45c000ba-d770-48e3-8a83-5950c60e8a1d", "bridge": "br-int", "label": "test-net", "subnets": [{"cidr": "192.0.2.0/24", "dns": [], "gateway": {"address": "192.0.2.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "192.0.2.178", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "192.0.2.2"}}], "meta": {"injected": false, "tenant_id": "19303d9afcc4447b8985e7011add0d3d", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true}, "devname": "tap409113d5-b2", "ovs_interfaceid": "409113d5-b275-48e8-8429-d08a06eb4caa", "qbh_params": null, "qbg_params": null, "active": false, "vnic_type": "normal", "profile": {}, "preserve_on_delete": true, "meta": {}}] update_instance_cache_with_nw_info /usr/lib/python3.6/site-packages/nova/network/neutron.py:119
2021-02-25 11:03:48.335 7 WARNING nova.compute.manager [req-2a330fc9-9bef-4f78-84cd-8b6a9e0158a8 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Received unexpected event network-vif-plugged-409113d5-b275-48e8-8429-d08a06eb4caa for instance with vm_state active and task_state None.
Libvirt/qemu:
2021-02-25 11:03:46.568+0000: 17285: debug : virDomainAttachDeviceFlags:8222 : dom=0x7f700400a9f0, (VM: name=instance-00000018, uuid=d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f), xml=<interface type="bridge">
<mac address="fa:16:3e:aa:ce:9a"/>
<model type="virtio"/>
<driver name="qemu"/>
<source bridge="br-int"/>
<mtu size="1442"/>
<target dev="tap409113d5-b2"/>
<virtualport type="openvswitch">
<parameters interfaceid="409113d5-b275-48e8-8429-d08a06eb4caa"/>
</virtualport>
</interface>
, flags=0x3
2021-02-25 11:03:46.568+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f7004116970
2021-02-25 11:03:46.568+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x5561fdc8adf0
2021-02-25 11:03:46.568+0000: 17285: debug : virAccessManagerCheckDomain:239 : manager=0x5561fdc8adf0(name=stack) driver=QEMU domain=0x7f705401c400 perm=2
2021-02-25 11:03:46.568+0000: 17285: debug : virAccessManagerCheckDomain:239 : manager=0x5561fdc8ae50(name=none) driver=QEMU domain=0x7f705401c400 perm=2
2021-02-25 11:03:46.568+0000: 17285: debug : virAccessManagerCheckDomain:239 : manager=0x5561fdc8adf0(name=stack) driver=QEMU domain=0x7f705401c400 perm=7
2021-02-25 11:03:46.568+0000: 17285: debug : virAccessManagerCheckDomain:239 : manager=0x5561fdc8ae50(name=none) driver=QEMU domain=0x7f705401c400 perm=7
2021-02-25 11:03:46.568+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x5561fdc8adf0
2021-02-25 11:03:46.568+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f7004114020
2021-02-25 11:03:46.568+0000: 17285: debug : qemuDomainObjBeginJobInternal:840 : Starting job: job=modify agentJob=none asyncJob=none (vm=0x7f7004116970 name=instance-00000018, current job=none agentJob=none async=none)
2021-02-25 11:03:46.568+0000: 17285: debug : qemuDomainObjBeginJobInternal:887 : Started job: modify (async=none vm=0x7f7004116970 name=instance-00000018)
2021-02-25 11:03:46.568+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f7004114020
2021-02-25 11:03:46.568+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f7004114020
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f6ffc098580 classname=qemuDomainVcpuPrivate
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f704403b550 classname=virStorageSource
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f6ff8007470 classname=qemuDomainDiskPrivate
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f704403b710 classname=virStorageSource
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f6ff80074d0 classname=qemuDomainDiskPrivate
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f7038005a80 classname=qemuDomainNetworkPrivate
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f6ffc19c400 classname=virDomainChrSourceDef
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f7038005ab0 classname=qemuDomainChrSourcePrivate
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f6ffc19c490 classname=virDomainChrSourceDef
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f7038005ae0 classname=qemuDomainChrSourcePrivate
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f705000d4d0 classname=qemuDomainGraphicsPrivate
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f7038005b10 classname=qemuDomainVideoPrivate
2021-02-25 11:03:46.569+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f7004114020
2021-02-25 11:03:46.569+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f7004114020
2021-02-25 11:03:46.569+0000: 17285: debug : qemuDomainAssignVirtioSerialAddresses:136 : Finished reserving existing ports
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:864 : PCI bus 0000:00 assigned isolation group 0 because of first device 0000:00:04.0
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:04.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:03.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:02.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:05.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:06.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.2 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.1 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.3 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:01 already in use
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:02 already in use
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:03 already in use
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:04 already in use
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:05 already in use
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:06 already in use
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressGetNextAddr:1234 : Found free PCI slot 0000:00:07
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:07.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:864 : PCI bus 0000:00 assigned isolation group 0 because of first device 0000:00:04.0
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:04.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:03.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:02.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:05.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:06.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.2 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.1 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.0 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.3 (aggregate='false')
2021-02-25 11:03:46.569+0000: 17285: debug : qemuDomainUSBAddressAddHubs:2999 : Found 1 USB devices and 2 provided USB ports; adding 0 hubs
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainUSBAddressSetAddController:2070 : Adding a USB controller model=piix3-uhci with 2 ports
2021-02-25 11:03:46.569+0000: 17285: debug : virDomainUSBAddressReserve:2404 : Reserving USB address bus=0 port=1
2021-02-25 11:03:46.569+0000: 17285: debug : qemuDomainAssignUSBAddresses:3138 : Existing USB addresses have been reserved
2021-02-25 11:03:46.569+0000: 17285: debug : qemuDomainAssignUSBAddresses:3146 : Finished assigning USB ports
2021-02-25 11:03:46.569+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f7038005b40 classname=qemuDomainNetworkPrivate
2021-02-25 11:03:46.570+0000: 17285: debug : virFileClose:135 : Closed fd 27
2021-02-25 11:03:46.570+0000: 17285: debug : virFileClose:135 : Closed fd 27
2021-02-25 11:03:46.570+0000: 17285: debug : virArchFromHost:232 : Mapped x86_64 to 34 (x86_64)
2021-02-25 11:03:46.570+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f70040f3250
2021-02-25 11:03:46.570+0000: 17285: debug : virQEMUCapsCacheLookup:5656 : Returning caps 0x7f70040f3250 for /usr/libexec/qemu-kvm
2021-02-25 11:03:46.570+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f7004114020
2021-02-25 11:03:46.570+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f700414dd00
2021-02-25 11:03:46.570+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f7004114020
2021-02-25 11:03:46.570+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f700414dd00
2021-02-25 11:03:46.570+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f70040f3250
2021-02-25 11:03:46.570+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f7004114020
2021-02-25 11:03:46.570+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f7004114020
2021-02-25 11:03:46.570+0000: 17285: debug : qemuDomainAssignVirtioSerialAddresses:136 : Finished reserving existing ports
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:864 : PCI bus 0000:00 assigned isolation group 0 because of first device 0000:00:04.0
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:04.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:03.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:02.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:05.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:06.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.2 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.1 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.3 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:01 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:02 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:03 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:04 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:05 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:06 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressGetNextAddr:1234 : Found free PCI slot 0000:00:07
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:07.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:01 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:02 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:03 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:04 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:05 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:06 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:07 already in use
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressGetNextAddr:1234 : Found free PCI slot 0000:00:08
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:08.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:864 : PCI bus 0000:00 assigned isolation group 0 because of first device 0000:00:04.0
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:04.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:03.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:02.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:05.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:06.0 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.2 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.1 (aggregate='false')
2021-02-25 11:03:46.570+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.0 (aggregate='false')
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:01.3 (aggregate='false')
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:01 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:02 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:03 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:04 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:05 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:06 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressGetNextAddr:1234 : Found free PCI slot 0000:00:07
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:07.0 (aggregate='false')
2021-02-25 11:03:46.571+0000: 17285: debug : qemuDomainUSBAddressAddHubs:2999 : Found 1 USB devices and 2 provided USB ports; adding 0 hubs
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainUSBAddressSetAddController:2070 : Adding a USB controller model=piix3-uhci with 2 ports
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainUSBAddressReserve:2404 : Reserving USB address bus=0 port=1
2021-02-25 11:03:46.571+0000: 17285: debug : qemuDomainAssignUSBAddresses:3138 : Existing USB addresses have been reserved
2021-02-25 11:03:46.571+0000: 17285: debug : qemuDomainAssignUSBAddresses:3146 : Finished assigning USB ports
2021-02-25 11:03:46.571+0000: 17285: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f7038005b70 classname=qemuDomainNetworkPrivate
2021-02-25 11:03:46.571+0000: 17285: debug : virFileClose:135 : Closed fd 27
2021-02-25 11:03:46.571+0000: 17285: debug : virFileClose:135 : Closed fd 27
2021-02-25 11:03:46.571+0000: 17285: debug : virArchFromHost:232 : Mapped x86_64 to 34 (x86_64)
2021-02-25 11:03:46.571+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f70040f3250
2021-02-25 11:03:46.571+0000: 17285: debug : virQEMUCapsCacheLookup:5656 : Returning caps 0x7f70040f3250 for /usr/libexec/qemu-kvm
2021-02-25 11:03:46.571+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f7004114020
2021-02-25 11:03:46.571+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f700414dd00
2021-02-25 11:03:46.571+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f7004114020
2021-02-25 11:03:46.571+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f700414dd00
2021-02-25 11:03:46.571+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f70040f3250
2021-02-25 11:03:46.571+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f7004114020
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:01 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:02 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:03 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:04 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:05 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressFindUnusedFunctionOnBus:1141 : PCI slot 0000:00:06 already in use
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressGetNextAddr:1234 : Found free PCI slot 0000:00:07
2021-02-25 11:03:46.571+0000: 17285: debug : virDomainPCIAddressReserveAddrInternal:881 : Reserving PCI address 0000:00:07.0 (aggregate='false')
2021-02-25 11:03:46.571+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f7004114020
2021-02-25 11:03:46.571+0000: 17285: info : virNetDevProbeVnetHdr:234 : Enabling IFF_VNET_HDR
2021-02-25 11:03:46.571+0000: 17267: debug : virNetlinkEventCallback:862 : dispatching to max 0 clients, called from event watch 7
2021-02-25 11:03:46.571+0000: 17267: debug : virNetlinkEventCallback:875 : event not handled.
2021-02-25 11:03:46.571+0000: 17267: debug : virNetlinkEventCallback:862 : dispatching to max 0 clients, called from event watch 7
2021-02-25 11:03:46.571+0000: 17267: debug : virNetlinkEventCallback:875 : event not handled.
2021-02-25 11:03:46.571+0000: 17303: debug : udevHandleOneDevice:1500 : udev action: 'add'
2021-02-25 11:03:46.571+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'DRIVER' value '<null>' for device with sysname 'tap409113d5-b2'
2021-02-25 11:03:46.571+0000: 17285: info : virNetDevTapCreate:403 : created device: 'tap409113d5-b2'
2021-02-25 11:03:46.571+0000: 17267: debug : virNetlinkEventCallback:862 : dispatching to max 0 clients, called from event watch 7
2021-02-25 11:03:46.571+0000: 17267: debug : virNetlinkEventCallback:875 : event not handled.
2021-02-25 11:03:46.571+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'SUBSYSTEM' value 'net' for device with sysname 'tap409113d5-b2'
2021-02-25 11:03:46.571+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'INTERFACE' value 'tap409113d5-b2' for device with sysname 'tap409113d5-b2'
2021-02-25 11:03:46.571+0000: 17303: debug : udevGetDeviceSysfsAttr:211 : Found sysfs attribute 'address' value 'fe:16:3e:aa:ce:9a' for device with sysname 'tap409113d5-b2'
2021-02-25 11:03:46.571+0000: 17285: debug : virNetDevSetMACInternal:280 : SIOCSIFHWADDR tap409113d5-b2 MAC=fe:16:3e:aa:ce:9a - Success
2021-02-25 11:03:46.571+0000: 17285: debug : virFileClose:135 : Closed fd 28
2021-02-25 11:03:46.571+0000: 17285: debug : virFileClose:135 : Closed fd 36
2021-02-25 11:03:46.571+0000: 17303: debug : udevGetDeviceSysfsAttr:211 : Found sysfs attribute 'addr_len' value '6' for device with sysname 'tap409113d5-b2'
2021-02-25 11:03:46.571+0000: 17285: debug : virFileClose:135 : Closed fd 28
2021-02-25 11:03:46.571+0000: 17303: debug : virFileClose:135 : Closed fd 28
2021-02-25 11:03:46.571+0000: 17285: debug : virCommandRunAsync:2618 : About to run ovs-vsctl --timeout=5 -- --if-exists del-port tap409113d5-b2 -- add-port br-int tap409113d5-b2 -- set Interface tap409113d5-b2 'external-ids:attached-mac="fa:16:3e:aa:ce:9a"' -- set Interface tap409113d5-b2 'external-ids:iface-id="409113d5-b275-48e8-8429-d08a06eb4caa"' -- set Interface tap409113d5-b2 'external-ids:vm-id="d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f"' -- set Interface tap409113d5-b2 external-ids:iface-status=active
2021-02-25 11:03:46.572+0000: 17303: debug : virFileClose:135 : Closed fd 28
2021-02-25 11:03:46.573+0000: 17285: debug : virFileClose:135 : Closed fd 36
2021-02-25 11:03:46.573+0000: 17285: debug : virFileClose:135 : Closed fd 37
2021-02-25 11:03:46.573+0000: 17285: debug : virFileClose:135 : Closed fd 39
2021-02-25 11:03:46.573+0000: 17285: debug : virCommandRunAsync:2621 : Command result 0, with PID 21403
2021-02-25 11:03:46.573+0000: 17303: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f704400fa50 classname=virNodeDeviceObj
2021-02-25 11:03:46.573+0000: 17303: info : virObjectRef:402 : OBJECT_REF: obj=0x7f704400fa50
2021-02-25 11:03:46.573+0000: 17303: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f6ff0006720 classname=virNodeDeviceEventLifecycle
2021-02-25 11:03:46.573+0000: 17303: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f704400fa50
2021-02-25 11:03:46.573+0000: 17303: info : vir_object_finalize:318 : OBJECT_DISPOSE: obj=0x7f6ff0006720
2021-02-25 11:03:46.573+0000: 17303: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0006720
2021-02-25 11:03:46.574+0000: 17303: debug : udevHandleOneDevice:1500 : udev action: 'add'
2021-02-25 11:03:46.574+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'DRIVER' value '<null>' for device with sysname 'rx-0'
2021-02-25 11:03:46.574+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'SUBSYSTEM' value 'queues' for device with sysname 'rx-0'
2021-02-25 11:03:46.574+0000: 17303: debug : udevGetDeviceType:1174 : Could not determine device type for device with sysfs name 'rx-0'
2021-02-25 11:03:46.574+0000: 17303: debug : udevAddOneDevice:1362 : Discarding device -1 0x7f6ff8004f10 /sys/devices/virtual/net/tap409113d5-b2/queues/rx-0
2021-02-25 11:03:46.574+0000: 17303: debug : udevHandleOneDevice:1500 : udev action: 'add'
2021-02-25 11:03:46.574+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'DRIVER' value '<null>' for device with sysname 'tx-0'
2021-02-25 11:03:46.574+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'SUBSYSTEM' value 'queues' for device with sysname 'tx-0'
2021-02-25 11:03:46.574+0000: 17303: debug : udevGetDeviceType:1174 : Could not determine device type for device with sysfs name 'tx-0'
2021-02-25 11:03:46.574+0000: 17303: debug : udevAddOneDevice:1362 : Discarding device -1 0x7f6ff8004f10 /sys/devices/virtual/net/tap409113d5-b2/queues/tx-0
2021-02-25 11:03:46.621+0000: 17285: debug : virCommandRun:2463 : Result status 0, stdout: '' stderr: ''
2021-02-25 11:03:46.621+0000: 17285: debug : virFileClose:135 : Closed fd 28
2021-02-25 11:03:46.621+0000: 17285: debug : virFileClose:135 : Closed fd 38
2021-02-25 11:03:46.621+0000: 17285: debug : virFileClose:135 : Closed fd 28
2021-02-25 11:03:46.621+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f7004114020
2021-02-25 11:03:46.621+0000: 17285: debug : virFileClose:135 : Closed fd 28
2021-02-25 11:03:46.621+0000: 17285: debug : qemuDomainObjEnterMonitorInternal:5495 : Entering monitor (mon=0x7f6ff0004440 vm=0x7f7004116970 name=instance-00000018)
2021-02-25 11:03:46.621+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.621+0000: 17285: debug : qemuMonitorAddNetdev:2693 : props=0x7f705a59b690 tapfd=0x7f70500193f0 tapfdName=0x7f7050024000 tapfdSize=1vhostfd=0x7f705001f2c0 vhostfdName=(nil) vhostfdSize=0slirpfd=-1 slirpfdName=(null)
2021-02-25 11:03:46.621+0000: 17285: debug : qemuMonitorAddNetdev:2695 : mon:0x7f6ff0004440 vm:0x7f7004116970 fd:34
2021-02-25 11:03:46.621+0000: 17285: debug : qemuMonitorSendFileHandle:2644 : fdname=fd-net10 fd=27
2021-02-25 11:03:46.621+0000: 17285: debug : qemuMonitorSendFileHandle:2646 : mon:0x7f6ff0004440 vm:0x7f7004116970 fd:34
2021-02-25 11:03:46.621+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.621+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.621+0000: 17285: info : qemuMonitorSend:946 : QEMU_MONITOR_SEND_MSG: mon=0x7f6ff0004440 msg={"execute":"getfd","arguments":{"fdname":"fd-net10"},"id":"libvirt-374"}
fd=27
2021-02-25 11:03:46.621+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.621+0000: 17797: info : qemuMonitorIOWrite:433 : QEMU_MONITOR_IO_WRITE: mon=0x7f6ff0004440 buf={"execute":"getfd","arguments":{"fdname":"fd-net10"},"id":"libvirt-374"}
len=74 ret=74 errno=0
2021-02-25 11:03:46.622+0000: 17797: info : qemuMonitorIOWrite:438 : QEMU_MONITOR_IO_SEND_FD: mon=0x7f6ff0004440 fd=27 ret=74 errno=0
2021-02-25 11:03:46.622+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.622+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.622+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.622+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.622+0000: 17797: debug : qemuMonitorJSONIOProcessLine:220 : Line [{"return": {}, "id": "libvirt-374"}]
2021-02-25 11:03:46.623+0000: 17797: info : qemuMonitorJSONIOProcessLine:240 : QEMU_MONITOR_RECV_REPLY: mon=0x7f6ff0004440 reply={"return": {}, "id": "libvirt-374"}
2021-02-25 11:03:46.623+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17285: info : qemuMonitorSend:946 : QEMU_MONITOR_SEND_MSG: mon=0x7f6ff0004440 msg={"execute":"netdev_add","arguments":{"type":"tap","fd":"fd-net10","id":"hostnet1"},"id":"libvirt-375"}
fd=-1
2021-02-25 11:03:46.623+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17797: info : qemuMonitorIOWrite:433 : QEMU_MONITOR_IO_WRITE: mon=0x7f6ff0004440 buf={"execute":"netdev_add","arguments":{"type":"tap","fd":"fd-net10","id":"hostnet1"},"id":"libvirt-375"}
len=104 ret=104 errno=0
2021-02-25 11:03:46.623+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.623+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17797: debug : qemuMonitorJSONIOProcessLine:220 : Line [{"return": {}, "id": "libvirt-375"}]
2021-02-25 11:03:46.624+0000: 17797: info : qemuMonitorJSONIOProcessLine:240 : QEMU_MONITOR_RECV_REPLY: mon=0x7f6ff0004440 reply={"return": {}, "id": "libvirt-375"}
2021-02-25 11:03:46.624+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17285: debug : qemuDomainObjExitMonitorInternal:5520 : Exited monitor (mon=0x7f6ff0004440 vm=0x7f7004116970 name=instance-00000018)
2021-02-25 11:03:46.624+0000: 17285: debug : virFileClose:135 : Closed fd 27
2021-02-25 11:03:46.624+0000: 17285: debug : qemuDomainObjEnterMonitorInternal:5495 : Entering monitor (mon=0x7f6ff0004440 vm=0x7f7004116970 name=instance-00000018)
2021-02-25 11:03:46.624+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17285: debug : qemuMonitorAddDeviceWithFd:2841 : device=virtio-net-pci,host_mtu=1442,netdev=hostnet1,id=net1,mac=fa:16:3e:aa:ce:9a,bus=pci.0,addr=0x7 fd=-1 fdname=<null>
2021-02-25 11:03:46.624+0000: 17285: debug : qemuMonitorAddDeviceWithFd:2844 : mon:0x7f6ff0004440 vm:0x7f7004116970 fd:34
2021-02-25 11:03:46.624+0000: 17285: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17285: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17285: info : qemuMonitorSend:946 : QEMU_MONITOR_SEND_MSG: mon=0x7f6ff0004440 msg={"execute":"device_add","arguments":{"driver":"virtio-net-pci","host_mtu":"1442","netdev":"hostnet1","id":"net1","mac":"fa:16:3e:aa:ce:9a","bus":"pci.0","addr":"0x7"},"id":"libvirt-376"}
fd=-1
2021-02-25 11:03:46.624+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17797: info : qemuMonitorIOWrite:433 : QEMU_MONITOR_IO_WRITE: mon=0x7f6ff0004440 buf={"execute":"device_add","arguments":{"driver":"virtio-net-pci","host_mtu":"1442","netdev":"hostnet1","id":"net1","mac":"fa:16:3e:aa:ce:9a","bus":"pci.0","addr":"0x7"},"id":"libvirt-376"}
len=188 ret=188 errno=0
2021-02-25 11:03:46.624+0000: 17797: info : virObjectRef:402 : OBJECT_REF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.624+0000: 17797: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff0004440
2021-02-25 11:03:46.920+0000: 17267: debug : virNetlinkEventCallback:862 : dispatching to max 0 clients, called from event watch 7
2021-02-25 11:03:46.920+0000: 17267: debug : virNetlinkEventCallback:875 : event not handled.
2021-02-25 11:03:46.920+0000: 17267: debug : virNetlinkEventCallback:862 : dispatching to max 0 clients, called from event watch 7
2021-02-25 11:03:46.920+0000: 17267: debug : virNetlinkEventCallback:875 : event not handled.
2021-02-25 11:03:46.920+0000: 17303: debug : udevHandleOneDevice:1500 : udev action: 'add'
2021-02-25 11:03:46.920+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'DRIVER' value '<null>' for device with sysname 'tapddba2bff-00'
2021-02-25 11:03:46.920+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'SUBSYSTEM' value 'net' for device with sysname 'tapddba2bff-00'
2021-02-25 11:03:46.920+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'INTERFACE' value 'tapddba2bff-00' for device with sysname 'tapddba2bff-00'
2021-02-25 11:03:46.920+0000: 17267: debug : virNetlinkEventCallback:862 : dispatching to max 0 clients, called from event watch 7
2021-02-25 11:03:46.920+0000: 17267: debug : virNetlinkEventCallback:875 : event not handled.
2021-02-25 11:03:46.920+0000: 17303: debug : udevGetDeviceSysfsAttr:211 : Found sysfs attribute 'address' value '1e:3e:df:a6:d7:f1' for device with sysname 'tapddba2bff-00'
2021-02-25 11:03:46.920+0000: 17303: debug : udevGetDeviceSysfsAttr:211 : Found sysfs attribute 'addr_len' value '6' for device with sysname 'tapddba2bff-00'
2021-02-25 11:03:46.921+0000: 17303: debug : virFileClose:135 : Closed fd 27
2021-02-25 11:03:46.921+0000: 17303: debug : virFileClose:135 : Closed fd 27
2021-02-25 11:03:46.921+0000: 17303: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f704400fab0 classname=virNodeDeviceObj
2021-02-25 11:03:46.921+0000: 17303: info : virObjectRef:402 : OBJECT_REF: obj=0x7f704400fab0
2021-02-25 11:03:46.921+0000: 17303: info : virObjectNew:259 : OBJECT_NEW: obj=0x7f6ff8008050 classname=virNodeDeviceEventLifecycle
2021-02-25 11:03:46.921+0000: 17303: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f704400fab0
2021-02-25 11:03:46.921+0000: 17303: info : vir_object_finalize:318 : OBJECT_DISPOSE: obj=0x7f6ff8008050
2021-02-25 11:03:46.921+0000: 17303: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x7f6ff8008050
2021-02-25 11:03:46.921+0000: 17303: debug : udevHandleOneDevice:1500 : udev action: 'add'
2021-02-25 11:03:46.921+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'DRIVER' value '<null>' for device with sysname 'rx-0'
2021-02-25 11:03:46.921+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'SUBSYSTEM' value 'queues' for device with sysname 'rx-0'
2021-02-25 11:03:46.921+0000: 17303: debug : udevGetDeviceType:1174 : Could not determine device type for device with sysfs name 'rx-0'
2021-02-25 11:03:46.921+0000: 17303: debug : udevAddOneDevice:1362 : Discarding device -1 0x7f6ff8004700 /sys/devices/virtual/net/tapddba2bff-00/queues/rx-0
2021-02-25 11:03:46.921+0000: 17303: debug : udevHandleOneDevice:1500 : udev action: 'add'
2021-02-25 11:03:46.921+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'DRIVER' value '<null>' for device with sysname 'tx-0'
2021-02-25 11:03:46.921+0000: 17303: debug : udevGetDeviceProperty:145 : Found property key 'SUBSYSTEM' value 'queues' for device with sysname 'tx-0'
2021-02-25 11:03:46.921+0000: 17303: debug : udevGetDeviceType:1174 : Could not determine device type for device with sysfs name 'tx-0'
2021-02-25 11:03:46.921+0000: 17303: debug : udevAddOneDevice:1362 : Discarding device -1 0x7f6ff8004700 /sys/devices/virtual/net/tapddba2bff-00/queues/tx-0
2021-02-25 11:03:51.573+0000: 17267: info : virObjectRef:402 : OBJECT_REF: obj=0x5561fdcb48d0
2021-02-25 11:03:51.573+0000: 17267: info : virObjectUnref:380 : OBJECT_UNREF: obj=0x5561fdcb48d0
2021-02-25 11:03:53.517+0000: 17267: info : virObjectRef:402 : OBJECT_REF: obj=0x5561fdcb6080 |
Description
===========
Centos 8.3 Host - failed to attach second NIC on 1 vcpu ubuntu guests with qemu-kvm-5.1.0-14.el8.1.x86_64
Downgrading to qemu-kvm-4.2.0-29.el8.3.x86_64 fixes the problem.
First seen in Octavia:
http://lists.openstack.org/pipermail/openstack-discuss/2021-February/020218.html
https://storyboard.openstack.org/#!/story/2008651
Steps to reproduce
==================
Kayobe (kolla-ansible under the hood) deployed all-in-one on baremetal:
https://docs.openstack.org/kayobe/latest/contributor/automated.html#overcloud
ubuntu images - https://cloud-images.ubuntu.com/focal/current/focal-server-cloudimg-amd64.img
Problem reproduced on bionic, focal, groovy and hirsute.
Failing flavor - 1 VCPU - 16G RAM
Working flavor - 2 VCPUs - 1G RAM
openstack server create --flavor 16g --image focal --config-drive True --key-name test --network demo-net testvm16g
openstack --debug server add port testvm16g testvm1port
Expected result
===============
Proper attachment of NIC to VM
Actual result
=============
novaclient.exceptions.ClientException: Unknown Error (HTTP 504)
clean_up AddPort: Unknown Error (HTTP 504)
Environment
===========
1. Openstack Ussuri
openstack-nova-compute-21.1.2-1.el8.noarch
openstack-nova-common-21.1.2-1.el8.noarch
2. Which hypervisor did you use?
Centos 8.3 - Libvirt + KVM
2. Which storage type did you use?
SSD with ext4
3. Which networking type did you use?
Tested on Neutron with OpenVSwitch, and Neutron with OVN
Logs & Configs
==============
Libvirt/Qemu logs are here:
http://paste.openstack.org/show/802996/
openstack --debug server add port testvm16g testvm1port
Network client initialized using OpenStack SDK: <openstack.network.v2._proxy.Proxy object at 0x7ff4d30e7cf8>
REQ: curl -g -i -X GET http://192.168.33.2:9696/v2.0/ports/testvm1port -H "User-Agent: openstacksdk/0.46.0 keystoneauth1/4.0.0 python-requests/2.23.0 CPython/3.6.8" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d"
Starting new HTTP connection (1): 192.168.33.2:9696
http://192.168.33.2:9696 "GET /v2.0/ports/testvm1port HTTP/1.1" 404 107
RESP: [404] Connection: keep-alive Content-Length: 107 Content-Type: application/json Date: Thu, 25 Feb 2021 11:03:44 GMT X-Openstack-Request-Id: req-ba52034b-d259-44dc-a87f-93a26c9479f0
RESP BODY: {"NeutronError": {"type": "PortNotFound", "message": "Port testvm1port could not be found.", "detail": ""}}
GET call to network for http://192.168.33.2:9696/v2.0/ports/testvm1port used request id req-ba52034b-d259-44dc-a87f-93a26c9479f0
REQ: curl -g -i -X GET "http://192.168.33.2:9696/v2.0/ports?name=testvm1port" -H "Accept: application/json" -H "User-Agent: openstacksdk/0.46.0 keystoneauth1/4.0.0 python-requests/2.23.0 CPython/3.6.8" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d"
http://192.168.33.2:9696 "GET /v2.0/ports?name=testvm1port HTTP/1.1" 200 805
RESP: [200] Connection: keep-alive Content-Length: 805 Content-Type: application/json Date: Thu, 25 Feb 2021 11:03:44 GMT X-Openstack-Request-Id: req-68eebc47-6a29-4c0c-ab35-26bd8138676c
RESP BODY: {"ports":[{"id":"409113d5-b275-48e8-8429-d08a06eb4caa","name":"testvm1port","network_id":"45c000ba-d770-48e3-8a83-5950c60e8a1d","tenant_id":"19303d9afcc4447b8985e7011add0d3d","mac_address":"fa:16:3e:aa:ce:9a","admin_state_up":true,"status":"DOWN","device_id":"","device_owner":"","fixed_ips":[{"subnet_id":"19164ffe-2c52-4233-b916-8448ee1e42a0","ip_address":"192.0.2.178"}],"allowed_address_pairs":[],"extra_dhcp_opts":[],"security_groups":["c997fbce-9065-47f5-9738-e311969c1db6"],"description":"","binding:vnic_type":"normal","binding:profile":{},"binding:host_id":"","binding:vif_type":"unbound","binding:vif_details":{},"port_security_enabled":true,"tags":[],"created_at":"2021-02-24T13:45:38Z","updated_at":"2021-02-25T10:06:27Z","revision_number":91,"project_id":"19303d9afcc4447b8985e7011add0d3d"}]}
GET call to network for http://192.168.33.2:9696/v2.0/ports?name=testvm1port used request id req-68eebc47-6a29-4c0c-ab35-26bd8138676c
REQ: curl -g -i -X POST http://192.168.33.2:8774/v2.1/servers/d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f/os-interface -H "Accept: application/json" -H "Content-Type: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d" -H "X-OpenStack-Nova-API-Version: 2.1" -d '{"interfaceAttachment": {"port_id": "409113d5-b275-48e8-8429-d08a06eb4caa"}}'
http://192.168.33.2:8774 "POST /v2.1/servers/d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f/os-interface HTTP/1.1" 504 None
RESP: [504] Cache-Control: no-cache Connection: close Content-Type: text/html
RESP BODY: Omitted, Content-Type is set to text/html. Only application/json responses have their bodies logged.
Unknown Error (HTTP 504)
Traceback (most recent call last):
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/cliff/app.py", line 401, in run_subcommand
result = cmd.run(parsed_args)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/osc_lib/command/command.py", line 41, in run
return super(Command, self).run(parsed_args)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/cliff/command.py", line 185, in run
return_code = self.take_action(parsed_args) or 0
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/openstackclient/compute/v2/server.py", line 359, in take_action
server.interface_attach(port_id=port_id, net_id=None, fixed_ip=None)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/api_versions.py", line 393, in substitution
return methods[-1].func(obj, *args, **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/v2/servers.py", line 610, in interface_attach
return self.manager.interface_attach(self, port_id, net_id, fixed_ip)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/api_versions.py", line 393, in substitution
return methods[-1].func(obj, *args, **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/v2/servers.py", line 2063, in interface_attach
obj_class=NetworkInterface)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/base.py", line 363, in _create
resp, body = self.api.client.post(url, body=body)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/keystoneauth1/adapter.py", line 392, in post
return self.request(url, 'POST', **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/client.py", line 78, in request
raise exceptions.from_response(resp, body, url, method)
novaclient.exceptions.ClientException: Unknown Error (HTTP 504)
clean_up AddPort: Unknown Error (HTTP 504)
END return value: 1
nova-compute:
2021-02-25 11:03:46.549 7 DEBUG nova.network.os_vif_util [req-f47d8eee-0beb-4890-af38-e0d78cbfae88 8d64a09fc978483a9c9a64d71d863fb8 19303d9afcc4447b8985e7011add0d3d - default default] Converted object VIFOpenVSwitch(active=False,address=fa:16:3e:aa:ce:9a,bridge_name='br-int',has_traffic_filtering=True,id=409113d5-b275-48e8-8429-d08a06eb4caa,network=Network(45c000ba-d770-48e3-8a83-5950c60e8a1d),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap409113d5-b2') nova_to_osvif_vif /usr/lib/python3.6/site-packages/nova/network/os_vif_util.py:538
2021-02-25 11:03:46.567 7 DEBUG nova.virt.libvirt.guest [req-f47d8eee-0beb-4890-af38-e0d78cbfae88 8d64a09fc978483a9c9a64d71d863fb8 19303d9afcc4447b8985e7011add0d3d - default default] attach device xml: <interface type="bridge">
<mac address="fa:16:3e:aa:ce:9a"/>
<model type="virtio"/>
<driver name="qemu"/>
<source bridge="br-int"/>
<mtu size="1442"/>
<target dev="tap409113d5-b2"/>
<virtualport type="openvswitch">
<parameters interfaceid="409113d5-b275-48e8-8429-d08a06eb4caa"/>
</virtualport>
</interface>
attach_device /usr/lib/python3.6/site-packages/nova/virt/libvirt/guest.py:292
2021-02-25 11:03:47.004 7 DEBUG nova.network.neutron [req-9ec4dc24-3aec-44c9-bb3d-3b4f9a398bc9 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Updated VIF entry in instance network info cache for port 409113d5-b275-48e8-8429-d08a06eb4caa. _build_network_info_model /usr/lib/python3.6/site-packages/nova/network/neutron.py:3157
2021-02-25 11:03:47.005 7 DEBUG nova.network.neutron [req-9ec4dc24-3aec-44c9-bb3d-3b4f9a398bc9 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Updating instance_info_cache with network_info: [{"id": "3dd3e38a-45ad-4e67-8b04-a9bb18ed372a", "address": "fa:16:3e:7d:98:04", "network": {"id": "dac630c1-4d4d-42b7-b2c7-f110697dc999", "bridge": "br-int", "label": "demo-net", "subnets": [{"cidr": "10.0.0.0/24", "dns": [{"address": "8.8.8.8", "type": "dns", "version": 4, "meta": {}}], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.174", "type": "fixed", "version": 4, "meta": {}, "floating_ips": [{"address": "192.168.33.96", "type": "floating", "version": 4, "meta": {}}]}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.2"}}], "meta": {"injected": false, "tenant_id": "19303d9afcc4447b8985e7011add0d3d", "mtu": null, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true}, "devname": "tap3dd3e38a-45", "ovs_interfaceid": "3dd3e38a-45ad-4e67-8b04-a9bb18ed372a", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "meta": {}}, {"id": "409113d5-b275-48e8-8429-d08a06eb4caa", "address": "fa:16:3e:aa:ce:9a", "network": {"id": "45c000ba-d770-48e3-8a83-5950c60e8a1d", "bridge": "br-int", "label": "test-net", "subnets": [{"cidr": "192.0.2.0/24", "dns": [], "gateway": {"address": "192.0.2.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "192.0.2.178", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "192.0.2.2"}}], "meta": {"injected": false, "tenant_id": "19303d9afcc4447b8985e7011add0d3d", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true}, "devname": "tap409113d5-b2", "ovs_interfaceid": "409113d5-b275-48e8-8429-d08a06eb4caa", "qbh_params": null, "qbg_params": null, "active": false, "vnic_type": "normal", "profile": {}, "preserve_on_delete": true, "meta": {}}] update_instance_cache_with_nw_info /usr/lib/python3.6/site-packages/nova/network/neutron.py:119
2021-02-25 11:03:48.335 7 WARNING nova.compute.manager [req-2a330fc9-9bef-4f78-84cd-8b6a9e0158a8 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Received unexpected event network-vif-plugged-409113d5-b275-48e8-8429-d08a06eb4caa for instance with vm_state active and task_state None. |
|
| 2021-02-25 11:30:54 |
Bartosz Bezak |
description |
Description
===========
Centos 8.3 Host - failed to attach second NIC on 1 vcpu ubuntu guests with qemu-kvm-5.1.0-14.el8.1.x86_64
Downgrading to qemu-kvm-4.2.0-29.el8.3.x86_64 fixes the problem.
First seen in Octavia:
http://lists.openstack.org/pipermail/openstack-discuss/2021-February/020218.html
https://storyboard.openstack.org/#!/story/2008651
Steps to reproduce
==================
Kayobe (kolla-ansible under the hood) deployed all-in-one on baremetal:
https://docs.openstack.org/kayobe/latest/contributor/automated.html#overcloud
ubuntu images - https://cloud-images.ubuntu.com/focal/current/focal-server-cloudimg-amd64.img
Problem reproduced on bionic, focal, groovy and hirsute.
Failing flavor - 1 VCPU - 16G RAM
Working flavor - 2 VCPUs - 1G RAM
openstack server create --flavor 16g --image focal --config-drive True --key-name test --network demo-net testvm16g
openstack --debug server add port testvm16g testvm1port
Expected result
===============
Proper attachment of NIC to VM
Actual result
=============
novaclient.exceptions.ClientException: Unknown Error (HTTP 504)
clean_up AddPort: Unknown Error (HTTP 504)
Environment
===========
1. Openstack Ussuri
openstack-nova-compute-21.1.2-1.el8.noarch
openstack-nova-common-21.1.2-1.el8.noarch
2. Which hypervisor did you use?
Centos 8.3 - Libvirt + KVM
2. Which storage type did you use?
SSD with ext4
3. Which networking type did you use?
Tested on Neutron with OpenVSwitch, and Neutron with OVN
Logs & Configs
==============
Libvirt/Qemu logs are here:
http://paste.openstack.org/show/802996/
openstack --debug server add port testvm16g testvm1port
Network client initialized using OpenStack SDK: <openstack.network.v2._proxy.Proxy object at 0x7ff4d30e7cf8>
REQ: curl -g -i -X GET http://192.168.33.2:9696/v2.0/ports/testvm1port -H "User-Agent: openstacksdk/0.46.0 keystoneauth1/4.0.0 python-requests/2.23.0 CPython/3.6.8" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d"
Starting new HTTP connection (1): 192.168.33.2:9696
http://192.168.33.2:9696 "GET /v2.0/ports/testvm1port HTTP/1.1" 404 107
RESP: [404] Connection: keep-alive Content-Length: 107 Content-Type: application/json Date: Thu, 25 Feb 2021 11:03:44 GMT X-Openstack-Request-Id: req-ba52034b-d259-44dc-a87f-93a26c9479f0
RESP BODY: {"NeutronError": {"type": "PortNotFound", "message": "Port testvm1port could not be found.", "detail": ""}}
GET call to network for http://192.168.33.2:9696/v2.0/ports/testvm1port used request id req-ba52034b-d259-44dc-a87f-93a26c9479f0
REQ: curl -g -i -X GET "http://192.168.33.2:9696/v2.0/ports?name=testvm1port" -H "Accept: application/json" -H "User-Agent: openstacksdk/0.46.0 keystoneauth1/4.0.0 python-requests/2.23.0 CPython/3.6.8" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d"
http://192.168.33.2:9696 "GET /v2.0/ports?name=testvm1port HTTP/1.1" 200 805
RESP: [200] Connection: keep-alive Content-Length: 805 Content-Type: application/json Date: Thu, 25 Feb 2021 11:03:44 GMT X-Openstack-Request-Id: req-68eebc47-6a29-4c0c-ab35-26bd8138676c
RESP BODY: {"ports":[{"id":"409113d5-b275-48e8-8429-d08a06eb4caa","name":"testvm1port","network_id":"45c000ba-d770-48e3-8a83-5950c60e8a1d","tenant_id":"19303d9afcc4447b8985e7011add0d3d","mac_address":"fa:16:3e:aa:ce:9a","admin_state_up":true,"status":"DOWN","device_id":"","device_owner":"","fixed_ips":[{"subnet_id":"19164ffe-2c52-4233-b916-8448ee1e42a0","ip_address":"192.0.2.178"}],"allowed_address_pairs":[],"extra_dhcp_opts":[],"security_groups":["c997fbce-9065-47f5-9738-e311969c1db6"],"description":"","binding:vnic_type":"normal","binding:profile":{},"binding:host_id":"","binding:vif_type":"unbound","binding:vif_details":{},"port_security_enabled":true,"tags":[],"created_at":"2021-02-24T13:45:38Z","updated_at":"2021-02-25T10:06:27Z","revision_number":91,"project_id":"19303d9afcc4447b8985e7011add0d3d"}]}
GET call to network for http://192.168.33.2:9696/v2.0/ports?name=testvm1port used request id req-68eebc47-6a29-4c0c-ab35-26bd8138676c
REQ: curl -g -i -X POST http://192.168.33.2:8774/v2.1/servers/d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f/os-interface -H "Accept: application/json" -H "Content-Type: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d" -H "X-OpenStack-Nova-API-Version: 2.1" -d '{"interfaceAttachment": {"port_id": "409113d5-b275-48e8-8429-d08a06eb4caa"}}'
http://192.168.33.2:8774 "POST /v2.1/servers/d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f/os-interface HTTP/1.1" 504 None
RESP: [504] Cache-Control: no-cache Connection: close Content-Type: text/html
RESP BODY: Omitted, Content-Type is set to text/html. Only application/json responses have their bodies logged.
Unknown Error (HTTP 504)
Traceback (most recent call last):
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/cliff/app.py", line 401, in run_subcommand
result = cmd.run(parsed_args)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/osc_lib/command/command.py", line 41, in run
return super(Command, self).run(parsed_args)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/cliff/command.py", line 185, in run
return_code = self.take_action(parsed_args) or 0
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/openstackclient/compute/v2/server.py", line 359, in take_action
server.interface_attach(port_id=port_id, net_id=None, fixed_ip=None)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/api_versions.py", line 393, in substitution
return methods[-1].func(obj, *args, **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/v2/servers.py", line 610, in interface_attach
return self.manager.interface_attach(self, port_id, net_id, fixed_ip)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/api_versions.py", line 393, in substitution
return methods[-1].func(obj, *args, **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/v2/servers.py", line 2063, in interface_attach
obj_class=NetworkInterface)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/base.py", line 363, in _create
resp, body = self.api.client.post(url, body=body)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/keystoneauth1/adapter.py", line 392, in post
return self.request(url, 'POST', **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/client.py", line 78, in request
raise exceptions.from_response(resp, body, url, method)
novaclient.exceptions.ClientException: Unknown Error (HTTP 504)
clean_up AddPort: Unknown Error (HTTP 504)
END return value: 1
nova-compute:
2021-02-25 11:03:46.549 7 DEBUG nova.network.os_vif_util [req-f47d8eee-0beb-4890-af38-e0d78cbfae88 8d64a09fc978483a9c9a64d71d863fb8 19303d9afcc4447b8985e7011add0d3d - default default] Converted object VIFOpenVSwitch(active=False,address=fa:16:3e:aa:ce:9a,bridge_name='br-int',has_traffic_filtering=True,id=409113d5-b275-48e8-8429-d08a06eb4caa,network=Network(45c000ba-d770-48e3-8a83-5950c60e8a1d),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap409113d5-b2') nova_to_osvif_vif /usr/lib/python3.6/site-packages/nova/network/os_vif_util.py:538
2021-02-25 11:03:46.567 7 DEBUG nova.virt.libvirt.guest [req-f47d8eee-0beb-4890-af38-e0d78cbfae88 8d64a09fc978483a9c9a64d71d863fb8 19303d9afcc4447b8985e7011add0d3d - default default] attach device xml: <interface type="bridge">
<mac address="fa:16:3e:aa:ce:9a"/>
<model type="virtio"/>
<driver name="qemu"/>
<source bridge="br-int"/>
<mtu size="1442"/>
<target dev="tap409113d5-b2"/>
<virtualport type="openvswitch">
<parameters interfaceid="409113d5-b275-48e8-8429-d08a06eb4caa"/>
</virtualport>
</interface>
attach_device /usr/lib/python3.6/site-packages/nova/virt/libvirt/guest.py:292
2021-02-25 11:03:47.004 7 DEBUG nova.network.neutron [req-9ec4dc24-3aec-44c9-bb3d-3b4f9a398bc9 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Updated VIF entry in instance network info cache for port 409113d5-b275-48e8-8429-d08a06eb4caa. _build_network_info_model /usr/lib/python3.6/site-packages/nova/network/neutron.py:3157
2021-02-25 11:03:47.005 7 DEBUG nova.network.neutron [req-9ec4dc24-3aec-44c9-bb3d-3b4f9a398bc9 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Updating instance_info_cache with network_info: [{"id": "3dd3e38a-45ad-4e67-8b04-a9bb18ed372a", "address": "fa:16:3e:7d:98:04", "network": {"id": "dac630c1-4d4d-42b7-b2c7-f110697dc999", "bridge": "br-int", "label": "demo-net", "subnets": [{"cidr": "10.0.0.0/24", "dns": [{"address": "8.8.8.8", "type": "dns", "version": 4, "meta": {}}], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.174", "type": "fixed", "version": 4, "meta": {}, "floating_ips": [{"address": "192.168.33.96", "type": "floating", "version": 4, "meta": {}}]}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.2"}}], "meta": {"injected": false, "tenant_id": "19303d9afcc4447b8985e7011add0d3d", "mtu": null, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true}, "devname": "tap3dd3e38a-45", "ovs_interfaceid": "3dd3e38a-45ad-4e67-8b04-a9bb18ed372a", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "meta": {}}, {"id": "409113d5-b275-48e8-8429-d08a06eb4caa", "address": "fa:16:3e:aa:ce:9a", "network": {"id": "45c000ba-d770-48e3-8a83-5950c60e8a1d", "bridge": "br-int", "label": "test-net", "subnets": [{"cidr": "192.0.2.0/24", "dns": [], "gateway": {"address": "192.0.2.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "192.0.2.178", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "192.0.2.2"}}], "meta": {"injected": false, "tenant_id": "19303d9afcc4447b8985e7011add0d3d", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true}, "devname": "tap409113d5-b2", "ovs_interfaceid": "409113d5-b275-48e8-8429-d08a06eb4caa", "qbh_params": null, "qbg_params": null, "active": false, "vnic_type": "normal", "profile": {}, "preserve_on_delete": true, "meta": {}}] update_instance_cache_with_nw_info /usr/lib/python3.6/site-packages/nova/network/neutron.py:119
2021-02-25 11:03:48.335 7 WARNING nova.compute.manager [req-2a330fc9-9bef-4f78-84cd-8b6a9e0158a8 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Received unexpected event network-vif-plugged-409113d5-b275-48e8-8429-d08a06eb4caa for instance with vm_state active and task_state None. |
Description
===========
Centos 8.3 Host - failed to attach second NIC on 1 vcpu ubuntu guests with qemu-kvm-5.1.0-14.el8.1.x86_64
Downgrading to qemu-kvm-4.2.0-29.el8.3.x86_64 fixes the problem.
First seen in Octavia:
http://lists.openstack.org/pipermail/openstack-discuss/2021-February/020218.html
https://storyboard.openstack.org/#!/story/2008651
Steps to reproduce
==================
Kayobe (kolla-ansible under the hood) deployed all-in-one on baremetal:
https://docs.openstack.org/kayobe/latest/contributor/automated.html#overcloud
ubuntu images - https://cloud-images.ubuntu.com/focal/current/focal-server-cloudimg-amd64.img
Problem reproduced on bionic, focal, groovy and hirsute.
Failing flavor - 1 VCPU - 16G RAM
Working flavor - 2 VCPUs - 1G RAM
openstack server create --flavor 16g --image focal --config-drive True --key-name test --network demo-net testvm16g
openstack --debug server add port testvm16g testvm1port
Expected result
===============
Proper attachment of NIC to VM
Actual result
=============
novaclient.exceptions.ClientException: Unknown Error (HTTP 504)
clean_up AddPort: Unknown Error (HTTP 504)
Environment
===========
1. Openstack Ussuri
openstack-nova-compute-21.1.2-1.el8.noarch
openstack-nova-common-21.1.2-1.el8.noarch
2. Which hypervisor did you use?
Centos 8.3 - Libvirt + KVM
2. Which storage type did you use?
SSD with ext4
3. Which networking type did you use?
Tested on Neutron with OpenVSwitch, and Neutron with OVN
Logs & Configs
==============
Libvirt/Qemu logs are here:
http://paste.openstack.org/show/802996/
######################
openstack --debug server add port testvm16g testvm1port
Network client initialized using OpenStack SDK: <openstack.network.v2._proxy.Proxy object at 0x7ff4d30e7cf8>
REQ: curl -g -i -X GET http://192.168.33.2:9696/v2.0/ports/testvm1port -H "User-Agent: openstacksdk/0.46.0 keystoneauth1/4.0.0 python-requests/2.23.0 CPython/3.6.8" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d"
Starting new HTTP connection (1): 192.168.33.2:9696
http://192.168.33.2:9696 "GET /v2.0/ports/testvm1port HTTP/1.1" 404 107
RESP: [404] Connection: keep-alive Content-Length: 107 Content-Type: application/json Date: Thu, 25 Feb 2021 11:03:44 GMT X-Openstack-Request-Id: req-ba52034b-d259-44dc-a87f-93a26c9479f0
RESP BODY: {"NeutronError": {"type": "PortNotFound", "message": "Port testvm1port could not be found.", "detail": ""}}
GET call to network for http://192.168.33.2:9696/v2.0/ports/testvm1port used request id req-ba52034b-d259-44dc-a87f-93a26c9479f0
REQ: curl -g -i -X GET "http://192.168.33.2:9696/v2.0/ports?name=testvm1port" -H "Accept: application/json" -H "User-Agent: openstacksdk/0.46.0 keystoneauth1/4.0.0 python-requests/2.23.0 CPython/3.6.8" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d"
http://192.168.33.2:9696 "GET /v2.0/ports?name=testvm1port HTTP/1.1" 200 805
RESP: [200] Connection: keep-alive Content-Length: 805 Content-Type: application/json Date: Thu, 25 Feb 2021 11:03:44 GMT X-Openstack-Request-Id: req-68eebc47-6a29-4c0c-ab35-26bd8138676c
RESP BODY: {"ports":[{"id":"409113d5-b275-48e8-8429-d08a06eb4caa","name":"testvm1port","network_id":"45c000ba-d770-48e3-8a83-5950c60e8a1d","tenant_id":"19303d9afcc4447b8985e7011add0d3d","mac_address":"fa:16:3e:aa:ce:9a","admin_state_up":true,"status":"DOWN","device_id":"","device_owner":"","fixed_ips":[{"subnet_id":"19164ffe-2c52-4233-b916-8448ee1e42a0","ip_address":"192.0.2.178"}],"allowed_address_pairs":[],"extra_dhcp_opts":[],"security_groups":["c997fbce-9065-47f5-9738-e311969c1db6"],"description":"","binding:vnic_type":"normal","binding:profile":{},"binding:host_id":"","binding:vif_type":"unbound","binding:vif_details":{},"port_security_enabled":true,"tags":[],"created_at":"2021-02-24T13:45:38Z","updated_at":"2021-02-25T10:06:27Z","revision_number":91,"project_id":"19303d9afcc4447b8985e7011add0d3d"}]}
GET call to network for http://192.168.33.2:9696/v2.0/ports?name=testvm1port used request id req-68eebc47-6a29-4c0c-ab35-26bd8138676c
REQ: curl -g -i -X POST http://192.168.33.2:8774/v2.1/servers/d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f/os-interface -H "Accept: application/json" -H "Content-Type: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}af6b741fc3c2fc134934a1cdfc10f75be456bb8536d64d4fe32559fb341d669d" -H "X-OpenStack-Nova-API-Version: 2.1" -d '{"interfaceAttachment": {"port_id": "409113d5-b275-48e8-8429-d08a06eb4caa"}}'
http://192.168.33.2:8774 "POST /v2.1/servers/d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f/os-interface HTTP/1.1" 504 None
RESP: [504] Cache-Control: no-cache Connection: close Content-Type: text/html
RESP BODY: Omitted, Content-Type is set to text/html. Only application/json responses have their bodies logged.
Unknown Error (HTTP 504)
Traceback (most recent call last):
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/cliff/app.py", line 401, in run_subcommand
result = cmd.run(parsed_args)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/osc_lib/command/command.py", line 41, in run
return super(Command, self).run(parsed_args)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/cliff/command.py", line 185, in run
return_code = self.take_action(parsed_args) or 0
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/openstackclient/compute/v2/server.py", line 359, in take_action
server.interface_attach(port_id=port_id, net_id=None, fixed_ip=None)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/api_versions.py", line 393, in substitution
return methods[-1].func(obj, *args, **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/v2/servers.py", line 610, in interface_attach
return self.manager.interface_attach(self, port_id, net_id, fixed_ip)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/api_versions.py", line 393, in substitution
return methods[-1].func(obj, *args, **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/v2/servers.py", line 2063, in interface_attach
obj_class=NetworkInterface)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/base.py", line 363, in _create
resp, body = self.api.client.post(url, body=body)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/keystoneauth1/adapter.py", line 392, in post
return self.request(url, 'POST', **kwargs)
File "/home/centos/kayobe-venv/lib/python3.6/site-packages/novaclient/client.py", line 78, in request
raise exceptions.from_response(resp, body, url, method)
novaclient.exceptions.ClientException: Unknown Error (HTTP 504)
clean_up AddPort: Unknown Error (HTTP 504)
END return value: 1
#############################
nova-compute:
2021-02-25 11:03:46.549 7 DEBUG nova.network.os_vif_util [req-f47d8eee-0beb-4890-af38-e0d78cbfae88 8d64a09fc978483a9c9a64d71d863fb8 19303d9afcc4447b8985e7011add0d3d - default default] Converted object VIFOpenVSwitch(active=False,address=fa:16:3e:aa:ce:9a,bridge_name='br-int',has_traffic_filtering=True,id=409113d5-b275-48e8-8429-d08a06eb4caa,network=Network(45c000ba-d770-48e3-8a83-5950c60e8a1d),plugin='ovs',port_profile=VIFPortProfileOpenVSwitch,preserve_on_delete=True,vif_name='tap409113d5-b2') nova_to_osvif_vif /usr/lib/python3.6/site-packages/nova/network/os_vif_util.py:538
2021-02-25 11:03:46.567 7 DEBUG nova.virt.libvirt.guest [req-f47d8eee-0beb-4890-af38-e0d78cbfae88 8d64a09fc978483a9c9a64d71d863fb8 19303d9afcc4447b8985e7011add0d3d - default default] attach device xml: <interface type="bridge">
<mac address="fa:16:3e:aa:ce:9a"/>
<model type="virtio"/>
<driver name="qemu"/>
<source bridge="br-int"/>
<mtu size="1442"/>
<target dev="tap409113d5-b2"/>
<virtualport type="openvswitch">
<parameters interfaceid="409113d5-b275-48e8-8429-d08a06eb4caa"/>
</virtualport>
</interface>
attach_device /usr/lib/python3.6/site-packages/nova/virt/libvirt/guest.py:292
2021-02-25 11:03:47.004 7 DEBUG nova.network.neutron [req-9ec4dc24-3aec-44c9-bb3d-3b4f9a398bc9 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Updated VIF entry in instance network info cache for port 409113d5-b275-48e8-8429-d08a06eb4caa. _build_network_info_model /usr/lib/python3.6/site-packages/nova/network/neutron.py:3157
2021-02-25 11:03:47.005 7 DEBUG nova.network.neutron [req-9ec4dc24-3aec-44c9-bb3d-3b4f9a398bc9 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Updating instance_info_cache with network_info: [{"id": "3dd3e38a-45ad-4e67-8b04-a9bb18ed372a", "address": "fa:16:3e:7d:98:04", "network": {"id": "dac630c1-4d4d-42b7-b2c7-f110697dc999", "bridge": "br-int", "label": "demo-net", "subnets": [{"cidr": "10.0.0.0/24", "dns": [{"address": "8.8.8.8", "type": "dns", "version": 4, "meta": {}}], "gateway": {"address": "10.0.0.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "10.0.0.174", "type": "fixed", "version": 4, "meta": {}, "floating_ips": [{"address": "192.168.33.96", "type": "floating", "version": 4, "meta": {}}]}], "routes": [], "version": 4, "meta": {"dhcp_server": "10.0.0.2"}}], "meta": {"injected": false, "tenant_id": "19303d9afcc4447b8985e7011add0d3d", "mtu": null, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true}, "devname": "tap3dd3e38a-45", "ovs_interfaceid": "3dd3e38a-45ad-4e67-8b04-a9bb18ed372a", "qbh_params": null, "qbg_params": null, "active": true, "vnic_type": "normal", "profile": {}, "preserve_on_delete": false, "meta": {}}, {"id": "409113d5-b275-48e8-8429-d08a06eb4caa", "address": "fa:16:3e:aa:ce:9a", "network": {"id": "45c000ba-d770-48e3-8a83-5950c60e8a1d", "bridge": "br-int", "label": "test-net", "subnets": [{"cidr": "192.0.2.0/24", "dns": [], "gateway": {"address": "192.0.2.1", "type": "gateway", "version": 4, "meta": {}}, "ips": [{"address": "192.0.2.178", "type": "fixed", "version": 4, "meta": {}, "floating_ips": []}], "routes": [], "version": 4, "meta": {"dhcp_server": "192.0.2.2"}}], "meta": {"injected": false, "tenant_id": "19303d9afcc4447b8985e7011add0d3d", "mtu": 1442, "physical_network": null, "tunneled": true}}, "type": "ovs", "details": {"port_filter": true}, "devname": "tap409113d5-b2", "ovs_interfaceid": "409113d5-b275-48e8-8429-d08a06eb4caa", "qbh_params": null, "qbg_params": null, "active": false, "vnic_type": "normal", "profile": {}, "preserve_on_delete": true, "meta": {}}] update_instance_cache_with_nw_info /usr/lib/python3.6/site-packages/nova/network/neutron.py:119
2021-02-25 11:03:48.335 7 WARNING nova.compute.manager [req-2a330fc9-9bef-4f78-84cd-8b6a9e0158a8 9ff617d4a7584f8b8fe1d40322430b5c 39cd2e2aa42b4eabb2fe199175406cda - default default] [instance: d2a08a27-5f9f-46f5-bbf0-f3920bd8cc9f] Received unexpected event network-vif-plugged-409113d5-b275-48e8-8429-d08a06eb4caa for instance with vm_state active and task_state None. |
|
