With enough load the test times out but due to the load the timeout time is pretty random as the signal handler also gets delayed due to the same load.
[...]
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/pymysql/connections.py", line 683, in _read_bytes
data = self._rfile.read(num_bytes)
File "/usr/lib/python3.8/socket.py", line 669, in readinto
return self._sock.recv_into(b)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/greenio/base.py", line 371, in recv_into
return self._recv_loop(self.fd.recv_into, 0, buffer, nbytes, flags)
[...]
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/hubs/epolls.py", line 31, in do_poll
return self.poll.poll(seconds)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/fixtures/_fixtures/timeout.py", line 52, in signal_handler
raise TimeoutException()
Now that I can reporduce this I can play with the timeout values to see what is reasonable.
Full primary stack trace:
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1276, in _execute_context
self.dialect.do_execute(
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 593, in do_execute
cursor.execute(statement, parameters)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/pymysql/cursors.py", line 163, in execute
result = self._query(query)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/pymysql/cursors.py", line 321, in _query
conn.query(q)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/pymysql/connections.py", line 505, in query
self._affected_rows = self._read_query_result(unbuffered=unbuffered)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/pymysql/connections.py", line 724, in _read_query_result
result.read()
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/pymysql/connections.py", line 1069, in read
first_packet = self.connection._read_packet()
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/pymysql/connections.py", line 646, in _read_packet
packet_header = self._read_bytes(4)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/pymysql/connections.py", line 683, in _read_bytes
data = self._rfile.read(num_bytes)
File "/usr/lib/python3.8/socket.py", line 669, in readinto
return self._sock.recv_into(b)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/greenio/base.py", line 371, in recv_into
return self._recv_loop(self.fd.recv_into, 0, buffer, nbytes, flags)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/greenio/base.py", line 359, in _recv_loop
self._read_trampoline()
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/greenio/base.py", line 327, in _read_trampoline
self._trampoline(
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/greenio/base.py", line 208, in _trampoline
return trampoline(fd, read=read, write=write, timeout=timeout,
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/hubs/__init__.py", line 159, in trampoline
return hub.switch()
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/hubs/hub.py", line 313, in switch
return self.greenlet.switch()
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/hubs/hub.py", line 365, in run
self.wait(sleep_time)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/hubs/poll.py", line 80, in wait
presult = self.do_poll(seconds)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/eventlet/hubs/epolls.py", line 31, in do_poll
return self.poll.poll(seconds)
File "/root/rtox/nova/py38-walk/.tox/py38/lib/python3.8/site-packages/fixtures/_fixtures/timeout.py", line 52, in signal_handler
raise TimeoutException()
Finally I managed to reproduce the same issue locally.
Reproduction steps:
1) create IO. I did started coping files in a loop.
$ for i in {1..1000}; do cp loadfile loadfile3; done &
2) create load on mysqld. openstack_ citest &
$ mysqlslap -a -u openstack_citest -p --iterations 1000 --number-of-queries 8000 --number-char-cols 20 --number-int-cols 20 --concurrency 80 --password=
3) run the nova unit test suite
$ tox -e py38
With enough load the test times out but due to the load the timeout time is pretty random as the signal handler also gets delayed due to the same load.
[...] rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ pymysql/ connections. py", line 683, in _read_bytes read(num_ bytes)
File "/root/
data = self._rfile.
File "/usr/lib/ python3. 8/socket. py", line 669, in readinto recv_into( b)
return self._sock.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ greenio/ base.py" , line 371, in recv_into loop(self. fd.recv_ into, 0, buffer, nbytes, flags)
return self._recv_
[...]
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ hubs/epolls. py", line 31, in do_poll poll(seconds)
return self.poll.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ fixtures/ _fixtures/ timeout. py", line 52, in signal_handler
raise TimeoutException()
The nova db migration unit test sets timeout to these tests specifically: https:/ /github. com/openstack/ nova/blob/ 5d910b6695fc675 17b6fe08194ed27 54a182f9a9/ nova/tests/ unit/db/ test_migrations .py#L101
But interrestingly the api db functional migration tests do not https:/ /github. com/openstack/ nova/blob/ 7dcc4cfea7da2ef 1163e0a65618cb7 84f5159c6d/ nova/tests/ functional/ db/api/ test_migrations .py
Now that I can reporduce this I can play with the timeout values to see what is reasonable.
Full primary stack trace:
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ sqlalchemy/ engine/ base.py" , line 1276, in _execute_context dialect. do_execute(
self.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ sqlalchemy/ engine/ default. py", line 593, in do_execute execute( statement, parameters)
cursor.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ pymysql/ cursors. py", line 163, in execute
result = self._query(query)
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ pymysql/ cursors. py", line 321, in _query
conn.query(q)
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ pymysql/ connections. py", line 505, in query _affected_ rows = self._read_ query_result( unbuffered= unbuffered)
self.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ pymysql/ connections. py", line 724, in _read_query_result
result.read()
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ pymysql/ connections. py", line 1069, in read ._read_ packet( )
first_packet = self.connection
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ pymysql/ connections. py", line 646, in _read_packet
packet_header = self._read_bytes(4)
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ pymysql/ connections. py", line 683, in _read_bytes read(num_ bytes)
data = self._rfile.
File "/usr/lib/ python3. 8/socket. py", line 669, in readinto recv_into( b)
return self._sock.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ greenio/ base.py" , line 371, in recv_into loop(self. fd.recv_ into, 0, buffer, nbytes, flags)
return self._recv_
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ greenio/ base.py" , line 359, in _recv_loop _read_trampolin e()
self.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ greenio/ base.py" , line 327, in _read_trampoline _trampoline(
self.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ greenio/ base.py" , line 208, in _trampoline
return trampoline(fd, read=read, write=write, timeout=timeout,
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ hubs/__ init__. py", line 159, in trampoline
return hub.switch()
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ hubs/hub. py", line 313, in switch switch( )
return self.greenlet.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ hubs/hub. py", line 365, in run wait(sleep_ time)
self.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ hubs/poll. py", line 80, in wait poll(seconds)
presult = self.do_
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ eventlet/ hubs/epolls. py", line 31, in do_poll poll(seconds)
return self.poll.
File "/root/ rtox/nova/ py38-walk/ .tox/py38/ lib/python3. 8/site- packages/ fixtures/ _fixtures/ timeout. py", line 52, in signal_handler
raise TimeoutException()
fixtures. _fixtures. timeout. TimeoutExceptio n