Failed to attach second NIC on 1 vcpu ubuntu guests with qemu-kvm 5.1.0

Bug #1916879 reported by Bartosz Bezak
30
This bug affects 6 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Invalid
Undecided
Unassigned

Bug 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.

Tags: libvirt
Bartosz Bezak (bbezak)
description: updated
description: updated
tags: added: libvirt
Revision history for this message
Bartosz Bezak (bbezak) wrote :

Changing machine type to q35 also solves the problem:

openstack image set --property hw_machine_type=q35 bionic

<type arch='x86_64' machine='pc-q35-rhel8.3.0'>hvm</type>

still failing on:
pc-i440fx-rhel7.6.0

Revision history for this message
Balazs Gibizer (balazs-gibizer) wrote :

Sorry I don't see any actionable error in the nova logs you attached. Do you have a bit bigger log context from nova-compute?

Changed in nova:
status: New → Incomplete
Revision history for this message
Balazs Gibizer (balazs-gibizer) wrote :
Download full text (3.6 KiB)

From the linked Octavia bug https://storyboard.openstack.org/#!/story/2008651 I see that nova got error from libvirt.

2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [req-a71cf7b7-8198-42d4-99b3-e23951e17dd3 28a680c9c5ca4c05a22a29afed378311 6a6da86833a14179b295badec574d4c6 - default default] [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] attaching network adapter failed.: libvirt.libvirtError: Unable to read from monitor: Connection reset by peer
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] Traceback (most recent call last):
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] File "/usr/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 2200, in attach_interface
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] guest.attach_device(cfg, persistent=True, live=live)
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] File "/usr/lib/python3.6/site-packages/nova/virt/libvirt/guest.py", line 293, in attach_device
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] self._domain.attachDeviceFlags(device_xml, flags=flags)
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] File "/usr/lib/python3.6/site-packages/eventlet/tpool.py", line 190, in doit
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] result = proxy_call(self._autowrap, f, *args, **kwargs)
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] File "/usr/lib/python3.6/site-packages/eventlet/tpool.py", line 148, in proxy_call
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] rv = execute(f, *args, **kwargs)
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] File "/usr/lib/python3.6/site-packages/eventlet/tpool.py", line 129, in execute
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] six.reraise(c, e, tb)
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] File "/usr/lib/python3.6/site-packages/six.py", line 703, in reraise
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] raise value
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] File "/usr/lib/python3.6/site-packages/eventlet/tpool.py", line 83, in tworker
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] rv = meth(*args, **kwargs)
2021-02-23 14:22:50.148 8 ERROR nova.virt.libvirt.driver [instance: 7385598b-6161-4012-86b1-6d5a88a6e85c] File "/usr/lib64/python3.6/site-packages/libvirt.py", line 630, in attachDeviceFlags
2021-02-23 14:22:50.148 8 ERROR no...

Read more...

Changed in nova:
status: Incomplete → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.