Bug 1789330

Summary: Iteration problems on for loops
Product: OpenShift Container Platform Reporter: Luis Tomas Bolivar <ltomasbo>
Component: NetworkingAssignee: Luis Tomas Bolivar <ltomasbo>
Networking sub component: kuryr QA Contact: GenadiC <gcheresh>
Status: CLOSED ERRATA Docs Contact:
Severity: medium    
Priority: medium CC: gcheresh, itbrown, scuppett
Version: 4.3.0   
Target Milestone: ---   
Target Release: 4.3.z   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1789329 Environment:
Last Closed: 2020-02-19 05:39:53 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1789329    
Bug Blocks:    

Description Luis Tomas Bolivar 2020-01-09 11:17:33 UTC
+++ This bug was initially created as a clone of Bug #1789329 +++

There are several points where kuryr-controller hits errors when iterating in certain loops, such as:

2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging [-] Failed to handle event {'type': 'DELETED', 'object': {'kind': 'NetworkPolicy', 'apiVersion': 'networking.k8s.io/v1', 'metadata': {'name': 'allow-to-server-a-pod-selector', 'namespace': 'network-policy-9843', 'selfLink': '/apis/networking.k8s.io/v1/namespaces/network-policy-9843/networkpolicies/allow-to-server-a-pod-selector', 'uid': 'f1469d78-f392-4b56-a0e3-7f4bd3ab9603', 'resourceVersion': '50385', 'generation': 1, 'creationTimestamp': '2019-12-24T10:50:13Z', 'annotations': {'kuryrnetpolicy_selfLink': '/apis/openstack.org/v1/namespaces/network-policy-9843/kuryrnetpolicies/np-allow-to-server-a-pod-selector'}}, 'spec': {'podSelector': {'matchLabels': {'pod-name': 'client-a'}}, 'egress': [{'ports': [{'protocol': 'UDP', 'port': 53}, {'protocol': 'TCP', 'port': 53}]}, {'to': [{'podSelector': {'matchLabels': {'pod-name': 'server'}}}]}], 'policyTypes': ['Egress']}}}: RuntimeError: dictionary changed size during iteration
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging Traceback (most recent call last):
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging File "/usr/lib/python3.6/site-packages/kuryr_kubernetes/handlers/logging.py", line 37, in __call__
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging self._handler(event)
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging File "/usr/lib/python3.6/site-packages/kuryr_kubernetes/handlers/retry.py", line 78, in __call__
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging self._handler(event)
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging File "/usr/lib/python3.6/site-packages/kuryr_kubernetes/handlers/k8s_base.py", line 77, in __call__
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging self.on_deleted(obj)
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging File "/usr/lib/python3.6/site-packages/kuryr_kubernetes/controller/handlers/policy.py", line 123, in on_deleted
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging self._drv_vif_pool.remove_sg_from_pools(crd_sg, net_id)
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging File "/usr/lib/python3.6/site-packages/kuryr_kubernetes/controller/drivers/vif_pool.py", line 1079, in remove_sg_from_pools
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging vif_drv.remove_sg_from_pools(sg_id, net_id)
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging File "/usr/lib/python3.6/site-packages/kuryr_kubernetes/controller/drivers/vif_pool.py", line 309, in remove_sg_from_pools
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging for sg_key, ports in pool_ports.items():
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging RuntimeError: dictionary changed size during iteration
2019-12-24 10:53:40.073 1 ERROR kuryr_kubernetes.handlers.logging
2019-12-24 10:53:49.163 1 INFO werkzeug [-] 10.196.0.15 - - [24/Dec/2019 10:53:49] "GET /alive HTTP/1.1" 500 -


Or due to fact that the remote_ip_prefixes is used to keep track of pods that has a container port matching a Network Policy rule with named port specified, and it has the following format {'remote_ip_prefixes': {'10.128.106.20': 'network-policy-5545'}}. Right now it's being tried to iterate over each remote_ip_prefixes dicts and fetch its keys and values without fetching the dict items, causing the following error:

2020-01-04 18:06:22.839 1 DEBUG kuryr_kubernetes.controller.drivers.utils [-] Return Kuryr Network Policies with label {'apiVersion': 'openstack.org/v1', 'items': [{'apiVersion': 'openstack.org/v1', 'kind': 'KuryrNetPolicy', 'metadata': {'annotations': {'networkpolicy_name': 'allow-client-a-via-named-port-ingress-rule', 'networkpolicy_namespace': 'network-policy-5545', 'networkpolicy_uid': 'ab27ccf2-daf7-4316-86a5-645c43c7679e'}, 'creationTimestamp': '2020-01-04T18:03:47Z', 'generation': 3, 'name': 'np-allow-client-a-via-named-port-ingress-rule', 'namespace': 'network-policy-5545', 'resourceVersion': '81157', 'selfLink': '/apis/openstack.org/v1/namespaces/network-policy-5545/kuryrnetpolicies/np-allow-client-a-via-named-port-ingress-rule', 'uid': '7aef0f43-0c0b-4f3f-bd82-1f8a04c41269'}, 'spec': {'egressSgRules': [{'security_group_rule': {'description': 'Kuryr-Kubernetes NetPolicy SG rule', 'direction': 'egress', 'ethertype': 'IPv4', 'id': '24d088d3-83c0-4874-acd3-9325b6971633', 'security_group_id': '7a726447-9bda-41ca-a72e-c478d73c99ec'}}], 'ingressSgRules': [{'remote_ip_prefixes': {'10.128.106.20': 'network-policy-5545'}, 'security_group_rule': {'description': 'Kuryr-Kubernetes NetPolicy SG rule', 'direction': 'ingress', 'ethertype': 'IPv4', 'id': '154bd8a2-7834-4b70-a88b-5fdddc754d5d', 'port_range_max': 80, 'port_range_min': 80, 'protocol': 'tcp', 'security_group_id': '7a726447-9bda-41ca-a72e-c478d73c99ec'}}], 'networkpolicy_spec': {'ingress': [{'ports': [{'port': 'serve-80', 'protocol': 'TCP'}]}], 'podSelector': {'matchLabels': {'pod-name': 'server'}}, 'policyTypes': ['Ingress']}, 'podSelector': {'matchLabels': {'pod-name': 'server'}}, 'securityGroupId': '7a726447-9bda-41ca-a72e-c478d73c99ec', 'securityGroupName': 'sg-allow-client-a-via-named-port-ingress-rule'}}], 'kind': 'KuryrNetPolicyList', 'metadata': {'continue': '', 'resourceVersion': '81931', 'selfLink': '/apis/openstack.org/v1/kuryrnetpolicies'}} get_kuryrnetpolicy_crds /usr/local/lib/python3.6/site-packages/kuryr_kubernetes/controller/drivers/utils.py:331
2020-01-04 18:06:22.839 1 DEBUG kuryr_kubernetes.controller.drivers.network_policy_security_groups [-] Parsing ingress Rule {'remote_ip_prefixes': {'10.128.106.20': 'network-policy-5545'}, 'security_group_rule': {'description': 'Kuryr-Kubernetes NetPolicy SG rule', 'direction': 'ingress', 'ethertype': 'IPv4', 'id': '154bd8a2-7834-4b70-a88b-5fdddc754d5d', 'port_range_max': 80, 'port_range_min': 80, 'protocol': 'tcp', 'security_group_id': '7a726447-9bda-41ca-a72e-c478d73c99ec'}} _parse_rules_on_delete_namespace /usr/local/lib/python3.6/site-packages/kuryr_kubernetes/controller/drivers/network_policy_security_groups.py:381
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry [-] Report handler unhealthy NamespaceHandler: ValueError: too many values to unpack (expected 2)
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry Traceback (most recent call last):
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry File "/usr/local/lib/python3.6/site-packages/kuryr_kubernetes/handlers/retry.py", line 78, in __call__
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry self._handler(event)
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry File "/usr/local/lib/python3.6/site-packages/kuryr_kubernetes/handlers/k8s_base.py", line 72, in __call__
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry self.on_present(obj)
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry File "/usr/local/lib/python3.6/site-packages/kuryr_kubernetes/controller/handlers/namespace.py", line 86, in on_present
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry crd_selectors = self._drv_sg.update_namespace_sg_rules(namespace)
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry File "/usr/local/lib/python3.6/site-packages/kuryr_kubernetes/controller/drivers/network_policy_security_groups.py", line 562, in update_namespace_sg_rules
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry crd_selectors.extend(self.delete_namespace_sg_rules(namespace))
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry File "/usr/local/lib/python3.6/site-packages/kuryr_kubernetes/controller/drivers/network_policy_security_groups.py", line 526, in delete_namespace_sg_rules
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry ingress_rule_list, "ingress", ns_name)
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry File "/usr/local/lib/python3.6/site-packages/kuryr_kubernetes/controller/drivers/network_policy_security_groups.py", line 388, in _parse_rules_on_delete_namespace
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry for remote_ip, namespace in remote_ip_prefixes:
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry ValueError: too many values to unpack (expected 2)
2020-01-04 18:06:22.840 1 ERROR kuryr_kubernetes.handlers.retry

Comment 2 Itzik Brown 2020-02-06 15:03:51 UTC
OSP RHOS_TRUNK-16.0-RHEL-8-20200131.n.0
OCP 4.3.0-0.nightly-2020-02-06-035100
Ran conformance test and haven't see such error.

Comment 4 errata-xmlrpc 2020-02-19 05:39:53 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:0492