neutron

gate-grenade-dsvm-neutron-multinode fails server build on newton side with "Unrecognized attribute(s) 'dns_name'"

Bug #1607412 reported by Matt Riedemann
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Invalid
Undecided
Unassigned
neutron
Fix Released
High
Miguel Lavalle

Bug Description

Saw this here in the gate:

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/new/screen-n-cond.txt.gz?level=TRACE#_2016-07-25_10_24_50_160

2016-07-25 10:24:50.160 3162 ERROR nova.scheduler.utils [req-3b0678a2-4d9c-462e-97a5-913dc36fab81 tempest-ServerAddressesTestJSON-491230418 tempest-ServerAddressesTestJSON-491230418] [instance: f0e2b7fc-d88a-4e2d-9bc8-adcb81efc0dc] Error from last host: ubuntu-trusty-2-node-rax-ord-2845415-108069 (node ubuntu-trusty-2-node-rax-ord-2845415-108069): [u'Traceback (most recent call last):\n', u' File "/opt/stack/old/nova/nova/compute/manager.py", line 1926, in _do_build_and_run_instance\n filter_properties)\n', u' File "/opt/stack/old/nova/nova/compute/manager.py", line 2116, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance f0e2b7fc-d88a-4e2d-9bc8-adcb81efc0dc was re-scheduled: Unrecognized attribute(s) 'dns_name'\nNeutron server returns request_ids: ['req-d96c687a-3971-4d8d-bb42-08661632f7c8']\n"]

There are only 3 hits in 7 days in logstash, but it seems like there should be more than this (we might also be backed up on logstash results):

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22RescheduledException%3A%20Build%20of%20instance%5C%22%20AND%20message%3A%5C%22was%20re-scheduled%3A%20Unrecognized%20attribute(s)%20'dns_name'%5C%22%20AND%20tags%3A%5C%22screen-n-cond.txt%5C%22&from=7d

Matt Riedemann (mriedem)
tags: added: dns neutron
Revision history for this message
Matt Riedemann (mriedem) wrote :

Looks like it's actually on the mitaka side of grenade:

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/subnode-2/old/screen-n-cpu.txt.gz?level=TRACE#_2016-07-25_10_24_49_258

This is probably related to these two backports to stable/mitaka in nova:

https://review.openstack.org/#/q/topic:bug/1572593+branch:stable/mitaka

Revision history for this message
Matt Riedemann (mriedem) wrote :
Download full text (4.4 KiB)

2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager [req-3b0678a2-4d9c-462e-97a5-913dc36fab81 tempest-ServerAddressesTestJSON-491230418 tempest-ServerAddressesTestJSON-491230418] Instance failed network setup after 1 attempt(s)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager Traceback (most recent call last):
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/opt/stack/old/nova/nova/compute/manager.py", line 1570, in _allocate_network_async
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager bind_host_id=bind_host_id)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/opt/stack/old/nova/nova/network/neutronv2/api.py", line 668, in allocate_for_instance
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager self._delete_ports(neutron, instance, created_port_ids)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager self.force_reraise()
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager six.reraise(self.type_, self.value, self.tb)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/opt/stack/old/nova/nova/network/neutronv2/api.py", line 657, in allocate_for_instance
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager security_group_ids, available_macs, dhcp_opts)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/opt/stack/old/nova/nova/network/neutronv2/api.py", line 295, in _create_port
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager network_id, instance=instance)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager self.force_reraise()
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager six.reraise(self.type_, self.value, self.tb)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/opt/stack/old/nova/nova/network/neutronv2/api.py", line 254, in _create_port
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager port = port_client.create_port(port_req_body)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 97, in with_params
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager ret = self.function(instance, *args, **kwargs)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 654, in create_port
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager return self.post(self.ports_path, body=body)
2016-07-25 10:24:49.258 12828 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packag...

Read more...

Revision history for this message
Matt Riedemann (mriedem) wrote :

Before nova creates the port, it would set the port's dns_name here:

https://github.com/openstack/nova/blob/stable/mitaka/nova/network/neutronv2/api.py#L741-L752

But only if the "DNS Integration" extension was loaded, which it must be, so I'm not sure where the AttributeError on dns_name is coming from.

Jakub Libosvar (libosvar)
tags: added: gate-failure
Revision history for this message
eil397 (anton-haldin) wrote :
Download full text (5.8 KiB)

Not sure where the AttributeError on dns_name is coming from.

But looks like that this '"dns_name": null,' coming from "Routers returned to l3 agent"

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/new/screen-q-svc.txt.gz#_2016-07-25_10_18_57_090

2016-07-25 10:18:57.090 31579 DEBUG neutron.api.rpc.handlers.l3_rpc [req-8614958e-93af-4166-9642-7dbdecee2900 - -] Routers returned to l3 agent:
 [
     {
          "status": "ACTIVE",
          "_interfaces": [
               {
                    "status": "ACTIVE",
                    "subnets": [
                         {
                              "dns_nameservers": [],
                              "ipv6_ra_mode": "slaac",
                              "gateway_ip": "fda4:bff1:9226::1",
                              "cidr": "fda4:bff1:9226::/64",
                              "id": "fd6b43b3-e384-4458-b5d3-94cb8ddeeffc",
                              "subnetpool_id": null
                         }
                    ],
                    "binding:host_id": "ubuntu-trusty-2-node-rax-ord-2845415",
                    "description": "",
                    "allowed_address_pairs": [],
                    "extra_dhcp_opts": [],
                    "updated_at": "2016-07-25T09:58:10",
                    "device_owner": "network:router_interface",
                    "port_security_enabled": false,
                    "binding:profile": {},
                    "mtu": 1400,
                    "fixed_ips": [
                         {
                              "subnet_id": "fd6b43b3-e384-4458-b5d3-94cb8ddeeffc",
                              "prefixlen": 64,
                              "ip_address": "fda4:bff1:9226::1"
                         }
                    ],
                    "id": "09d20977-0258-462a-9dde-f38d3cabdba1",
                    "security_groups": [],
                    "device_id": "d8c9b97c-1fd0-4644-a224-8250b144f40a",
                    "name": "",
                    "admin_state_up": true,
                    "network_id": "f1ad1be3-f572-4f14-b562-bf960cc1d2e1",
                    "dns_name": null,
                    "binding:vif_details": {
                         "port_filter": true,
                         "ovs_hybrid_plug": true
                    },
                    "address_scopes": {
                         "4": null,
                         "6": null
                    },
                    "binding:vnic_type": "normal",
                    "binding:vif_type": "ovs",
                    "tenant_id": "b583b372fa3e4828b7d7807529e0c61d",
                    "mac_address": "fa:16:3e:80:b3:c1",
                    "extra_subnets": [
                         {
                              "dns_nameservers": [],
                              "ipv6_ra_mode": null,
                              "gateway_ip": "10.1.0.1",
                              "cidr": "10.1.0.0/20",
                              "id": "b2c49785-5d6a-4ed3-9eef-ba80fcf353da",
                              "subnetpool_id": null
                         }
                    ],
                    "created_at": "2016-07-25T09:58:...

Read more...

Revision history for this message
eil397 (anton-haldin) wrote :

Sorry my previous comment is not helpful.

Looks like this error appears somewhere here:

2016-07-25 10:24:49.249 31572 DEBUG neutron.api.v2.base [req-d96c687a-3971-4d8d-bb42-08661632f7c8 neutron -] Request body: {u'port': {u'binding:host_id': u'ubuntu-trusty-2-node-rax-ord-2845415-108069', u'admin_state_up': True, u'network_id': u'946228d2-a787-45cb-838a-c410c48d3abc', u'dns_name': u'tempest.common.compute-instance-1749815685', u'device_owner': u'compute:None', u'tenant_id': u'17e7b0b74a024e318ffca20f138840a7', u'security_groups': [u'fdd02c2b-accc-4f11-b537-dab57823c674'], u'device_id': u'f0e2b7fc-d88a-4e2d-9bc8-adcb81efc0dc'}} prepare_request_body /opt/stack/new/neutron/neutron/api/v2/base.py:649
2016-07-25 10:24:49.249 31572 INFO neutron.api.v2.resource [req-d96c687a-3971-4d8d-bb42-08661632f7c8 neutron -] create failed (client error): Unrecognized attribute(s) 'dns_name'

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/new/screen-q-svc.txt.gz#_2016-07-25_10_24_49_249

Revision history for this message
eil397 (anton-haldin) wrote :

and exception maybe created here:
https://github.com/openstack/neutron/blob/master/neutron/api/v2/attributes.py#L459

    extra_keys = set(res_dict.keys()) - set(attr_info.keys())
    if extra_keys:

Revision history for this message
eil397 (anton-haldin) wrote :

Probably can be related to https://review.openstack.org/#/c/346221
"""
Avoid KeyError when accessing "dns_name" as it may not exist

Neutron LBaaS does not pass a full copy of the request_data
into this function, and causes the port create to fail
with a KeyError
"""

neutron/plugins/ml2/extensions/dns_integration.py
>> if not request_data[dns.DNSNAME]:

Same errors:
http://logs.openstack.org/21/346221/3/check/gate-grenade-dsvm-neutron-dvr-multinode/45c97d1/logs/new/screen-q-svc.txt.gz#_2016-07-25_20_37_27_173

2016-07-25 20:37:27.173 4591 INFO neutron.api.v2.resource [req-9e93d4e2-2a26-4053-ac05-dd1b4adf96af neutron -] create failed (client error): Unrecognized attribute(s) 'dns_name'

Revision history for this message
Miguel Lavalle (minsel) wrote :

@Anton,

Looking at the Neutron server screen you posted above, I can see that the DNS extension has not been configured in Neutron (please look at the list of ML2 extensions in parameter ml2_extension_drivers: http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/new/screen-q-svc.txt.gz#_2016-07-25_10_18_54_680

Contrast that with what I have in my development system, where the DNS extension is configured:

2016-07-28 21:37:42.199 ^[[00;32mDEBUG oslo_service.service [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mml2.extension_drivers = ['port_security', 'dns']^[[00m ^[[00;33mfrom (pid=20513) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2573^[[00m

So when the request gets to Neutron, the controller for ports verifies that all the attributes in the request body are supported: https://github.com/openstack/neutron/blob/master/neutron/api/v2/base.py#L673. This calls the attributes.verify_attributes method that you point to above and we get the exception because, since the DNS extension is not loaded, the dns_name attribute is not supported.

I can also see the request from Nova to get the extensions loaded in Neutron:

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/new/screen-q-svc.txt.gz#_2016-07-25_10_23_35_494

I cannot see the response from Neutron in this log, but this is tempest code, so there must be a tempest log somewhere. That is where we should look at next, to see the response sent back from Neutron

Revision history for this message
Miguel Lavalle (minsel) wrote :

@Anton,

No, I don't think it is related to https://review.openstack.org/#/c/346221. That is actually the opposite issue: the dns extension is enabled in Neutron, but a service (LBaaS in this case) calls the plugin directly to create a port, without passing through the API. LBaaS is not adding the dns_name attribute to the port body and the dns extension assumes that it is going to get a default value from the api

Revision history for this message
Miguel Lavalle (minsel) wrote :

Looking at the compute manager screen log, we can see that it is configured to query Neutron for its enabled extensions every 600 seconds (neutron.extension_sync_interval = 600):

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/subnode-2/old/screen-n-cpu.txt.gz?#_2016-07-25_10_04_12_778

So this compute manager queries Neutron for enabled extensions on 3 occasions (in each case, look at the following line):

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/subnode-2/old/screen-n-cpu.txt.gz?#_2016-07-25_10_04_25_201

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/subnode-2/old/screen-n-cpu.txt.gz?#_2016-07-25_10_15_04_869

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/subnode-2/old/screen-n-cpu.txt.gz?#_2016-07-25_10_25_13_705

The first two times, the list of extensions is: http://paste.openstack.org/show/543462/. The third, though, the list changed: http://paste.openstack.org/show/543463/. Looking in detail, the difference is that in the first two occasions, "dns-integration" is included. The last occasion, "dns-integration" is not included and "flavors" and "service-type" were added. Note that the failed port creation took place at 2016-07-25_10_24_49_258. That is right before the last Neutron extensions update, which doesn't return "dns_integration". So it seems that during the course the test, extensions are being added and removed from Neutron.

Jakub Libosvar (libosvar)
Changed in neutron:
importance: Undecided → High
status: New → Confirmed
Miguel Lavalle (minsel)
Changed in neutron:
assignee: nobody → Miguel Lavalle (minsel)
Revision history for this message
Miguel Lavalle (minsel) wrote :

The root cause of this problem is that the l3_router_plugin is incorrectly loading the DNS integration extension in the stable Mitaka branch. This extension should only be configured by the operator / deployer by adding 'dns' to the 'extension_driver' list in ml2_conf.ini. This bug was fixed for master (https://bugs.launchpad.net/neutron/+bug/1574694, https://review.openstack.org/#/c/311640) but not back ported to stable Mitaka.

This explains why when the compute manager queries Neutron for the enabled extensions the first two occasions (see my previous comment), it gets 'DNS Integration' in the list. The 'old' Neutron server (stable Mitaka) responded to these two queries:

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/old/screen-q-svc.txt.gz#_2016-07-25_10_04_25_207

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/old/screen-q-svc.txt.gz#_2016-07-25_10_15_04_868

The third occasion the compute manager queries for the enabled extensions, the response comes from the 'new' (Master branch) Neutron, where 'DNS integration' is not enabled:

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/new/screen-q-svc.txt.gz#_2016-07-25_10_25_13_702

Note that the failed port creation occurred right before the last extensions update:

http://logs.openstack.org/62/324262/3/gate/gate-grenade-dsvm-neutron-multinode/9af98c8/logs/new/screen-q-svc.txt.gz#_2016-07-25_10_24_49_250

The fix for this bug is to back port https://review.openstack.org/#/c/311640 to stable Mitaka

Revision history for this message
Miguel Lavalle (minsel) wrote :

Proposed fix: https://review.openstack.org/#/c/349214/

Changed in neutron:
status: Confirmed → In Progress
Revision history for this message
Miguel Lavalle (minsel) wrote :

Fix merged: https://review.openstack.org/#/c/349214/

Changed in neutron:
status: In Progress → Fix Released
Revision history for this message
Sean Dague (sdague) wrote :

This looks potentially solved now with the mitaka fixes for neutron. Marking incomplete, as it's not clear there are any nova changes to be made.

Changed in nova:
status: New → Incomplete
Matt Riedemann (mriedem)
Changed in nova:
status: Incomplete → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

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