test_walk_versions tests fail with "IndexError: tuple index out of range" after timeout

Bug #1687027 reported by Ihar Hrachyshka on 2017-04-28
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
neutron
High
Miguel Lavalle

Bug Description

http://logs.openstack.org/99/460399/1/check/gate-neutron-dsvm-functional-ubuntu-xenial/25de43d/testr_results.html.gz

Traceback (most recent call last):
  File "neutron/tests/base.py", line 115, in func
    return f(self, *args, **kwargs)
  File "neutron/tests/base.py", line 115, in func
    return f(self, *args, **kwargs)
  File "neutron/tests/functional/db/test_migrations.py", line 551, in test_walk_versions
    self._migrate_up(config, engine, dest, curr, with_data=True)
  File "neutron/tests/functional/db/test_migrations.py", line 537, in _migrate_up
    migration.do_alembic_command(config, 'upgrade', dest)
  File "neutron/db/migration/cli.py", line 109, in do_alembic_command
    getattr(alembic_command, cmd)(config, *args, **kwargs)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/command.py", line 254, in upgrade
    script.run_env()
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/script/base.py", line 416, in run_env
    util.load_python_file(self.dir, 'env.py')
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/util/pyfiles.py", line 93, in load_python_file
    module = load_module_py(module_id, path)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/util/compat.py", line 75, in load_module_py
    mod = imp.load_source(module_id, path, fp)
  File "neutron/db/migration/alembic_migrations/env.py", line 120, in <module>
    run_migrations_online()
  File "neutron/db/migration/alembic_migrations/env.py", line 114, in run_migrations_online
    context.run_migrations()
  File "<string>", line 8, in run_migrations
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/runtime/environment.py", line 817, in run_migrations
    self.get_context().run_migrations(**kw)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/runtime/migration.py", line 323, in run_migrations
    step.migration_fn(**kw)
  File "/opt/stack/new/neutron/neutron/db/migration/alembic_migrations/versions/mitaka/expand/3894bccad37f_add_timestamp_to_base_resources.py", line 36, in upgrade
    sa.Column(column_name, sa.DateTime(), nullable=True)
  File "<string>", line 8, in add_column
  File "<string>", line 3, in add_column
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/operations/ops.py", line 1551, in add_column
    return operations.invoke(op)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/operations/base.py", line 318, in invoke
    return fn(self, operation)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/operations/toimpl.py", line 123, in add_column
    schema=schema
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/ddl/impl.py", line 172, in add_column
    self._exec(base.AddColumn(table_name, column, schema=schema))
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/alembic/ddl/impl.py", line 118, in _exec
    return conn.execute(construct, *multiparams, **params)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 945, in execute
    return meth(self, multiparams, params)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/sqlalchemy/sql/ddl.py", line 68, in _execute_on_connection
    return connection._execute_ddl(self, multiparams, params)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1002, in _execute_ddl
    compiled
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1189, in _execute_context
    context)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1398, in _handle_dbapi_exception
    util.raise_from_cause(newraise, exc_info)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb, cause=cause)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
    context)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
    cursor.execute(statement, parameters)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
    result = self._query(query)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
    conn.query(q)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
    self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
    result.read()
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
    first_packet = self.connection._read_packet()
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/pymysql/connections.py", line 987, in _read_packet
    packet_header = self._read_bytes(4)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/pymysql/connections.py", line 1021, in _read_bytes
    data = self._rfile.read(num_bytes)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/pymysql/_socketio.py", line 59, in readinto
    return self._sock.recv_into(b)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 360, in recv_into
    return self._recv_loop(self.fd.recv_into, 0, buffer, nbytes, flags)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 348, in _recv_loop
    self._read_trampoline()
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 319, in _read_trampoline
    timeout_exc=socket.timeout("timed out"))
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 203, in _trampoline
    mark_as_closed=self._mark_as_closed)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/eventlet/hubs/__init__.py", line 162, in trampoline
    return hub.switch()
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 294, in switch
    return self.greenlet.switch()
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 346, in run
    self.wait(sleep_time)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/eventlet/hubs/poll.py", line 85, in wait
    presult = self.do_poll(seconds)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/eventlet/hubs/epolls.py", line 62, in do_poll
    return self.poll.poll(seconds)
  File "/opt/stack/new/neutron/.tox/dsvm-functional/local/lib/python2.7/site-packages/fixtures/_fixtures/timeout.py", line 52, in signal_handler
    raise TimeoutException()
IndexError: tuple index out of range

It's interesting that ALL of them fail in the same job (something wrong with the db backend?) Counterparts for postgresql didn't fail.

The tests in question are quite long. (Tool psql test to pass in 55secs, while mysql failed after 200s+). We see that mysqld is the most intensive process during those 200secs (see dstat). Is it really just slow?

Several suggestions here:
- we should probably squash scripts, they span till Mitaka right now.
- there are no mysqld logs in functional job. Should we add those?
- there is no per-testcase log file for the tests, probably because the tests are special snowflakes that don't use common base test class that would set logdir.

In good runs, mysql flavours of the test work just fine, not taking much longer than postgresql.

Changed in neutron:
importance: Undecided → High
status: New → Confirmed
tags: added: functional-tests gate-failure
Slawek Kaplonski (slaweq) wrote :

No hits in last 30 days for such error: http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22IndexError%3A%20tuple%20index%20out%20of%20range%5C%22%20AND%20build_name%3Aneutron-functional

I will close it for now. If You think that it's still problem, please reopen this bug

Changed in neutron:
status: Confirmed → Incomplete
Jakub Libosvar (libosvar) wrote :
Changed in neutron:
status: Incomplete → Confirmed
Miguel Lavalle (minsel) on 2018-06-26
Changed in neutron:
assignee: nobody → Miguel Lavalle (minsel)
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers