OpenStack Compute (nova)

Got some db errors when call list servers

Bug #1836029 reported by zhangyujun on 2019-07-10

This bug affects 5 people

Affects		Status	Importance	Assigned to	Milestone
	OpenStack Compute (nova)	Confirmed	Undecided	Unassigned

Bug Description

Got some db errors when call list servers and nova-api return http code 500

2019-07-02 10:08:39 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:39.736 16 INFO nova.osapi_compute.wsgi.server [req-5804b3dd-9968-481d-b03f-ed36192abb2f 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 200 len: 42583 time: 0.2910399
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters [req-edd4d5e5-05ee-4a94-974b-c127fc4ce86f 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] DB exception wrapped.
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters context)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters cursor.execute(statement, parameters)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 167, in execute
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters result = self._query(query)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 323, in _query
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters conn.query(q)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 836, in query
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1020, in _read_query_result
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters result.read()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1303, in read
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters first_packet = self.connection._read_packet()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 962, in _read_packet
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters packet_header = self._read_bytes(4)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 989, in _read_bytes
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters data = self._rfile.read(num_bytes)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters RuntimeError: reentrant call inside <_io.BufferedReader name=23>
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions [req-edd4d5e5-05ee-4a94-974b-c127fc4ce86f 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] Unexpected exception in API method
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/api/openstack/extensions.py", line 338, in wrapped
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 208, in detail
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 359, in _get_servers
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 1325, in fill_faults
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 184, in wrapper
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions result = fn(cls, context, *args, **kwargs)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/objects/instance_fault.py", line 108, in get_by_instance_uuids
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 1906, in instance_fault_get_by_instance_uuids
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 255, in wrapped
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 5999, in instance_fault_get_by_instance_uuids
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2613, in all
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions return list(self)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2761, in __iter__
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions return self._execute_and_instances(context)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2774, in _execute_and_instances
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions close_with_result=True)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2765, in _connection_from_session
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions **kw)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 893, in connection
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions execution_options=execution_options)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 898, in _connection_for_bind
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions engine, execution_options)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 334, in _connection_for_bind
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions conn = bind.contextual_connect()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 2041, in contextual_connect
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions **kwargs)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 92, in __init__
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions self.dispatch.engine_connect(self, self.__branch)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/event/attr.py", line 256, in __call__
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions fn(*args, **kw)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py", line 72, in _connect_ping_listener
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions connection.scalar(select([1]))
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 844, in scalar
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions return self.execute(object, *multiparams, **params).scalar()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 914, in execute
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions return meth(self, multiparams, params)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions return connection._execute_clauseelement(self, multiparams, params)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions compiled_sql, distilled_params
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions context)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1334, in _handle_dbapi_exception
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions self._autorollback()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 791, in _autorollback
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions self._root._rollback_impl()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 670, in _rollback_impl
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions self._handle_dbapi_exception(e, None, None, None, None)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1266, in _handle_dbapi_exception
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions exc_info
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 202, in raise_from_cause
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions reraise(type(exception), exception, tb=exc_tb, cause=cause)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 668, in _rollback_impl
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions self.engine.dialect.do_rollback(self.connection)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib64/python2.7/site-packages/sqlalchemy/dialects/mysql/base.py", line 2542, in do_rollback
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions dbapi_connection.rollback()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 773, in rollback
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions self._read_ok_packet()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 747, in _read_ok_packet
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions pkt = self._read_packet()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 962, in _read_packet
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions packet_header = self._read_bytes(4)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 989, in _read_bytes
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions data = self._rfile.read(num_bytes)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions DBAPIError: (exceptions.RuntimeError) reentrant call inside <_io.BufferedReader name=23>
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.785 16 ERROR nova.api.openstack.extensions
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool [req-edd4d5e5-05ee-4a94-974b-c127fc4ce86f 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] Exception during reset or similar
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool Traceback (most recent call last):
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 636, in _finalize_fairy
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool fairy._reset(pool)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 776, in _reset
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool pool._dialect.do_rollback(self)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool File "/usr/lib64/python2.7/site-packages/sqlalchemy/dialects/mysql/base.py", line 2542, in do_rollback
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool dbapi_connection.rollback()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 773, in rollback
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool self._read_ok_packet()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 747, in _read_ok_packet
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool pkt = self._read_packet()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 962, in _read_packet
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool packet_header = self._read_bytes(4)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 989, in _read_bytes
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool data = self._rfile.read(num_bytes)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool RuntimeError: reentrant call inside <_io.BufferedReader name=23>
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR sqlalchemy.pool.QueuePool
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters [req-179abec8-6e3e-4ee2-a732-43709f25aa91 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] DB exception wrapped.
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters context)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters cursor.execute(statement, parameters)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 167, in execute
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters result = self._query(query)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 323, in _query
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters conn.query(q)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 836, in query
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1020, in _read_query_result
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters result.read()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1303, in read
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters first_packet = self.connection._read_packet()
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 972, in _read_packet
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters recv_data = self._read_bytes(bytes_to_read)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 986, in _read_bytes
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters self._sock.settimeout(self._read_timeout)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters AttributeError: 'NoneType' object has no attribute 'settimeout'
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.787 16 ERROR oslo_db.sqlalchemy.exc_filters
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.788 16 INFO nova.api.openstack.wsgi [req-edd4d5e5-05ee-4a94-974b-c127fc4ce86f 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | <class 'sqlalchemy.exc.DBAPIError'>
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.789 16 INFO nova.osapi_compute.wsgi.server [req-edd4d5e5-05ee-4a94-974b-c127fc4ce86f 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-4.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.1924100

Tags:

Takashi Natsume (natsume-takashi) on 2019-07-10

tags:

added: db

Revision history for this message

Matt Riedemann (mriedem) wrote on 2019-07-12:

I see:

2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters data = self._rfile.read(num_bytes)
2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.784 16 ERROR oslo_db.sqlalchemy.exc_filters RuntimeError: reentrant call inside <_io.BufferedReader name=23>

And:

10:08:42.785 16 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 5999, in instance_fault_get_by_instance_uuids

But I'm not sure what would cause that. Are you able to provide steps to reproduce? Maybe paste into the bug the faults table entries for the instance in question when this fails.

Revision history for this message

zhangyujun (zhangyujun) wrote on 2019-07-15:

Download full text (14.7 KiB)

thanks matt, these errors happened occasionally, I could not reproduce that with a stable way. I'm running with OpenStack Newton, and some db driver dependent python packages as follows:

MySQL-python (1.2.5)
PyMySQL (0.7.6)
SQLAlchemy (1.0.14)
sqlalchemy-migrate (0.10.0)
sqlparse (0.2.1)

the nova database configs

[database]
connection = mysql+pymysql://xxxx:3306/nova
max_overflow = 20
max_pool_size = 20
max_retries = -1

I got some clues from pymysql project https://github.com/PyMySQL/PyMySQL/issues/275, and it notice to openstack dev http://lists.openstack.org/pipermail/openstack-dev/2014-December/052344.html, but I'm not pretty sure that this is the root cause.

hope would get some help from nova community. I got about 30 error records from nova log, but no errors occurred in other openstack components like neutron/cinder

thanks matt, these errors happened occasionally, I could not reproduce that with a stable way. I'm running with OpenStack Newton, and some db driver dependent python packages as follows:

MySQL-python (1.2.5)
PyMySQL (0.7.6)
SQLAlchemy (1.0.14)
sqlalchemy-migrate (0.10.0)
sqlparse (0.2.1)

the nova database configs

[database]
connection = mysql+pymysql://xxxx:3306/nova
max_overflow = 20
max_pool_size = 20
max_retries = -1

hope would get some help from nova community. I got about 30 error records from nova log, but no errors occurred in other openstack components like neutron/cinder

api-osapi.node-2.20190702.log:2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.789 16 INFO nova.osapi_compute.wsgi.server [req-edd4d5e5-05ee-4a94-974b-c127fc4ce86f 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-4.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.1924100
api-osapi.node-2.20190702.log:2019-07-02 10:08:42 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:08:42.792 16 INFO nova.osapi_compute.wsgi.server [req-179abec8-6e3e-4ee2-a732-43709f25aa91 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-2.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 578 time: 0.1922901
api-osapi.node-2.20190702.log:2019-07-02 10:58:18 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:58:18.438 16 INFO nova.osapi_compute.wsgi.server [req-b66fd2e0-428c-4d72-b1b3-82da136dbcad 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/flavors/detail HTTP/1.1" status: 500 len: 566 time: 0.0666962
api-osapi.node-2.20190702.log:2019-07-02 10:58:18 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:58:18.441 16 INFO nova.osapi_compute.wsgi.server [req-404eebfb-2e1e-48fe-ae5c-b44df4ff4395 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/flavors/detail?is_public=False HTTP/1.1" status: 500 len: 576 time: 0.0668118
api-osapi.node-2.20190702.log:2019-07-02 10:59:19 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:59:19.435 16 INFO nova.osapi_compute.wsgi.server [req-00fc27b8-d199-4510-adaf-a3c313b9dccc 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-3.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.1546311
api-osapi.node-2.20190702.log:2019-07-02 10:59:19 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:59:19.438 16 INFO nova.osapi_compute.wsgi.server [req-680717a3-a9e0-449b-bbb9-74ba2493af22 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-2.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 578 time: 0.1542120
api-osapi.node-2.20190702.log:2019-07-02 10:59:35 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:59:35.866 16 INFO nova.osapi_compute.wsgi.server [req-eb08c21b-64e5-4af5-87b5-689e9e511bb8 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-2.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.0986638
api-osapi.node-2.20190702.log:2019-07-02 10:59:35 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:59:35.868 16 INFO nova.osapi_compute.wsgi.server [req-4683ee73-0ed3-48ad-91ed-9498bd5c7e96 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?all_tenants=True&redirect=detail_x HTTP/1.1" status: 500 len: 578 time: 0.1148541
api-osapi.node-2.20190702.log:2019-07-02 10:59:59 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:59:59.553 16 INFO nova.osapi_compute.wsgi.server [req-7abe6e71-9c14-4b90-a098-26fcb2c89420 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.65.164 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-4.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.2493899
api-osapi.node-2.20190702.log:2019-07-02 10:59:59 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 10:59:59.556 16 INFO nova.osapi_compute.wsgi.server [req-6ec1d6f5-3142-404f-89cc-fc4fb8e3218a 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.65.164 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-2.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 578 time: 0.2341990
api-osapi.node-2.20190702.log:2019-07-02 11:00:39 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:00:39.972 16 INFO nova.osapi_compute.wsgi.server [req-afb737a0-0f50-475f-b208-db1bcdb599fd 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?all_tenants=True&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.2033510
api-osapi.node-2.20190702.log:2019-07-02 11:05:09 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:05:09.980 16 INFO nova.osapi_compute.wsgi.server [req-d9b0ca2b-51df-4987-b59f-f39b68539cc2 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-4.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.2005029
api-osapi.node-2.20190702.log:2019-07-02 11:05:09 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:05:09.983 16 INFO nova.osapi_compute.wsgi.server [req-bc642bdb-a847-487b-9273-0697cfdf14d9 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-2.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 578 time: 0.2071099
api-osapi.node-2.20190702.log:2019-07-02 11:05:35 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:05:35.367 16 INFO nova.osapi_compute.wsgi.server [req-827d05e3-b3a1-49be-aca3-db8614243ad0 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-3.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.1658230
api-osapi.node-2.20190702.log:2019-07-02 11:06:26 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:06:26.115 16 INFO nova.osapi_compute.wsgi.server [req-52cc0de7-7cd2-4ed9-b10e-64440c006afa 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-2.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.2764349
api-osapi.node-2.20190702.log:2019-07-02 11:06:26 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:06:26.118 16 INFO nova.osapi_compute.wsgi.server [req-3d2aebf2-bab7-4d17-ae28-b7b0ddb26f9e 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.66.23 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x&status=ERROR HTTP/1.1" status: 500 len: 578 time: 0.2550640
api-osapi.node-2.20190702.log:2019-07-02 11:20:30 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:20:30.526 16 INFO nova.osapi_compute.wsgi.server [req-2cb77092-f92c-448f-9a5a-f283abff6c2c 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/flavors/detail HTTP/1.1" status: 500 len: 566 time: 0.0660131
api-osapi.node-2.20190702.log:2019-07-02 11:31:50 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:31:50.726 16 INFO nova.osapi_compute.wsgi.server [req-4416a16b-54c0-4ad2-a36e-e522b22f83f2 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-4.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.1068242
api-osapi.node-2.20190702.log:2019-07-02 11:31:50 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:31:50.729 16 INFO nova.osapi_compute.wsgi.server [req-95480b17-f258-46ca-a4b3-dc0500e0f40c 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x&status=ERROR HTTP/1.1" status: 500 len: 578 time: 0.1145289
api-osapi.node-2.20190702.log:2019-07-02 11:32:49 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:32:49.900 16 INFO nova.osapi_compute.wsgi.server [req-b72a1068-2b9d-4946-80ab-59c15fb5527a 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/d57a387c-bf4f-4e73-9b2b-080d2794684e HTTP/1.1" status: 500 len: 568 time: 0.3209841
api-osapi.node-2.20190702.log:2019-07-02 11:32:49 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:32:49.903 16 INFO nova.osapi_compute.wsgi.server [req-cc5270fd-cc1f-49a1-9cac-78bff8c44640 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/a96d84ef-72b4-4267-8337-40f61c355696 HTTP/1.1" status: 500 len: 578 time: 0.3278821
api-osapi.node-2.20190702.log:2019-07-02 11:44:09 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:44:09.463 16 INFO nova.osapi_compute.wsgi.server [req-9a970a8c-eab3-4810-ab73-6fe5bd306715 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/flavors/detail HTTP/1.1" status: 500 len: 566 time: 0.0566730
api-osapi.node-2.20190702.log:2019-07-02 11:44:09 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 11:44:09.466 16 INFO nova.osapi_compute.wsgi.server [req-3a2610a6-7580-42ef-851e-b626e31953b1 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/flavors/detail?is_public=False HTTP/1.1" status: 500 len: 576 time: 0.0621471
api-osapi.node-2.20190702.log:2019-07-02 12:06:05 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 12:06:05.850 16 INFO nova.osapi_compute.wsgi.server [req-3c849000-612d-4c77-a175-85ac5e3a0be7 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-3.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.0923002
api-osapi.node-2.20190702.log:2019-07-02 12:06:05 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 12:06:05.853 16 INFO nova.osapi_compute.wsgi.server [req-b1190eaf-1e67-421f-8f0c-3f12eb041a19 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x&status=BUILD HTTP/1.1" status: 500 len: 578 time: 0.0974100
api-osapi.node-2.20190702.log:2019-07-02 13:30:48 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 13:30:48.342 16 INFO nova.osapi_compute.wsgi.server [req-464bcc52-07ab-425d-a22d-b9614d754ee2 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x&status=BUILD HTTP/1.1" status: 500 len: 568 time: 0.0822620
api-osapi.node-2.20190702.log:2019-07-02 13:30:48 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 13:30:48.345 16 INFO nova.osapi_compute.wsgi.server [req-6d6556bc-2576-44f8-af12-5d6d6787defd 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.67.122 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-2.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 572 time: 0.0868950
api-osapi.node-2.20190702.log:2019-07-02 13:53:51 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 13:53:51.859 16 INFO nova.osapi_compute.wsgi.server [req-1f378baf-85bc-43cc-97fb-80e5c0427dc4 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.65.164 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/os-hypervisors/detail HTTP/1.1" status: 500 len: 566 time: 0.0327928
api-osapi.node-2.20190702.log:2019-07-02 13:53:51 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 13:53:51.861 16 INFO nova.osapi_compute.wsgi.server [req-681fb122-cd67-4557-99dc-998dd5f7056a 35d4f894f4de422a9056722abe668d79 b028c099cf6b4cd1b76e6fe33c8233b2 - default default] 10.233.67.109 "GET /v2.1/b028c099cf6b4cd1b76e6fe33c8233b2/os-hypervisors/detail HTTP/1.1" status: 500 len: 570 time: 0.0230091
api-osapi.node-2.20190702.log:2019-07-02 13:55:43 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 13:55:43.937 16 INFO nova.osapi_compute.wsgi.server [req-8127b93b-3869-4163-822e-ed6726fea0f1 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.65.164 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-3.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 568 time: 0.0963371
api-osapi.node-2.20190702.log:2019-07-02 13:55:43 +0800 | nova-api-osapi-5475cd965-9wbl2 | 2019-07-02 13:55:43.940 16 INFO nova.osapi_compute.wsgi.server [req-bfb0dcb2-6f03-4072-8851-d56eacb54881 1c827fbc129a4025bcb2a2d8cacc6b3d d8ac61ac9f1d4e5e9aa9c4313c668834 - default default] 10.233.65.164 "GET /v2.1/d8ac61ac9f1d4e5e9aa9c4313c668834/servers/detail?host=node-4.domain.tld&project_id=d8ac61ac9f1d4e5e9aa9c4313c668834&redirect=detail_x HTTP/1.1" status: 500 len: 572 time: 0.1042821

Revision history for this message

Matt Riedemann (mriedem) wrote on 2019-07-22:

The Newton release is end of life at this point, but I wonder if you need this fix:

https://review.opendev.org/#/c/409943/

That was added in Ocata but not backported to stable/newton because the RPC version change on the InstanceFaultList object.

Revision history for this message

Matt Riedemann (mriedem) wrote on 2019-07-22:

I'm going to mark this as Invalid given the old release (newton) and the fact it might already be fixed if you can upgrade.

Changed in nova:
status:	New → Invalid

Revision history for this message

zhangyujun (zhangyujun) wrote on 2019-07-23:

Thats a really helpful advice, I'm gonna try to reproduce those errors based on master branch, reopen this if it could be reproduced, thanks.

Revision history for this message

Tytus Kurek (tkurek) wrote on 2019-07-24:

Download full text (13.2 KiB)

I have just faced the same issue on OpenStack Ocata:

2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters [req-5670b1fa-afd0-4f30-a7c5-f3973fce2442 bcbadd6e37124fcabffeebd8cc186406 fb7bc775e86241f6b6807a06fd767c30 - default default] DB exception wrapped.
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters     context)
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/dist-packages/pymysql/cursors.py", line 166, in execute
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/dist-packages/pymysql/cursors.py", line 322, in _query
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 835, in query
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 1019, in _read_query_result
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 1302, in read
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 971, in _read_packet
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters     recv_data = self._read_bytes(bytes_to_read)
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 985, in _read_bytes
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters     self._sock.settimeout(self._read_timeout)
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters AttributeError: 'NoneType' object has no attribute 'settimeout'
2019-07-24 06:53:38.146 2329 ERROR oslo_db.sqlalchemy.exc_filters 
2019-07-24 06:53:38.147 2329 INFO nova.api.openstack.wsgi [req-4759ecc7-60fa-4ac0-8eff-3048981b854b 08e8ac57fb2447fe9c01e44d4baa423a 227a774fb9404585b854db2e6694ba63 - default default] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
2019-07-24 06:53:38.148 2329 INFO nova.osapi_compute.wsgi.server [req-4759ecc7-60fa-4ac0-8eff-3048981b854b 08e8ac57fb2447fe9c01e44d4baa423a 227a774fb9404585b854db2e6694ba63 - default default] 100.113.0.213,127.0.0.1 "GET /v2/227a774fb9404585b854db2e6694ba63/servers/detail?name=%5Ecaas-piaas-hcvart2-piaas-hcvart2-lb-01%24 HTTP/1.1" status: 500 len: 430 time: 0.2303760
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions [req-5670b1fa-afd0-4f30-a7c5-f3973fce2442 bcbadd6e37124fcabffeebd8cc186406 fb7bc775e86241f6b6807a06fd767c30 - default default] Unexpected exception in API method
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/extensions.py", line 338, in wrapped
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/flavors.py", line 46, in detail
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     limited_flavors = self._get_flavors(req)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/flavors.py", line 111, in _get_flavors
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     limit=limit, marker=marker)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 184, in wrapper
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     result = fn(cls, context, *args, **kwargs)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/objects/flavor.py", line 707, in get_all
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     marker=marker)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/db/api.py", line 1557, in flavor_get_all
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     sort_dir=sort_dir, limit=limit, marker=marker)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 180, in wrapper
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 266, in wrapped
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     return f(context, *args, **kwargs)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 5115, in flavor_get_all
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     inst_types = query.all()
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2588, in all
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     return list(self)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2736, in __iter__
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     return self._execute_and_instances(context)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2749, in _execute_and_instances
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     close_with_result=True)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2740, in _connection_from_session
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     **kw)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 905, in connection
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     execution_options=execution_options)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 910, in _connection_for_bind
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     engine, execution_options)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 334, in _connection_for_bind
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     conn = bind.contextual_connect()
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 2041, in contextual_connect
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     **kwargs)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 92, in __init__
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     self.dispatch.engine_connect(self, self.__branch)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/event/attr.py", line 256, in __call__
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     fn(*args, **kw)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py", line 72, in _connect_ping_listener
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     connection.scalar(select([1]))
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 844, in scalar
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     return self.execute(object, *multiparams, **params).scalar()
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 914, in execute
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     return meth(self, multiparams, params)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     return connection._execute_clauseelement(self, multiparams, params)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     compiled_sql, distilled_params
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     context)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1334, in _handle_dbapi_exception
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     self._autorollback()
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 791, in _autorollback
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     self._root._rollback_impl()
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 670, in _rollback_impl
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     self._handle_dbapi_exception(e, None, None, None, None)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1266, in _handle_dbapi_exception
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     exc_info
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 200, in raise_from_cause
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     reraise(type(exception), exception, tb=exc_tb)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 668, in _rollback_impl
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     self.engine.dialect.do_rollback(self.connection)
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/dialects/mysql/base.py", line 2526, in do_rollback
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     dbapi_connection.rollback()
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 771, in rollback
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     self._execute_command(COMMAND.COM_QUERY, "ROLLBACK")
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 1033, in _execute_command
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions     raise err.InterfaceError("(0, '')")
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions InterfaceError: (pymysql.err.InterfaceError) (0, '')
2019-07-24 06:53:38.149 2329 ERROR nova.api.openstack.extensions 
2019-07-24 06:53:38.150 2329 INFO nova.api.openstack.wsgi [req-5670b1fa-afd0-4f30-a7c5-f3973fce2442 bcbadd6e37124fcabffeebd8cc186406 fb7bc775e86241f6b6807a06fd767c30 - default default] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.

It occurred when running a Rally test. Attached is a full log from all nova cloud controller units.

Revision history for this message

Tytus Kurek (tkurek) wrote on 2019-07-24: