Comment 7 for bug 1649616

Revision history for this message
Alex Krzos (akrzos) wrote :

I reran to confirm on a similar setup but with a slightly better disk layout (RAID 1 Mirror rather than single SATA disk) and the results are the same. I reviewed the Keystone log files and did find the same stack trace as the other bug. So this is logged correctly with the deployment that I am using.

Aside from the tokens never clearing and the job running for almost 24 hours, when this job runs and doesn't complete the cloud still pays the same penalty in disk utilization attempting to remove the expired tokens(Every day forth).

Here is the log output related to the unsuccessful token flush and I will attach another disk io % util on the controller that the database processes are handling the request from the token flush process.

2017-01-06 03:43:05.810 1013422 INFO keystone.token.persistence.backends.sql [-] Total expired tokens removed: 1003291 [25/213]
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters [-] DBAPIError exception wrapped from (pymysql.err.InternalError) (1180, u'Got error 5 during COMMIT')
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 688, in _commit_impl
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters self.engine.dialect.do_commit(self.connection)
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib64/python2.7/site-packages/sqlalchemy/dialects/mysql/base.py", line 2514, in do_commit
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters dbapi_connection.commit()
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 719, in commit
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters self._read_ok_packet()
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 698, in _read_ok_packet
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters pkt = self._read_packet()
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 906, in _read_packet
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters packet.check_error()
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 367, in check_error
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters err.raise_mysql_exception(self._data)
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 120, in raise_mysql_exception
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters _check_mysql_exception(errinfo)
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 115, in _check_mysql_exception
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters raise InternalError(errno, errorvalue)
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1180, u'Got error 5 during COMMIT')
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.sqlalchemy.exc_filters
2017-01-06 04:06:23.581 1013422 CRITICAL keystone [-] DBError: (pymysql.err.InternalError) (1180, u'Got error 5 during COMMIT')
2017-01-06 04:06:23.581 1013422 ERROR keystone Traceback (most recent call last):
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/bin/keystone-manage", line 10, in <module>
2017-01-06 04:06:23.581 1013422 ERROR keystone sys.exit(main())
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/keystone/cmd/manage.py", line 43, in main
2017-01-06 04:06:23.581 1013422 ERROR keystone cli.main(argv=sys.argv, config_files=config_files)
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/keystone/cmd/cli.py", line 1256, in main
2017-01-06 04:06:23.581 1013422 ERROR keystone CONF.command.cmd_class.main()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/keystone/cmd/cli.py", line 767, in main
2017-01-06 04:06:23.581 1013422 ERROR keystone token_manager.flush_expired_tokens()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/keystone/token/persistence/backends/sql.py", line 286, in flush_expired_tokens
2017-01-06 04:06:23.581 1013422 ERROR keystone LOG.info(_LI('Total expired tokens removed: %d'), total_removed)
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/contextlib.py", line 24, in __exit__
2017-01-06 04:06:23.581 1013422 ERROR keystone self.gen.next()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 875, in _transaction_scope
2017-01-06 04:06:23.581 1013422 ERROR keystone yield resource
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/contextlib.py", line 24, in __exit__
2017-01-06 04:06:23.581 1013422 ERROR keystone self.gen.next()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 522, in _session
2017-01-06 04:06:23.581 1013422 ERROR keystone self._end_session_transaction(self.session)
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 543, in _end_session_transaction
2017-01-06 04:06:23.581 1013422 ERROR keystone session.commit()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 813, in commit
2017-01-06 04:06:23.581 1013422 ERROR keystone self.transaction.commit()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 396, in commit
2017-01-06 04:06:23.581 1013422 ERROR keystone t[1].commit()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1574, in commit
2017-01-06 04:06:23.581 1013422 ERROR keystone self._do_commit()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1605, in _do_commit
2017-01-06 04:06:23.581 1013422 ERROR keystone self.connection._commit_impl()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 690, in _commit_impl
2017-01-06 04:06:23.581 1013422 ERROR keystone self._handle_dbapi_exception(e, None, None, None, None)
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
2017-01-06 04:06:23.581 1013422 ERROR keystone util.raise_from_cause(newraise, exc_info)
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 200, in raise_from_cause
2017-01-06 04:06:23.581 1013422 ERROR keystone reraise(type(exception), exception, tb=exc_tb)
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 688, in _commit_impl
2017-01-06 04:06:23.581 1013422 ERROR keystone self.engine.dialect.do_commit(self.connection)
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/python2.7/site-packages/sqlalchemy/dialects/mysql/base.py", line 2514, in do_commit
2017-01-06 04:06:23.581 1013422 ERROR keystone dbapi_connection.commit()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 719, in commit
2017-01-06 04:06:23.581 1013422 ERROR keystone self._read_ok_packet()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 698, in _read_ok_packet
2017-01-06 04:06:23.581 1013422 ERROR keystone pkt = self._read_packet()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 906, in _read_packet
2017-01-06 04:06:23.581 1013422 ERROR keystone packet.check_error()
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 367, in check_error
2017-01-06 04:06:23.581 1013422 ERROR keystone err.raise_mysql_exception(self._data)
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 120, in raise_mysql_exception
2017-01-06 04:06:23.581 1013422 ERROR keystone _check_mysql_exception(errinfo)
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 115, in _check_mysql_exception
2017-01-06 04:06:23.581 1013422 ERROR keystone raise InternalError(errno, errorvalue)
2017-01-06 04:06:23.581 1013422 ERROR keystone DBError: (pymysql.err.InternalError) (1180, u'Got error 5 during COMMIT')
2017-01-06 04:06:23.581 1013422 ERROR keystone