In some circumstances record.exc_info may not be a string. In that case journald handler is fail to log.
[req-3197c7a2-d62b-495d-80bb-d181c2987980 - - - - -] cannot concatenate 'str' and 'tuple' objects: TypeError: cannot concatenate 'str' and 'tuple' objects
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/keystone/common/wsgi.py", line 148, in __call__
result = method(req, **params)
File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 67, in authenticate_for_token
self.authenticate(request, auth_info, auth_context)
File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 236, in authenticate
auth_info.get_method_data(method_name))
File "/usr/lib/python2.7/site-packages/keystone/auth/plugins/password.py", line 37, in authenticate
password=user_info.password)
File "/usr/lib/python2.7/site-packages/keystone/common/manager.py", line 116, in wrapped
__ret_val = __f(*args, **kwargs)
File "/usr/lib/python2.7/site-packages/keystone/notifications.py", line 521, in wrapper
result = f(wrapped_self, request, user_id, *args, **kwargs)
File "/usr/lib/python2.7/site-packages/keystone/identity/core.py", line 416, in wrapper
return f(self, *args, **kwargs)
File "/usr/lib/python2.7/site-packages/keystone/identity/core.py", line 426, in wrapper
return f(self, *args, **kwargs)
File "/usr/lib/python2.7/site-packages/keystone/identity/core.py", line 910, in authenticate
ref = driver.authenticate(entity_id, password)
File "/usr/lib/python2.7/site-packages/hybrid_identity.py", line 54, in authenticate
user_ref = self._get_user(session, user_id)
File "/usr/lib/python2.7/site-packages/hybrid_identity.py", line 113, in _get_user
user_ref = super(Identity, self)._get_user(session, user_id)
File "/usr/lib/python2.7/site-packages/keystone/identity/backends/sql.py", line 181, in _get_user
user_ref = session.query(model.User).get(user_id)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 882, in get
ident, loading.load_on_pk_identity)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 952, in _get_impl
return db_load_fn(self, primary_key_identity)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/loading.py", line 247, in load_on_pk_identity
return q.one()
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2884, in one
ret = self.one_or_none()
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2854, in one_or_none
ret = list(self)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2925, in __iter__
return self._execute_and_instances(context)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2946, in _execute_and_instances
close_with_result=True)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2955, in _get_bind_args
**kw
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2937, in _connection_from_session
conn = self.session.connection(**kw)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 1035, in connection
execution_options=execution_options)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 1040, in _connection_for_bind
engine, execution_options)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 409, in _connection_for_bind
conn = bind.contextual_connect()
File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 2125, in contextual_connect
**kwargs)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 110, in __init__
self.dispatch.engine_connect(self, self.__branch)
File "/usr/lib64/python2.7/site-packages/sqlalchemy/event/attr.py", line 284, in __call__
fn(*args, **kw)
File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py", line 82, in _connect_ping_listener
'Database connection was found disconnected; reconnecting')
File "/usr/lib64/python2.7/logging/__init__.py", line 1182, in exception
self.error(msg, *args, **kwargs)
File "/usr/lib64/python2.7/logging/__init__.py", line 1175, in error
self._log(ERROR, msg, args, **kwargs)
File "/usr/lib64/python2.7/logging/__init__.py", line 1268, in _log
self.handle(record)
File "/usr/lib64/python2.7/logging/__init__.py", line 1278, in handle
self.callHandlers(record)
File "/usr/lib64/python2.7/logging/__init__.py", line 1318, in callHandlers
hdlr.handle(record)
File "/usr/lib64/python2.7/logging/__init__.py", line 749, in handle
self.emit(record)
File "/usr/lib/python2.7/site-packages/oslo_log/handlers.py", line 145, in emit
journal.send(message, **extras)
File "/usr/lib64/python2.7/site-packages/systemd/journal.py", line 407, in send
args.extend(_make_line(key, val) for key, val in kwargs.items())
File "/usr/lib64/python2.7/site-packages/systemd/journal.py", line 407, in <genexpr>
args.extend(_make_line(key, val) for key, val in kwargs.items())
File "/usr/lib64/python2.7/site-packages/systemd/journal.py", line 358, in _make_line
return field + '=' + value
TypeError: cannot concatenate 'str' and 'tuple' objects
extras dict contain:
{'CODE_FILE': '/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py',
'CODE_FUNC': '_connect_ping_listener',
'CODE_LINE': 82,
'EXCEPTION_INFO': (<class 'oslo_db.exception.DBConnectionError'>,
DBConnectionError(u'(pymysql.err.OperationalError) (2006, "MySQL server has gone away (error(32, \\'Broken pipe\\'))") [SQL: u\\'SELECT 1\\'] (Background on this error at: http://sqlalche.me/e/e3q8)',),
<traceback object at 0x7fc1c5e25b48>),
'EXCEPTION_TEXT': '2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines Traceback (most recent call last):\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py", line 73, in _connect_ping_listener\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines connection.scalar(select([1]))\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 880, in scalar\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines return self.execute(object, *multiparams, **params).scalar()\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 948, in execute\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines return meth(self, multiparams, params)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines return connection._execute_clauseelement(self, multiparams, params)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines compiled_sql, distilled_params\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines context)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exception\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines util.raise_from_cause(newraise, exc_info)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines reraise(type(exception), exception, tb=exc_tb, cause=cause)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines context)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines cursor.execute(statement, parameters)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines result = self._query(query)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines conn.query(q)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 855, in query\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines self._execute_command(COMMAND.COM_QUERY, sql)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1092, in _execute_command\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines self._write_bytes(packet)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1044, in _write_bytes\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines "MySQL server has gone away (%r)" % (e,))\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines DBConnectionError: (pymysql.err.OperationalError) (2006, "MySQL server has gone away (error(32, \\'Broken pipe\\'))") [SQL: u\\'SELECT 1\\'] (Background on this error at: http://sqlalche.me/e/e3q8)\\n2018-11-07 19:18:12.390 ERROR oslo_db.sqlalchemy.engines ',
'LOGGER_LEVEL': 'ERROR',
'LOGGER_NAME': 'oslo_db.sqlalchemy.engines',
'PRIORITY': 3,
'PROCESS_NAME': 'MainProcess',
'REQUEST_ID': 'req-3edd46d4-e9ea-4ef0-9ace-83229160afd3',
'SYSLOG_IDENTIFIER': 'keystone-wsgi-public',
'THREAD_NAME': 'MainThread'}
Fix proposed to branch: master
Review: https:/