interface-attach to instance with a large number of attached interfaces fails with RequestURITooLong from neutron

[Evgeny]

Hello!

# nova-manage --version
14.0.0

Command which produce error:
nova interface-attach --net-id <NET_ID> <INSTANCE_NAME>

I got Unexpected API Error when i try nova interface-attach to instance with attached 250 network interface.

And after execute nova interface-attach i can't manipulate network interface, i can't see interface inside instance, only delete port.

DEBUG (session:727) GET call to compute for http://ip:8774/v2.1/b060ad44b2cd4592bdfc50948256ab02/servers/506260c2-343b-4f56-9409-5c4b5ea9d269 used request id req-34fe7aae-75ed-4a90-833d-86ef8cd3d2a4
DEBUG (client:85) GET call to compute for http://ip:8774/v2.1/b060ad44b2cd4592bdfc50948256ab02/servers/506260c2-343b-4f56-9409-5c4b5ea9d269 used request id req-34fe7aae-75ed-4a90-833d-86ef8cd3d2a4
DEBUG (session:375) REQ: curl -g -i -X POST http://ip:8774/v2.1/b060ad44b2cd4592bdfc50948256ab02/servers/506260c2-343b-4f56-9409-5c4b5ea9d269/os-interface -H "Accept: application/json" -H "User-Agent : python-novaclient" -H "OpenStack-API-Version: compute 2.37" -H "X-OpenStack-Nova-API-Version: 2.37" -H "X-Auth-Token: {SHA1}04925ba60ec47cac9d6e099b287f94ba49e99113" -H "Content-Type: application/json" -d '{"interfaceAttachment": {"net_id": "728b6584-8f52-4613-b799-b1bff4f42f53"}}'
 DEBUG (connectionpool:396) http://ip:8774 "POST /v2.1/b060ad44b2cd4592bdfc50948256ab02/servers/506260c2-343b-4f56-9409-5c4b5ea9d269/os-interface HTTP/1.1" 500 211
 DEBUG (session:423) RESP: [500] Openstack-Api-Version: compute 2.37 X-Openstack-Nova-Api-Version: 2.37 Vary: OpenStack-API-Version, X-OpenStack-Nova-API-Version Content-Type: application/json; charset=UTF-8 Content-Length: 211 X-Compute-Request-Id: req-0725bd5b-f86e-4194-aa35-efe229413e90 Date: Thu, 04 Oct 2018 09:12:44 GMT
RESP BODY: {"computeFault": {"message": "Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.\n<class 'oslo_messaging.rpc.client.RemoteError'>" , "code": 500}}
 DEBUG (session:727) POST call to compute for http://ip:8774/v2.1/b060ad44b2cd4592bdfc50948256ab02/servers/506260c2-343b-4f56-9409-5c4b5ea9d269/os-interface used request id req-0725bd5b-f86e-4194-aa35-efe229413e90
 DEBUG (client:85) POST call to compute for http://ip:8774/v2.1/b060ad44b2cd4592bdfc50948256ab02/servers/506260c2-343b-4f56-9409-5c4b5ea9d269/os-interface used request id req-0725bd5b-f86e-4194-aa35-efe22413e90
 DEBUG (shell:984) Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'oslo_messaging.rpc.client.RemoteError'> (HTTP 500) (Request-ID: req-0725bd5b-f86e-4194-aa35-efe229413e90)
 Traceback (most recent call last):
   File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line 982, in main
     OpenStackComputeShell().main(argv)
   File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line 909, in main
     args.func(self.cs, args)
   File "/usr/lib/python2.7/dist-packages/novaclient/v2/shell.py", line 5047, in do_interface_attach
     res = server.interface_attach(args.port_id, args.net_id, args.fixed_ip)
   File "/usr/lib/python2.7/dist-packages/novaclient/v2/servers.py", line 552, in interface_attach
     return self.manager.interface_attach(self, port_id, net_id, fixed_ip)
   File "/usr/lib/python2.7/dist-packages/novaclient/v2/servers.py", line 1822, in interface_attach
     body, 'interfaceAttachment')
   File "/usr/lib/python2.7/dist-packages/novaclient/base.py", line 356, in _create
     resp, body = self.api.client.post(url, body=body)
   File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 294, in post
     return self.request(url, 'POST', **kwargs)
   File "/usr/lib/python2.7/dist-packages/novaclient/client.py", line 117, in request
     raise exceptions.from_response(resp, body, url, method)
ClientException: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'oslo_messaging.rpc.client.RemoteError'> (HTTP 500) (Request-ID: req-0725bd5b-f86e-4194-aa35-efe229413e90)
ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'oslo_messaging.rpc.client.RemoteError'> (HTTP 500) (Request-ID: req-0725bd5b-f86e-4194-aa35-efe229413e90)

At nova-api logs nothing usefull information.
At logs of nova-compute

42071:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [req-cf8f6301-c4d4-4a46-890f-4153da706949 - - - - -] [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] An error occurred while refreshing the network cache.: RequestURITooLong: An unknown exception occurred.
42072:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] Traceback (most recent call last): 42073:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 5764, in _heal_instance_inf
o_cache 42074:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] self.network_api.get_instance_nw_info(context, instance)
42075:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/base_api.py", line 249, in get_instance_nw_info
42076:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] result = self._get_instance_nw_info(context, instance, **kwargs) 42077:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 1283, in _get_instanc
e_nw_info 42078:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] preexisting_port_ids)
42079:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 2196, in _build_network_info_model
42080:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] network_IPs) 42081:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 2054, in _nw_info_get
_subnets 42082:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] subnets = self._get_subnets_from_port(context, port)
42083:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 2241, in _get_subnets_from_port
42084:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] data = get_client(context).list_subnets(**search_opts) 42085:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 97, in wrapper 42086:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] ret = obj(*args, **kwargs)
42087:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 785, in list_subnets 42088:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] **_params) 42089:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 97, in wrapper
42090:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] ret = obj(*args, **kwargs) 42091:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 375, in list 42092:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] for r in self._pagination(collection, path, **params):
42093:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 390, in _pagination 42094:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] res = self.get(path, params=params) 42095:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 97, in wrapper
42096:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] ret = obj(*args, **kwargs)
42097:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 360, in get
42098:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] headers=headers, params=params)
42099:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 97, in wrapper
42100:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] ret = obj(*args, **kwargs)
42101:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 337, in retry_request
42102:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] headers=headers, params=params)
42103:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 97, in wrapper
42104:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] ret = obj(*args, **kwargs)
42105:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 288, in do_request
42106:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] resp, replybody = self.httpclient.do_request(action, method, body=body)
42107:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/neutronclient/client.py", line 310, in do_request
42108:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] self._check_uri_length(url)
42109:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] File "/usr/lib/python2.7/dist-packages/neutronclient/client.py", line 306, in _check_uri_length
42110:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] excess=uri_len - MAX_URI_LEN)
42111:2018-09-26 14:29:20.644 17535 ERROR nova.compute.manager [instance: 506260c2-343b-4f56-9409-5c4b5ea9d269] RequestURITooLong: An unknown exception occurred.

How to fix this error? I will be appreciate for any suggestions.

[melanie witt (melwitt)]

Thanks for providing a detailed bug report complete with log excerpts. From the log, we can see that the error you're hitting is coming from the python-neutronclient code:

  RequestURITooLong: An unknown exception occurred.

Looking at the nova code where this is being emitted from nova/network/neutronv2/api.py in the _get_subnets_from_port method [1], it looks like this:

  search_opts = {'id': [ip['subnet_id'] for ip in fixed_ips]}
  data = client.list_subnets(**search_opts)

with the second line being the call to neutron. It's calling the neutron /subnets API with a list of subnet IDs per fixed IP. I think it's this API [2] with using the 'fields' request parameter, for example:

  /subnets?id=<subnet_id1>&id=<subnet_id2>&id=<subnet_id3>...

The python-neutronclient code will add all of the parameters to the query string [3].

So, because you have 250 interfaces attached to your instance, the request to neutron is too long because 250 subnet_ids are in the URI and we fail with RequestURITooLong.

Are your interfaces attached to 250 different subnets? If not, then I think in nova we could improve the code to de-dupe subnet_ids before we call neutron. Other than that, if you really needed to have 250 different subnets filtered in the neutron API, you would need to propose a change to the python-neutronclient project to send query parameters in the request body instead of in the URI as a query string.

As a test, could you try changing the line in nova/network/neutronv2/api.py from:

  search_opts = {'id': [ip['subnet_id'] for ip in fixed_ips]}

to:

  search_opts = {'id': set([ip['subnet_id'] for ip in fixed_ips])}

and see if that helps you?

[1] https://github.com/openstack/nova/blob/85b36cd2f82ccd740057c1bee08fc722209604ab/nova/network/neutronv2/api.py#L2875-L2889
[2] https://developer.openstack.org/api-ref/network/v2/index.html#list-subnets
[3] https://github.com/openstack/python-neutronclient/blob/15d99a7d68435132fd2fbd4ba604c3796802a83e/neutronclient/v2_0/client.py#L276

[melanie witt (melwitt)]

This issue can only be addressed in nova, so marking as Invalid for python-novaclient.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/608040

[Evgeny (edemin)]

Thanks for your prompt response. I describe this bug at python-neutronclient (https://bugs.launchpad.net/python-neutronclient/+bug/1794528), but unfortunately it stay without answers. At instance attached two different subnets. I will try to fix at nova/network/neutronv2/api.py and describe result here.

[Evgeny (edemin)]

I made changes at /usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py and made restart services nova-api, nova-compute, nova-conductor, nova-scheduler and all works fine. New ip address successfully attach to instance. Thanks a lot for help, Melanie!!!

[melanie witt (melwitt)]

Thanks for confirming the result, Evgeny. According to the output of your 'nova-manage --version' command, you're running nova version 14.0.0 newton, which unfortunately has been EOL since 2017-10-25. So we won't be able to release the fix for newton. At best, we can backport it to 15.0.0 Ocata.

[Matt Riedemann (mriedem)]

Relaying what I said in the nova change review, nova could chunk the requests to neutron if there are more than some limit of subnet IDs, we do that elsewhere:

https://github.com/openstack/nova/blob/e37de17701168054484218e9618ed1cd21784047/nova/network/security_group/neutron_driver.py#L317

But the patch from melwitt does help with the immediate issue.

[melanie witt (melwitt)]

It helps with the immediate issue, but it also avoids wastefully sending duplicated IDs for neutron to filter upon. If/when we add chunking, we wouldn't want to be chunking duplicated IDs anyway.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/608040
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=ab5fc6870260d3b3c3bce90a7123c17816bf0093
Submitter: Zuul
Branch: master

commit ab5fc6870260d3b3c3bce90a7123c17816bf0093
Author: melanie witt <email address hidden>
Date: Thu Oct 4 17:37:59 2018 +0000

    De-dupe subnet IDs when calling neutron /subnets API

    In the _get_subnets_from_port method, we call the neutron /subnets API
    to list subnets filtered by subnet IDs. We get the subnet IDs by
    iterating all of the fixed IPs for the instance and sending the list of
    corresponding subnet IDs. The python-neutronclient sends the list of
    subnet IDs as a query string in the URI. When an instance has a large
    number of interfaces attached, the list of subnet IDs can be too long
    for the URI, resulting in a RequestURITooLong error from neutronclient.

    This de-dupes the subnet IDs before calling neutron, to handle the case
    where an instance has a large number of interfaces attached, but many
    of them are on the same subnet.

    Closes-Bug: #1796074

    Change-Id: I5b52ff81f74ae7cb11e6f012ab7e53cfc6821486

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/rocky
Review: https://review.openstack.org/608336

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/608336
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=057a05dbbd7e4b9aea0aaa52f4bf6c1089f079be
Submitter: Zuul
Branch: stable/rocky

commit 057a05dbbd7e4b9aea0aaa52f4bf6c1089f079be
Author: melanie witt <email address hidden>
Date: Thu Oct 4 17:37:59 2018 +0000

    De-dupe subnet IDs when calling neutron /subnets API

    In the _get_subnets_from_port method, we call the neutron /subnets API
    to list subnets filtered by subnet IDs. We get the subnet IDs by
    iterating all of the fixed IPs for the instance and sending the list of
    corresponding subnet IDs. The python-neutronclient sends the list of
    subnet IDs as a query string in the URI. When an instance has a large
    number of interfaces attached, the list of subnet IDs can be too long
    for the URI, resulting in a RequestURITooLong error from neutronclient.

    This de-dupes the subnet IDs before calling neutron, to handle the case
    where an instance has a large number of interfaces attached, but many
    of them are on the same subnet.

    Closes-Bug: #1796074

    Change-Id: I5b52ff81f74ae7cb11e6f012ab7e53cfc6821486
    (cherry picked from commit ab5fc6870260d3b3c3bce90a7123c17816bf0093)

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/queens
Review: https://review.openstack.org/616551

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/616551
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=346c8feb5837b33b3759c7faaba486715e32b685
Submitter: Zuul
Branch: stable/queens

commit 346c8feb5837b33b3759c7faaba486715e32b685
Author: melanie witt <email address hidden>
Date: Thu Oct 4 17:37:59 2018 +0000

    De-dupe subnet IDs when calling neutron /subnets API

    In the _get_subnets_from_port method, we call the neutron /subnets API
    to list subnets filtered by subnet IDs. We get the subnet IDs by
    iterating all of the fixed IPs for the instance and sending the list of
    corresponding subnet IDs. The python-neutronclient sends the list of
    subnet IDs as a query string in the URI. When an instance has a large
    number of interfaces attached, the list of subnet IDs can be too long
    for the URI, resulting in a RequestURITooLong error from neutronclient.

    This de-dupes the subnet IDs before calling neutron, to handle the case
    where an instance has a large number of interfaces attached, but many
    of them are on the same subnet.

    Closes-Bug: #1796074

    Change-Id: I5b52ff81f74ae7cb11e6f012ab7e53cfc6821486
    (cherry picked from commit ab5fc6870260d3b3c3bce90a7123c17816bf0093)
    (cherry picked from commit 057a05dbbd7e4b9aea0aaa52f4bf6c1089f079be)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 18.1.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 17.0.9 release.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/pike
Review: https://review.openstack.org/632480

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/632480
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=2c464b084006866cb31a289971a36b55eada2355
Submitter: Zuul
Branch: stable/pike

commit 2c464b084006866cb31a289971a36b55eada2355
Author: melanie witt <email address hidden>
Date: Thu Oct 4 17:37:59 2018 +0000

    De-dupe subnet IDs when calling neutron /subnets API

    In the _get_subnets_from_port method, we call the neutron /subnets API
    to list subnets filtered by subnet IDs. We get the subnet IDs by
    iterating all of the fixed IPs for the instance and sending the list of
    corresponding subnet IDs. The python-neutronclient sends the list of
    subnet IDs as a query string in the URI. When an instance has a large
    number of interfaces attached, the list of subnet IDs can be too long
    for the URI, resulting in a RequestURITooLong error from neutronclient.

    This de-dupes the subnet IDs before calling neutron, to handle the case
    where an instance has a large number of interfaces attached, but many
    of them are on the same subnet.

    Closes-Bug: #1796074

    Change-Id: I5b52ff81f74ae7cb11e6f012ab7e53cfc6821486
    (cherry picked from commit ab5fc6870260d3b3c3bce90a7123c17816bf0093)
    (cherry picked from commit 057a05dbbd7e4b9aea0aaa52f4bf6c1089f079be)
    (cherry picked from commit 346c8feb5837b33b3759c7faaba486715e32b685)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 19.0.0.0rc1 release candidate.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 16.1.8 release.