neutron.agent.dhcp.agent TypeError: 'bool' object is not subscriptable

neutron-22.0.0 (antelope) bumped up the minimum version of pyroute2 to 0.7.3[0] while in the archive we have 0.7.2, I’m testing a new version of pyroute in this ppa https://launchpad.net/~freyes/+archive/ubuntu/jammy-antelope/+packages

[0] https://review.opendev.org/c/openstack/neutron/+/870963

output from 'systemctl status neutron-dhcp-agent':

Apr 03 14:28:05 juju-8472d8-zaza-fe27bb416aca-9 neutron-dhcp-agent[66553]: TypeError: 'bool' object is not subscriptable
Apr 03 14:34:17 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq[67441]: exiting on receipt of SIGTERM

# grep 67441 /var/log/syslog
Apr 3 14:28:05 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq[67441]: started, version 2.86 cachesize 150
Apr 3 14:28:05 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq[67441]: DNS service limited to local subnets
Apr 3 14:28:05 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq[67441]: compile time options: IPv6 GNU-getopt DBus no-UBus i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset auth cryptohash DNSSEC loop-detect inotify dumpfile
Apr 3 14:28:05 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq[67441]: warning: no upstream servers configured
Apr 3 14:28:05 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq-dhcp[67441]: DHCP, static leases only on 192.168.0.0, lease time 1d
Apr 3 14:28:05 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq[67441]: read /var/lib/neutron/dhcp/30f322ee-540e-4365-9c3c-4031fd026dd0/addn_hosts - 2 addresses
Apr 3 14:28:05 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq-dhcp[67441]: read /var/lib/neutron/dhcp/30f322ee-540e-4365-9c3c-4031fd026dd0/host
Apr 3 14:28:05 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq-dhcp[67441]: read /var/lib/neutron/dhcp/30f322ee-540e-4365-9c3c-4031fd026dd0/opts
Apr 3 14:34:17 juju-8472d8-zaza-fe27bb416aca-9 dnsmasq[67441]: exiting on receipt of SIGTERM

The issue is still present when using pyroute2-0.7.3

I added some instrumentation ( see https://dpaste.com/9ZTVHH97E ) which produced this output:

2023-04-03 18:32:57.381 65042 DEBUG neutron.agent.dhcp.agent [-] Calling driver for network: 94bb0c66-40f7-4590-9ba0-aac6e6e621e0/seg=None action: get_metadata_bind_interface _call_driver /usr/lib/python3/dist-packages/neutron/agent/dhcp/agent.py:242
2023-04-03 18:32:57.383 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:335
2023-04-03 18:32:57.384 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: True (<class 'bool'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:57.384 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ stack: File "/usr/lib/python3/dist-packages/eventlet/greenthread.py", line 221, in main
    result = function(*args, **kwargs) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:338
2023-04-03 18:32:57.385 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ stack: File "/usr/lib/python3/dist-packages/osprofiler/profiler.py", line 159, in wrapper
    result = f(*args, **kwargs) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:338
2023-04-03 18:32:57.385 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ stack: File "/usr/lib/python3/dist-packages/neutron/common/utils.py", line 182, in call
    return func(*args, **kwargs) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:338
2023-04-03 18:32:57.385 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ stack: File "/usr/lib/python3/dist-packages/neutron/agent/dhcp/agent.py", line 434, in safe_configure_dhcp_for_network
    self.configure_dhcp_for_network(network) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:338
2023-04-03 18:32:57.385 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ stack: File "/usr/lib/python3/dist-packages/osprofiler/profiler.py", line 159, in wrapper
    result = f(*args, **kwargs) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:338
2023-04-03 18:32:57.385 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ stack: File "/usr/lib/python3/dist-packages/neutron/agent/dhcp/agent.py", line 447, in configure_dhcp_for_network
    self.update_isolated_metadata_proxy(network) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:338
2023-04-03 18:32:57.385 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ stack: File "/usr/lib/python3/dist-packages/osprofiler/profiler.py", line 159, in wrapper
    result = f(*args, **kwargs) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:338
2023-04-03 18:32:57.386 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ stack: File "/usr/lib/python3/dist-packages/neutron/agent/dhcp/agent.py", line 763, in update_isolated_metadata_proxy
    self.enable_isolated_metadata_proxy(network) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:338
2023-04-03 18:32:57.386 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: __init__ stack: File "/usr/lib/python3/dist-packages/osprofiler/profiler.py", line 159, in wrapper
...

Something is leaking booleans into the routines that expect device names:

ges/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:09.112 35374 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:09.236 35374 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:09.311 35374 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: True (<class 'bool'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:16.868 35374 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:17.037 35374 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:17.139 35374 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: True (<class 'bool'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:52.986 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:56.552 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:56.600 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:56.711 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:56.824 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:56.907 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: tapb2aeb618-16 (<class 'str'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336
2023-04-03 18:32:57.384 65042 DEBUG neutron.agent.linux.ip_lib [-] XXX: self._name: True (<class 'bool'>) __init__ /usr/lib/python3/dist-packages/neutron/agent/linux/ip_lib.py:336

I think I found the root cause. This piece of code returns a True/False instead of a device name[0], this is expected to be executed only when there are network segments defined, although in this testing environment there aren't, I'm collecting more information to understand and confirm if this assumption is correct.

The code in question was merged in this review https://review.opendev.org/c/openstack/neutron/+/840421

[0] https://opendev.org/openstack/neutron/src/tag/22.0.0/neutron/agent/dhcp/agent.py#L219-L234

The sid_subnets dict is built with a None key:

2023-04-10 17:11:04.265 142264 DEBUG neutron.agent.dhcp.agent [-] XXX: sid_subnets: defaultdict(<class 'list'>, {None: [<neutron.agent.linux.dhcp.DictModel object at 0x7fa82e21e350>]}) call_driver /usr/lib/python3/dist-packages/neutron/agent/dhcp/agent.py:220

Could it be that this line[0] requires to check for None, something like this:

```
diff --git a/neutron/agent/dhcp/agent.py b/neutron/agent/dhcp/agent.py
index 208ebce743..ab4f4a5244 100644
--- a/neutron/agent/dhcp/agent.py
+++ b/neutron/agent/dhcp/agent.py
@@ -214,7 +214,8 @@ class DhcpAgent(manager.Manager):
             for segment in network.segments:
                 sid_segment[segment.id] = segment
             for subnet in network.subnets:
- sid_subnets[subnet.get('segment_id')].append(subnet)
+ if subnet.get('segment_id'):
+ sid_subnets[subnet.get('segment_id')].append(subnet)
         if sid_subnets:
             ret = []
             for seg_id, subnets in sid_subnets.items():
```

I tested this change in a testing environment successfully, the dhcp and metadata services came online and instances could consume them.

[0] https://review.opendev.org/c/openstack/neutron/+/840421/46/neutron/agent/dhcp/agent.py#211

Thanks a lot for this great investigation Felippe,

To well understand the root cause. Could share share outputs of network, subnet, segement show ?

It looks like your subnet is not attached to any segments but the network is attached to one. Which looks strange. We have some design problems previously where a segment was consider part of a network. I have to understand how this can happen.

Besides that I will try to reproduce the case in my side.

Thorough analysis, thank you! For a fix, please note, that the driver call has different return types depending on the method:

https://opendev.org/openstack/neutron/src/tag/22.0.0/neutron/agent/dhcp/agent.py#L260-L264

Sahid, do you maybe want to take this bug?

Hi Sahid,

On Tue, 2023-04-11 at 08:33 +0000, Sahid Orentino wrote:
> Thanks a lot for this great investigation Felippe,
>
> To well understand the root cause. Could share share outputs of network,
> subnet, segement show ?

Here it's the output of list and show for network, subnet and segment:
https://pastebin.ubuntu.com/p/5jZ9nGGvvZ/ . Something that stood up (to me) while running these
commands is that the external network type 'flat' which has no segment set.

I added this log line[0] in [1] which produced this output:

2023-04-10 23:35:44.269 64730 DEBUG neutron.agent.dhcp.agent [-] XXX: segments:
[<neutron.agent.linux.dhcp.DictModel object at 0x7f2ebfe836d0>] call_driver /usr/lib/python3/dist-
packages/neutron/agent/dhcp/agent.py:210

I will try to get a better output for that DictModel object.

[0] LOG.debug('XXX: segments: %s', str(network.segments))
[1] https://opendev.org/openstack/neutron/src/tag/22.0.0/neutron/agent/dhcp/agent.py#L210

Hum... line 33 and 45 of [0] we can see that your networks are not attached to any segments. It is not expected that the code go through the point that you are mentioning on comment #7, see [1].

anychance that you print network.segments ? In all cases I will check the code to understand what's going on...

[0] https://pastebin.ubuntu.com/p/5jZ9nGGvvZ/
[1] https://opendev.org/openstack/neutron/src/tag/22.0.0/neutron/agent/dhcp/agent.py#L209

On Tue, 2023-04-11 at 14:05 +0000, Sahid Orentino wrote:
> Hum... line 33 and 45 of [0] we can see that your networks are not
> attached to any segments. It is not expected that the code go through
> the point that you are mentioning on comment #7, see [1].
>
> anychance that you print network.segments ? In all cases I will check
> the code to understand what's going on...

I applied this change[0] which produced this output [1] (this is a different environment, so the
list/show for network, subnet and segments are [2] in case you need to cross reference the UUIDs)

The network that has associated a segment with the segment_id set to None is of network_type flat:

network: 9eb0c107-fc1b-494b-922a-645c2f728fc3
segment: hosts=['juju-aae23a-jammy-antelope-8.project.serverstack',
                'juju-aae23a-jammy-antelope-9.project.serverstack'],
         id=9fa37738-1cd1-48bf-8d2b-426bd65216f6,
         is_dynamic=False,
         name=None,
         network_id=9eb0c107-fc1b-494b-922a-645c2f728fc3,
         network_type=flat,
         physical_network=physnet1,
         segment_index=0,
         segmentation_id=None

[0] https://pastebin.ubuntu.com/p/qRWwZFwcpH/
[1] https://pastebin.ubuntu.com/p/hdRZmjDFvs/
[2] https://pastebin.ubuntu.com/p/VCmBfyZyRk/

Thanks a lot.

network.segments is returning a DictModel I guess it's the issue.

Could you try this:

diff --git a/neutron/agent/dhcp/agent.py b/neutron/agent/dhcp/agent.py
index 208ebce743..ce36fc3587 100644
--- a/neutron/agent/dhcp/agent.py
+++ b/neutron/agent/dhcp/agent.py
@@ -206,7 +206,7 @@ class DhcpAgent(manager.Manager):
                      action, action_kwargs)
             # There is nothing we can do.
             return
- if 'segments' in network and network.segments:
+ if 'segments' in network and len(network.segments) > 0:
             # In case of multi-segments network, let's group network per
             # segments. We can then create DHPC process per segmentation
             # id. All subnets on a same network that are sharing the same

On Wed, 2023-04-12 at 08:19 +0000, Sahid Orentino wrote:
> Thanks a lot.
>
> network.segments is returning a DictModel I guess it's the issue.
>
It holds a list of DictModel, `len(network.segments) > 0` will be True, see comment #10 .

Fix proposed to branch: master
Review: https://review.opendev.org/c/openstack/neutron/+/884674

Reviewed: https://review.opendev.org/c/openstack/neutron/+/884674
Committed: https://opendev.org/openstack/neutron/commit/a9323f0325cc4227ca6f1f0316913aa7a2d315f5
Submitter: "Zuul (22348)"
Branch: master

commit a9323f0325cc4227ca6f1f0316913aa7a2d315f5
Author: Sahid Orentino Ferdjaoui <email address hidden>
Date: Tue May 30 12:09:56 2023 +0200

    dhcp/agent: fix 'get_metadata_bind_interface' driver call

    The 'get_metadata_bind_interface' driver call has a different behavior
    than other methods, it is expected to return metadata interface name.
    When introduced multisegments support this particularity was not taken
    into account.

    The fix is making the call acceptable in the purpose of the current
    driver interface.

    Closes-bug: #2015090
    Signed-off-by: Sahid Orentino Ferdjaoui <email address hidden>
    Change-Id: I08e686397238685c11b0de818caa399d69da04fd

Fix proposed to branch: stable/2023.1
Review: https://review.opendev.org/c/openstack/neutron/+/886682

This issue was fixed in the openstack/neutron 22.0.2 release.

The fix for lunar/antelope is in the 22.0.2 stable point release. For ubuntu we are tracking that in https://bugs.launchpad.net/cloud-archive/+bug/2030514

This issue was fixed in the openstack/neutron 23.0.0.0b3 development milestone.