octavia

test_http_l7policies_and_l7rules randomly fails

Bug #2015572 reported by Gregory Thiemonge on 2023-04-07

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	octavia	Fix Released	Medium	Gregory Thiemonge

Bug Description

Reported at https://bugzilla.redhat.com/show_bug.cgi?id=2185183

Description of problem:
octavia_tempest_plugin.tests.scenario.v2.test_traffic_ops.TrafficOperationsScenarioTest.test_http_l7policies_and_l7rules randomly fails

How reproducible:
randomly ~10%

Backtrace:

octavia_tempest_plugin.tests.scenario.v2.test_traffic_ops.TrafficOperationsScenarioTest.test_http_l7policies_and_l7rules[id-3558186d-6dcd-4d9d-b7f7-adc190b66149]
-----------------------------------------------------------------------------------------------------------------------------------------------------------------

Captured traceback:
~~~~~~~~~~~~~~~~~~~
    Traceback (most recent call last):
      File "/usr/lib/python3.9/site-packages/urllib3/connectionpool.py", line 445, in _make_request
        six.raise_from(e, None)
      File "<string>", line 3, in raise_from
      File "/usr/lib/python3.9/site-packages/urllib3/connectionpool.py", line 440, in _make_request
        httplib_response = conn.getresponse()
      File "/usr/lib64/python3.9/http/client.py", line 1377, in getresponse
        response.begin()
      File "/usr/lib64/python3.9/http/client.py", line 320, in begin
        version, status, reason = self._read_status()
      File "/usr/lib64/python3.9/http/client.py", line 281, in _read_status
        line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
      File "/usr/lib64/python3.9/socket.py", line 704, in readinto
        return self._sock.recv_into(b)
    socket.timeout: timed out

During handling of the above exception, another exception occurred:

    Traceback (most recent call last):
      File "/usr/lib/python3.9/site-packages/requests/adapters.py", line 439, in send
        resp = conn.urlopen(
      File "/usr/lib/python3.9/site-packages/urllib3/connectionpool.py", line 755, in urlopen
        retries = retries.increment(
      File "/usr/lib/python3.9/site-packages/urllib3/util/retry.py", line 532, in increment
        raise six.reraise(type(error), error, _stacktrace)
      File "/usr/lib/python3.9/site-packages/urllib3/packages/six.py", line 709, in reraise
        raise value
      File "/usr/lib/python3.9/site-packages/urllib3/connectionpool.py", line 699, in urlopen
        httplib_response = self._make_request(
      File "/usr/lib/python3.9/site-packages/urllib3/connectionpool.py", line 447, in _make_request
        self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
      File "/usr/lib/python3.9/site-packages/urllib3/connectionpool.py", line 336, in _raise_timeout
        raise ReadTimeoutError(
    urllib3.exceptions.ReadTimeoutError: HTTPConnectionPool(host='10.0.0.227', port=84): Read timed out. (read timeout=2)

During handling of the above exception, another exception occurred:

    Traceback (most recent call last):
      File "/usr/lib/python3.9/site-packages/octavia_tempest_plugin/tests/scenario/v2/test_traffic_ops.py", line 712, in test_http_l7policies_and_l7rules
        self.assertConsistentResponse((200, self.webserver1_response),
      File "/usr/lib/python3.9/site-packages/octavia_tempest_plugin/tests/validators.py", line 357, in assertConsistentResponse
        req = session.request(method, url,
      File "/usr/lib/python3.9/site-packages/requests/sessions.py", line 542, in request
        resp = self.send(prep, **send_kwargs)
      File "/usr/lib/python3.9/site-packages/requests/sessions.py", line 655, in send
        r = adapter.send(request, **kwargs)
      File "/usr/lib/python3.9/site-packages/requests/adapters.py", line 529, in send
        raise ReadTimeout(e, request=request)
    requests.exceptions.ReadTimeout: HTTPConnectionPool(host='10.0.0.227', port=84): Read timed out. (read timeout=2)

tpcdump outputs from another run (not the same VIP address)

undercloud:

12:53:48.039779 IP 10.0.0.54.52864 > 10.0.0.159.84: Flags [S], seq 692056855, win 64240, options [mss 1460,sackOK,TS val 176487310 ecr 0,nop,wscale 7], length 0
12:53:48.041801 IP 10.0.0.159.84 > 10.0.0.54.52864: Flags [S.], seq 79995390, ack 692056856, win 43090, options [mss 1402,sackOK,TS val 3299079005 ecr 176487310,nop,wscale 11], length 0
12:53:48.041852 IP 10.0.0.54.52864 > 10.0.0.159.84: Flags [.], ack 1, win 502, options [nop,nop,TS val 176487312 ecr 3299079005], length 0
12:53:48.041909 IP 10.0.0.54.52864 > 10.0.0.159.84: Flags [P.], seq 1:145, ack 1, win 502, options [nop,nop,TS val 176487312 ecr 3299079005], length 144
12:53:48.083807 IP 10.0.0.159.84 > 10.0.0.54.52864: Flags [.], ack 145, win 21, options [nop,nop,TS val 3299079048 ecr 176487312], length 0
12:53:50.044449 IP 10.0.0.54.52864 > 10.0.0.159.84: Flags [F.], seq 145, ack 1, win 502, options [nop,nop,TS val 176489315 ecr 3299079048], length 0
12:53:50.085643 IP 10.0.0.159.84 > 10.0.0.54.52864: Flags [.], ack 146, win 21, options [nop,nop,TS val 3299081050 ecr 176489315], length 0
12:53:56.107623 IP 10.0.0.159.84 > 10.0.0.54.52864: Flags [P.], seq 1:163, ack 146, win 21, options [nop,nop,TS val 3299087072 ecr 176489315], length 162
12:53:56.107668 IP 10.0.0.54.52864 > 10.0.0.159.84: Flags [R], seq 692057001, win 0, length 0
12:53:56.107741 IP 10.0.0.159.84 > 10.0.0.54.52864: Flags [F.], seq 163, ack 146, win 21, options [nop,nop,TS val 3299087072 ecr 176489315], length 0
12:53:56.107758 IP 10.0.0.54.52864 > 10.0.0.159.84: Flags [R], seq 692057001, win 0, length 0

The FIN packet sent from the client at 12:53:50.044449 is the termination of the tcp connection after a 2 sec timeout (default value in octavia-tempest-plugin)

compute-0 (LB, vip port):

tap7f5d8569-04.pcap
16:53:48.041495 IP 10.0.0.54.52864 > 10.1.1.178.84: Flags [S], seq 692056855, win 64240, options [mss 1460,sackOK,TS val 176487310 ecr 0,nop,wscale 7], length 0
16:53:48.041844 IP 10.1.1.178.84 > 10.0.0.54.52864: Flags [S.], seq 79995390, ack 692056856, win 43090, options [mss 1402,sackOK,TS val 3299079005 ecr 176487310,nop,wscale 11], length 0
16:53:48.042940 IP 10.0.0.54.52864 > 10.1.1.178.84: Flags [.], ack 1, win 502, options [nop,nop,TS val 176487312 ecr 3299079005], length 0
16:53:48.042971 IP 10.0.0.54.52864 > 10.1.1.178.84: Flags [P.], seq 1:145, ack 1, win 502, options [nop,nop,TS val 176487312 ecr 3299079005], length 144
16:53:48.084218 IP 10.1.1.178.84 > 10.0.0.54.52864: Flags [.], ack 145, win 21, options [nop,nop,TS val 3299079048 ecr 176487312], length 0
16:53:50.045287 IP 10.0.0.54.52864 > 10.1.1.178.84: Flags [F.], seq 145, ack 1, win 502, options [nop,nop,TS val 176489315 ecr 3299079048], length 0
16:53:50.086054 IP 10.1.1.178.84 > 10.0.0.54.52864: Flags [.], ack 146, win 21, options [nop,nop,TS val 3299081050 ecr 176489315], length 0
16:53:56.108080 IP 10.1.1.178.84 > 10.0.0.54.52864: Flags [P.], seq 1:163, ack 146, win 21, options [nop,nop,TS val 3299087072 ecr 176489315], length 162
16:53:56.108279 IP 10.1.1.178.84 > 10.0.0.54.52864: Flags [F.], seq 163, ack 146, win 21, options [nop,nop,TS val 3299087072 ecr 176489315], length 0
16:53:56.108412 IP 10.0.0.54.52864 > 10.1.1.178.84: Flags [R], seq 692057001, win 0, length 0
16:53:56.108457 IP 10.0.0.54.52864 > 10.1.1.178.84: Flags [R], seq 692057001, win 0, length 0

compute-0 (LB, member port):

tapd9ee04bd-6c.pcap
16:53:48.043569 fa:16:3e:4a:e3:cd > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42: Request who-has 10.2.1.201 tell 10.2.1.220, length 28
16:53:48.043774 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype ARP (0x0806), length 42: Reply 10.2.1.201 is-at fa:16:3e:e5:06:68, length 28
16:53:48.043902 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45847 > 10.2.1.201.80: Flags [S], seq 479897052, win 43462, options [mss 1402,sackOK,TS val 4071114320 ecr 0,nop,wscale 11], length 0
16:53:49.045169 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45847 > 10.2.1.201.80: Flags [S], seq 479897052, win 43462, options [mss 1402,sackOK,TS val 4071115322 ecr 0,nop,wscale 11], length 0
16:53:51.093070 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45847 > 10.2.1.201.80: Flags [S], seq 479897052, win 43462, options [mss 1402,sackOK,TS val 4071117370 ecr 0,nop,wscale 11], length 0
16:53:53.050223 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45851 > 10.2.1.201.80: Flags [S], seq 1703562389, win 43462, options [mss 1402,sackOK,TS val 4071119327 ecr 0,nop,wscale 11], length 0
16:53:54.101034 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45851 > 10.2.1.201.80: Flags [S], seq 1703562389, win 43462, options [mss 1402,sackOK,TS val 4071120378 ecr 0,nop,wscale 11], length 0
16:53:56.105191 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45851: Flags [S.], seq 2546563750, ack 1703562390, win 65330, options [mss 1402,sackOK,TS val 593222582 ecr 4071119327,nop,wscale 4], length 0
16:53:56.105778 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 66: 10.2.1.220.45851 > 10.2.1.201.80: Flags [.], ack 1, win 22, options [nop,nop,TS val 4071122382 ecr 593222582], length 0
16:53:56.106345 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 205: 10.2.1.220.45851 > 10.2.1.201.80: Flags [P.], seq 1:140, ack 1, win 22, options [nop,nop,TS val 4071122383 ecr 593222582], length 139: HTTP: GET / HTTP/1.1
16:53:56.106704 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 66: 10.2.1.201.80 > 10.2.1.220.45851: Flags [.], ack 140, win 4075, options [nop,nop,TS val 593222585 ecr 4071122383], length 0
16:53:56.107530 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 228: 10.2.1.201.80 > 10.2.1.220.45851: Flags [P.], seq 1:163, ack 140, win 4075, options [nop,nop,TS val 593222586 ecr 4071122383], length 162: HTTP: HTTP/1.1 200 OK
16:53:56.107649 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 66: 10.2.1.201.80 > 10.2.1.220.45851: Flags [F.], seq 163, ack 140, win 4075, options [nop,nop,TS val 593222586 ecr 4071122383], length 0
16:53:56.107688 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 66: 10.2.1.220.45851 > 10.2.1.201.80: Flags [.], ack 163, win 22, options [nop,nop,TS val 4071122384 ecr 593222586], length 0
16:53:56.108630 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 66: 10.2.1.220.45851 > 10.2.1.201.80: Flags [F.], seq 140, ack 164, win 22, options [nop,nop,TS val 4071122385 ecr 593222586], length 0
16:53:56.109034 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 66: 10.2.1.201.80 > 10.2.1.220.45851: Flags [.], ack 141, win 4075, options [nop,nop,TS val 593222587 ecr 4071122385], length 0
16:53:57.256115 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45847: Flags [S.], seq 1063921752, ack 479897053, win 65330, options [mss 1402,sackOK,TS

Many unreplied-SYN packets sent by the load balancer

compute-1 (backend server):

tap71ade383-18.pcap
16:53:48.044206 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45847 > 10.2.1.201.80: Flags [S], seq 479897052, win 43462, options [mss 1402,sackOK,TS val 4071114320 ecr 0,nop,wscale 11], length 0
16:53:48.044545 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45847: Flags [S.], seq 1063921752, ack 479897053, win 65330, options [mss 1402,sackOK,TS val 593214523 ecr 4071114320,nop,wscale 4], length 0
16:53:49.045318 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45847 > 10.2.1.201.80: Flags [S], seq 479897052, win 43462, options [mss 1402,sackOK,TS val 4071115322 ecr 0,nop,wscale 11], length 0
16:53:49.045541 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45847: Flags [S.], seq 1063921752, ack 479897053, win 65330, options [mss 1402,sackOK,TS val 593215524 ecr 4071114320,nop,wscale 4], length 0
16:53:50.055051 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45847: Flags [S.], seq 1063921752, ack 479897053, win 65330, options [mss 1402,sackOK,TS val 593216534 ecr 4071114320,nop,wscale 4], length 0
16:53:51.092783 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45847 > 10.2.1.201.80: Flags [S], seq 479897052, win 43462, options [mss 1402,sackOK,TS val 4071117370 ecr 0,nop,wscale 11], length 0
16:53:51.093071 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45847: Flags [S.], seq 1063921752, ack 479897053, win 65330, options [mss 1402,sackOK,TS val 593217572 ecr 4071114320,nop,wscale 4], length 0
16:53:53.050092 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45851 > 10.2.1.201.80: Flags [S], seq 1703562389, win 43462, options [mss 1402,sackOK,TS val 4071119327 ecr 0,nop,wscale 11], length 0
16:53:53.050590 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45851: Flags [S.], seq 2546563750, ack 1703562390, win 65330, options [mss 1402,sackOK,TS val 593219529 ecr 4071119327,nop,wscale 4], length 0
16:53:53.094983 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45847: Flags [S.], seq 1063921752, ack 479897053, win 65330, options [mss 1402,sackOK,TS val 593219574 ecr 4071114320,nop,wscale 4], length 0
16:53:53.159033 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype ARP (0x0806), length 42: Request who-has 10.2.1.220 tell 10.2.1.201, length 28
16:53:53.159674 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype ARP (0x0806), length 42: Reply 10.2.1.220 is-at fa:16:3e:4a:e3:cd, length 28
16:53:54.055053 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45851: Flags [S.], seq 2546563750, ack 1703562390, win 65330, options [mss 1402,sackOK,TS val 593220534 ecr 4071119327,nop,wscale 4], length 0
16:53:54.100741 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 74: 10.2.1.220.45851 > 10.2.1.201.80: Flags [S], seq 1703562389, win 43462, options [mss 1402,sackOK,TS val 4071120378 ecr 0,nop,wscale 11], length 0
16:53:54.101008 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45851: Flags [S.], seq 2546563750, ack 1703562390, win 65330, options [mss 1402,sackOK,TS val 593220580 ecr 4071119327,nop,wscale 4], length 0
16:53:54.183218 fa:16:3e:e5:06:68 > fa:16:3e:88:cd:6d, ethertype ARP (0x0806), length 42: Request who-has 10.2.1.220 tell 10.2.1.201, length 28
16:53:54.183645 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype ARP (0x0806), length 42: Reply 10.2.1.220 is-at fa:16:3e:4a:e3:cd, length 28
16:53:56.103047 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45851: Flags [S.], seq 2546563750, ack 1703562390, win 65330, options [mss 1402,sackOK,TS val 593222582 ecr 4071119327,nop,wscale 4], length 0
16:53:56.105709 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 66: 10.2.1.220.45851 > 10.2.1.201.80: Flags [.], ack 1, win 22, options [nop,nop,TS val 4071122382 ecr 593222582], length 0
16:53:56.105911 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 205: 10.2.1.220.45851 > 10.2.1.201.80: Flags [P.], seq 1:140, ack 1, win 22, options [nop,nop,TS val 4071122383 ecr 593222582], length 139: HTTP: GET / HTTP/1.1
16:53:56.106018 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 66: 10.2.1.201.80 > 10.2.1.220.45851: Flags [.], ack 140, win 4075, options [nop,nop,TS val 593222585 ecr 4071122383], length 0
16:53:56.106828 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 228: 10.2.1.201.80 > 10.2.1.220.45851: Flags [P.], seq 1:163, ack 140, win 4075, options [nop,nop,TS val 593222586 ecr 4071122383], length 162: HTTP: HTTP/1.1 200 OK
16:53:56.107020 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 66: 10.2.1.201.80 > 10.2.1.220.45851: Flags [F.], seq 163, ack 140, win 4075, options [nop,nop,TS val 593222586 ecr 4071122383], length 0
16:53:56.107256 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 66: 10.2.1.220.45851 > 10.2.1.201.80: Flags [.], ack 163, win 22, options [nop,nop,TS val 4071122384 ecr 593222586], length 0
16:53:56.108160 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 66: 10.2.1.220.45851 > 10.2.1.201.80: Flags [F.], seq 140, ack 164, win 22, options [nop,nop,TS val 4071122385 ecr 593222586], length 0
16:53:56.108381 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 66: 10.2.1.201.80 > 10.2.1.220.45851: Flags [.], ack 141, win 4075, options [nop,nop,TS val 593222587 ecr 4071122385], length 0
16:53:57.255104 fa:16:3e:e5:06:68 > fa:16:3e:4a:e3:cd, ethertype IPv4 (0x0800), length 74: 10.2.1.201.80 > 10.2.1.220.45847: Flags [S.], seq 1063921752, ack 479897053, win 65330, options [mss 1402,sackOK,TS val 593223734 ecr 4071114320,nop,wscale 4], length 0
16:53:57.256286 fa:16:3e:4a:e3:cd > fa:16:3e:e5:06:68, ethertype IPv4 (0x0800), length 54: 10.2.1.220.45847 > 10.2.1.201.80: Flags [R], seq 479897053, win 0, length 0

The backend server sent the SYN-ACK packets to an incorrect mac address.
This was fixed at 16:53:56.103047 after it sent an ARP request

The actual response of the load balancer was sent 8 sec after the first SYN (while the timeout in octavia-tempest-plugin is 2 sec)

Searching for the ip address of the member port in the logs:

controller-0
/var/log/containers/octavia/worker.log.2.gz:2023-04-06 16:52:38.849 20 DEBUG novaclient.v2.client [req-1158c1eb-1729-4265-b770-aea13fbea62d - 805c65b4a9e54d469f2fcc3ea75dc27c - - -] RESP BODY: {"interfaceAttachment": {"net_id": "6f714bea-bfd8-480d-978b-176910fe426a", "port_id": "d9ee04bd-6cbb-4112-b979-08f83f774b01", "mac_addr": "fa:16:3e:4a:e3:cd", "port_state": "ACTIVE", "fixed_ips": [{"subnet_id": "042d5e5f-e26c-4887-8119-65fdcfa32e0e", "ip_address": "10.2.1.220"}, {"subnet_id": "a50291c7-c2f8-4c57-8832-98f52b203c04", "ip_address": "fd7b:f9f7:fff:4eca::252"}]}} _http_log_response /usr/lib/python3.9/site-packages/keystoneauth1/session.py:582

controller-1
/var/log/containers/octavia/worker.log.2.gz:2023-04-06 16:39:24.600 14 DEBUG novaclient.v2.client [req-0bc9021c-2d2f-4d42-aa93-d4191316aaa8 - 227487505cc545bca3f3a297caf1f4b2 - - -] RESP BODY: {"interfaceAttachment": {"net_id": "6f714bea-bfd8-480d-978b-176910fe426a", "port_id": "3cca7c41-5943-4f7a-9ea2-44e51a00dfac", "mac_addr": "fa:16:3e:88:cd:6d", "port_state": "ACTIVE", "fixed_ips": [{"subnet_id": "042d5e5f-e26c-4887-8119-65fdcfa32e0e", "ip_address": "10.2.1.220"}, {"subnet_id": "a50291c7-c2f8-4c57-8832-98f52b203c04", "ip_address": "fd7b:f9f7:fff:4eca::135"}]}} _http_log_response /usr/lib/python3.9/site-packages/keystoneauth1/session.py:582

controller-2
/var/log/containers/octavia/worker.log.2.gz:2023-04-06 16:40:08.493 14 DEBUG novaclient.v2.client [req-74362e60-ca00-49e3-b70c-2bf3d601a82e - 227487505cc545bca3f3a297caf1f4b2 - - -] REQ: curl -g -i -X DELETE http://172.17.1.141:8774/v2.1/servers/94874609-d041-43a2-a392-c69121b577ab/os-interface/3cca7c41-5943-4f7a-9ea2-44e51a00dfac -H "Accept: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}517e872183a204bf09d94fb9e06363c4f9f023b2a6ded4fd0cd6b846553203b7" -H "X-OpenStack-Nova-API-Version: 2.15" _http_log_request /usr/lib/python3.9/site-packages/keystoneauth1/session.py:519
/var/log/containers/octavia/worker.log.2.gz:2023-04-06 16:40:08.587 14 DEBUG novaclient.v2.client [req-74362e60-ca00-49e3-b70c-2bf3d601a82e - 227487505cc545bca3f3a297caf1f4b2 - - -] DELETE call to compute for http://172.17.1.141:8774/v2.1/servers/94874609-d041-43a2-a392-c69121b577ab/os-interface/3cca7c41-5943-4f7a-9ea2-44e51a00dfac used request id req-9d4ae163-298e-4bc8-8dc0-9bf6949716ec request /usr/lib/python3.9/site-packages/keystoneauth1/session.py:954
/var/log/containers/octavia/worker.log.2.gz:2023-04-06 16:40:09.833 14 DEBUG octavia.network.drivers.neutron.allowed_address_pairs [req-74362e60-ca00-49e3-b70c-2bf3d601a82e - 227487505cc545bca3f3a297caf1f4b2 - - -] VIP instance port 3cca7c41-5943-4f7a-9ea2-44e51a00dfac already deleted. Skipping. delete_port /usr/lib/python3.9/site-packages/octavia/network/drivers/neutron/allowed_address_pairs.py:813

At 16:39:24, a port 3cca7c41-5943-4f7a-9ea2-44e51a00dfac was created with the ip address 10.2.1.220 and mac address fa:16:3e:88:cd:6d
At 16:40:08, this port was deleted
At 16:52:38, a port d9ee04bd-6cbb-4112-b979-08f83f774b01 was created with the same ip addr (10.2.1.220) but a different mac address fa:16:3e:4a:e3:cd

It seems that the cirros VM didn't update the ARP table when it received a packet from the newly created port and replied using the mac address of the old port.

This issue was mitigated automatically after 8 sec but it triggered an error in the test.
Another way to mitigate it would be to send a GARP from the load balancer when a new port is plugged into the amphora.

Tags:

Gregory Thiemonge (gthiemonge) on 2023-04-07

Changed in octavia:
importance:	Undecided → Medium
status:	New → Confirmed
assignee:	nobody → Gregory Thiemonge (gthiemonge)

OpenStack Infra (hudson-openstack) on 2023-04-11

Changed in octavia:
status:	Confirmed → In Progress

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-04-18: Fix merged to octavia (master)

Reviewed: https://review.opendev.org/c/openstack/octavia/+/879898
Committed: https://opendev.org/openstack/octavia/commit/18cd1f34c8a918ab6f969a3271ac74132c4ac736
Submitter: "Zuul (22348)"
Branch: master

commit 18cd1f34c8a918ab6f969a3271ac74132c4ac736
Author: Gregory Thiemonge <email address hidden>
Date: Fri Apr 7 08:04:45 2023 -0400

Send IP advertisements when plugging a new member subnet

    When plugging a new subnet, the amphora sends a packet advertising the
    IP address of the port. In case previously deallocated IP addresses are
    re-used, it helps the other resources on the same L2 network to flush
    the old ARP entries.

Closes-Bug: #2015572

Change-Id: Iecedb9e9c8f293cd4c067900e1696f5050769ee8

Changed in octavia:
status:	In Progress → Fix Released

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-04-18: Fix proposed to octavia (stable/2023.1)

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

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-04-18: Fix proposed to octavia (stable/zed)

Fix proposed to branch: stable/zed
Review: https://review.opendev.org/c/openstack/octavia/+/880724

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-04-18: Fix proposed to octavia (stable/yoga)

Fix proposed to branch: stable/yoga
Review: https://review.opendev.org/c/openstack/octavia/+/880725

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-04-18: Fix proposed to octavia (stable/xena)

Fix proposed to branch: stable/xena
Review: https://review.opendev.org/c/openstack/octavia/+/880726

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-04-18: Fix proposed to octavia (stable/wallaby)

Fix proposed to branch: stable/wallaby
Review: https://review.opendev.org/c/openstack/octavia/+/880727

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-06-07: Fix merged to octavia (stable/2023.1)

Reviewed: https://review.opendev.org/c/openstack/octavia/+/880723
Committed: https://opendev.org/openstack/octavia/commit/f03a2df9aa10f6901020292b2f2f4eaa912c4cb8
Submitter: "Zuul (22348)"
Branch: stable/2023.1

commit f03a2df9aa10f6901020292b2f2f4eaa912c4cb8
Author: Gregory Thiemonge <email address hidden>
Date: Fri Apr 7 08:04:45 2023 -0400

Send IP advertisements when plugging a new member subnet

Closes-Bug: #2015572

Change-Id: Iecedb9e9c8f293cd4c067900e1696f5050769ee8
(cherry picked from commit 18cd1f34c8a918ab6f969a3271ac74132c4ac736)

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-06-07: Fix merged to octavia (stable/zed)

Reviewed: https://review.opendev.org/c/openstack/octavia/+/880724
Committed: https://opendev.org/openstack/octavia/commit/6a380e3775e10485f1ded67d12bab3725225c8bb
Submitter: "Zuul (22348)"
Branch: stable/zed

commit 6a380e3775e10485f1ded67d12bab3725225c8bb
Author: Gregory Thiemonge <email address hidden>
Date: Fri Apr 7 08:04:45 2023 -0400

Send IP advertisements when plugging a new member subnet

Closes-Bug: #2015572

Conflicts:
octavia/amphorae/backends/agent/api_server/plug.py

    Change-Id: Iecedb9e9c8f293cd4c067900e1696f5050769ee8
    (cherry picked from commit 18cd1f34c8a918ab6f969a3271ac74132c4ac736)
    (cherry picked from commit f03a2df9aa10f6901020292b2f2f4eaa912c4cb8)

tags:	added: in-stable-zed
tags:	added: in-stable-wallaby

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-06-07: Fix merged to octavia (stable/wallaby)

Reviewed: https://review.opendev.org/c/openstack/octavia/+/880727
Committed: https://opendev.org/openstack/octavia/commit/38714459f6340a3a111be98a3ab569fca5663537
Submitter: "Zuul (22348)"
Branch: stable/wallaby

commit 38714459f6340a3a111be98a3ab569fca5663537
Author: Gregory Thiemonge <email address hidden>
Date: Fri Apr 7 08:04:45 2023 -0400

Send IP advertisements when plugging a new member subnet

Closes-Bug: #2015572

Conflicts:
octavia/amphorae/backends/agent/api_server/plug.py

    Change-Id: Iecedb9e9c8f293cd4c067900e1696f5050769ee8
    (cherry picked from commit 18cd1f34c8a918ab6f969a3271ac74132c4ac736)
    (cherry picked from commit f03a2df9aa10f6901020292b2f2f4eaa912c4cb8)
    (cherry picked from commit 6a380e3775e10485f1ded67d12bab3725225c8bb)
    (cherry picked from commit 4b5849c8d8a673c6a4c2cf15b4fb5e69b2b6308f)
    (cherry picked from commit 44b792bdeaae37b4a14a5c4a256a7a8b98ee1de6)

tags:

added: in-stable-yoga

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-06-07: Fix merged to octavia (stable/yoga)

#10

Reviewed: https://review.opendev.org/c/openstack/octavia/+/880725
Committed: https://opendev.org/openstack/octavia/commit/e0f7a145023dfd22865e832a571faccd2da391c5
Submitter: "Zuul (22348)"
Branch: stable/yoga

commit e0f7a145023dfd22865e832a571faccd2da391c5
Author: Gregory Thiemonge <email address hidden>
Date: Fri Apr 7 08:04:45 2023 -0400

Send IP advertisements when plugging a new member subnet

Closes-Bug: #2015572

Conflicts:
octavia/amphorae/backends/agent/api_server/plug.py

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-06-08: Fix merged to octavia (stable/xena)

#11

Reviewed: https://review.opendev.org/c/openstack/octavia/+/880726
Committed: https://opendev.org/openstack/octavia/commit/44b792bdeaae37b4a14a5c4a256a7a8b98ee1de6
Submitter: "Zuul (22348)"
Branch: stable/xena

commit 44b792bdeaae37b4a14a5c4a256a7a8b98ee1de6
Author: Gregory Thiemonge <email address hidden>
Date: Fri Apr 7 08:04:45 2023 -0400

Send IP advertisements when plugging a new member subnet

Closes-Bug: #2015572

Conflicts:
octavia/amphorae/backends/agent/api_server/plug.py

tags:

added: in-stable-xena

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-07-19: Fix included in openstack/octavia 10.1.0

#12

This issue was fixed in the openstack/octavia 10.1.0 release.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-07-20: Fix included in openstack/octavia 11.0.1

#13

This issue was fixed in the openstack/octavia 11.0.1 release.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-09-15: Fix included in openstack/octavia 13.0.0.0rc1

#14

This issue was fixed in the openstack/octavia 13.0.0.0rc1 release candidate.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2024-03-05: Fix included in openstack/octavia wallaby-eom

#15

This issue was fixed in the openstack/octavia wallaby-eom release.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2024-03-05: Fix included in openstack/octavia xena-eom

#16

This issue was fixed in the openstack/octavia xena-eom release.

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

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