Comment 16 for bug 1823251

Revision history for this message
Balazs Gibizer (balazs-gibizer) wrote :

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.
$ mysqlslap -a -u openstack_citest -p --iterations 1000 --number-of-queries 8000 --number-char-cols 20 --number-int-cols 20 --concurrency 80 --password=openstack_citest &

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.

[...]
      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()

The nova db migration unit test sets timeout to these tests specifically: https://github.com/openstack/nova/blob/5d910b6695fc67517b6fe08194ed2754a182f9a9/nova/tests/unit/db/test_migrations.py#L101

But interrestingly the api db functional migration tests do not https://github.com/openstack/nova/blob/7dcc4cfea7da2ef1163e0a65618cb784f5159c6d/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
    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()

    fixtures._fixtures.timeout.TimeoutException