tripleo-ci-centos-9-standalone-on-multinode-ipa fails because of connection timeout between keystone and memcache

Bug #1987483 reported by Takashi Kajinami
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
tripleo
New
Undecided
Unassigned

Bug Description

Description
===========
tripleo-ci-centos-9-standalone-on-multinode-ipa fails because multiple 500 error from keystone in tempest tests.

Example: https://zuul.opendev.org/t/openstack/build/89c2aeb5a3b945cf95fa83b828c7a1a7

Looking at keystone/apache log, it seems keystone is not able to connect to memcache servers properly

```
[Tue Aug 23 23:26:48.925597 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] mod_wsgi (pid=190): Exception occurred processing WSGI script '/var/www/cgi-bin/keystone/keystone'.
[Tue Aug 23 23:26:48.952950 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] Traceback (most recent call last):
[Tue Aug 23 23:26:48.953387 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib/python3.9/site-packages/flask/app.py", line 2088, in __call__
[Tue Aug 23 23:26:48.953402 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] return self.wsgi_app(environ, start_response)
...

[Tue Aug 23 23:26:48.954429 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib/python3.9/site-packages/dogpile/cache/region.py", line 1268, in _get_from_backend
[Tue Aug 23 23:26:48.954436 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] return cast(CacheReturnType, self.backend.get(key))
[Tue Aug 23 23:26:48.954445 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib/python3.9/site-packages/keystone/common/cache/_context_cache.py", line 74, in get
[Tue Aug 23 23:26:48.954451 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] value = self.proxied.get(key)
[Tue Aug 23 23:26:48.954460 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib/python3.9/site-packages/dogpile/cache/backends/memcached.py", line 192, in get
[Tue Aug 23 23:26:48.954466 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] value = self.client.get(key)
[Tue Aug 23 23:26:48.954480 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib/python3.9/site-packages/pymemcache/client/hash.py", line 361, in get
[Tue Aug 23 23:26:48.954487 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] return self._run_cmd('get', key, None, *args, **kwargs)
[Tue Aug 23 23:26:48.954496 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib/python3.9/site-packages/pymemcache/client/hash.py", line 334, in _run_cmd
[Tue Aug 23 23:26:48.954502 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] return self._safely_run_func(
[Tue Aug 23 23:26:48.954511 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib/python3.9/site-packages/pymemcache/client/hash.py", line 214, in _safely_run_func
[Tue Aug 23 23:26:48.954517 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] result = func(*args, **kwargs)
[Tue Aug 23 23:26:48.954526 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib/python3.9/site-packages/pymemcache/client/base.py", line 619, in get
[Tue Aug 23 23:26:48.954532 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] return self._fetch_cmd(b'get', [key], False).get(key, default)
[Tue Aug 23 23:26:48.954541 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib/python3.9/site-packages/pymemcache/client/base.py", line 1020, in _fetch_cmd
[Tue Aug 23 23:26:48.954547 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] self.sock.sendall(cmd)
[Tue Aug 23 23:26:48.954556 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib64/python3.9/ssl.py", line 1205, in sendall
[Tue Aug 23 23:26:48.954562 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] v = self.send(byte_view[count:])
[Tue Aug 23 23:26:48.954571 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] File "/usr/lib64/python3.9/ssl.py", line 1174, in send
[Tue Aug 23 23:26:48.954577 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] return self._sslobj.write(data)
[Tue Aug 23 23:26:48.954603 2022] [wsgi:error] [pid 190:tid 223] [remote 192.168.24.1:37798] TimeoutError: [Errno 110] Connection timed out
[Tue Aug 23 23:26:51.195453 2022] [wsgi:error] [pid 187:tid 205] [remote 192.168.24.1:37876] mod_wsgi (pid=187): Exception occurred processing WSGI script '/var/www/cgi-bin/keystone/keystone'.
[Tue Aug 23 23:26:51.200959 2022] [wsgi:error] [pid 187:tid 205] [remote 192.168.24.1:37876] Traceback (most recent call last):
...

Revision history for this message
Takashi Kajinami (kajinamit) wrote (last edit ):

https://02ea8309c4939df15922-960893a824932ed5ff76d948f9c50c81.ssl.cf1.rackcdn.com/853565/2/gate/tripleo-ci-centos-9-standalone-on-multinode-ipa/89c2aeb/logs/undercloud/var/lib/config-data/puppet-generated/keystone/etc/keystone/keystone.conf
~~~
[cache]
...
memcache_servers=standalone-0.ctlplane.ooo.test:11212
...
tls_enabled=True
~~~

https://02ea8309c4939df15922-960893a824932ed5ff76d948f9c50c81.ssl.cf1.rackcdn.com/853565/2/gate/tripleo-ci-centos-9-standalone-on-multinode-ipa/89c2aeb/logs/undercloud/var/log/extra/netstat.txt
~~~
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name
tcp 0 0 127.0.0.1:11211 0.0.0.0:* LISTEN 106790/memcached
tcp 0 0 127.0.0.1:11212 0.0.0.0:* LISTEN 106790/memcached
tcp 0 0 192.168.24.210:80 0.0.0.0:* LISTEN 109320/haproxy
tcp 0 0 192.168.24.210:443 0.0.0.0:* LISTEN 109320/haproxy
tcp 0 0 192.168.24.1:11211 0.0.0.0:* LISTEN 106790/memcached
tcp 0 0 192.168.24.1:11212 0.0.0.0:* LISTEN 106790/memcached
tcp 0 0 192.168.24.1:2224 0.0.0.0:* LISTEN 99980/python3
~~~

https://02ea8309c4939df15922-960893a824932ed5ff76d948f9c50c81.ssl.cf1.rackcdn.com/853565/2/gate/tripleo-ci-centos-9-standalone-on-multinode-ipa/89c2aeb/logs/undercloud/var/lib/config-data/puppet-generated/memcached/etc/sysconfig/memcached
~~~
PORT="11212"
USER="memcached"
MAXCONN="8192"
CACHESIZE="3870"
OPTIONS="-vv -l 127.0.0.1,192.168.24.1,notls:192.168.24.1:11211,notls:127.0.0.1:11211 -U 0 -X -t 8 -Z -o ssl_chain_cert=/etc/pki/tls/certs/memcached.crt -o ssl_key=/etc/pki/tls/private/memcached.key -o ssl_verify_mode=1"
~~~

https://02ea8309c4939df15922-960893a824932ed5ff76d948f9c50c81.ssl.cf1.rackcdn.com/853565/2/gate/tripleo-ci-centos-9-standalone-on-multinode-ipa/89c2aeb/logs/undercloud/etc/hosts
~~~
# START_HOST_ENTRIES_FOR_STACK: standalone
192.168.24.210 overcloud.ctlplane.ooo.test
192.168.24.1 standalone-0.ooo.test standalone-0
192.168.24.1 standalone-0.ctlplane.ooo.test standalone-0.ctlplane
~~~

https://02ea8309c4939df15922-960893a824932ed5ff76d948f9c50c81.ssl.cf1.rackcdn.com/853565/2/gate/tripleo-ci-centos-9-standalone-on-multinode-ipa/89c2aeb/logs/undercloud/etc/sysconfig/iptables
~~~
-A INPUT -s 192.168.24.0/24 -p tcp -m tcp --dport 11211 -m conntrack --ctstate NEW -m comment --comment "121 memcached 192.168.24.0/24 ipv4" -j ACCEPT
-A INPUT -s 192.168.24.0/24 -p tcp -m tcp --dport 11212 -m conntrack --ctstate NEW -m comment --comment "121 memcached 192.168.24.0/24 ipv4" -j ACCEPT
~~~

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

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