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
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.persisten ce.backends. sql [-] Total expired tokens removed: 1003291 [25/213] sqlalchemy. exc_filters [-] DBAPIError exception wrapped from (pymysql. err.InternalErr or) (1180, u'Got error 5 during COMMIT') sqlalchemy. exc_filters Traceback (most recent call last): sqlalchemy. exc_filters File "/usr/lib64/ python2. 7/site- packages/ sqlalchemy/ engine/ base.py" , line 688, in _commit_impl sqlalchemy. exc_filters self.engine. dialect. do_commit( self.connection ) sqlalchemy. exc_filters File "/usr/lib64/ python2. 7/site- packages/ sqlalchemy/ dialects/ mysql/base. py", line 2514, in do_commit sqlalchemy. exc_filters dbapi_connectio n.commit( ) sqlalchemy. exc_filters File "/usr/lib/ python2. 7/site- packages/ pymysql/ connections. py", line 719, in commit sqlalchemy. exc_filters self._read_ ok_packet( ) sqlalchemy. exc_filters File "/usr/lib/ python2. 7/site- packages/ pymysql/ connections. py", line 698, in _read_ok_packet sqlalchemy. exc_filters pkt = self._read_packet() sqlalchemy. exc_filters File "/usr/lib/ python2. 7/site- packages/ pymysql/ connections. py", line 906, in _read_packet sqlalchemy. exc_filters packet. check_error( ) sqlalchemy. exc_filters File "/usr/lib/ python2. 7/site- packages/ pymysql/ connections. py", line 367, in check_error sqlalchemy. exc_filters err.raise_ mysql_exception (self._ data) sqlalchemy. exc_filters File "/usr/lib/ python2. 7/site- packages/ pymysql/ err.py" , line 120, in raise_mysql_ exception sqlalchemy. exc_filters _check_ mysql_exception (errinfo) sqlalchemy. exc_filters File "/usr/lib/ python2. 7/site- packages/ pymysql/ err.py" , line 115, in _check_ mysql_exception sqlalchemy. exc_filters raise InternalError( errno, errorvalue) sqlalchemy. exc_filters InternalError: (1180, u'Got error 5 during COMMIT') sqlalchemy. exc_filters err.InternalErr or) (1180, u'Got error 5 during COMMIT') manage" , line 10, in <module> python2. 7/site- packages/ keystone/ cmd/manage. py", line 43, in main argv=sys. argv, config_ files=config_ files) python2. 7/site- packages/ keystone/ cmd/cli. py", line 1256, in main cmd_class. main() python2. 7/site- packages/ keystone/ cmd/cli. py", line 767, in main flush_expired_ tokens( ) python2. 7/site- packages/ keystone/ token/persisten ce/backends/ sql.py" , line 286, in flush_expired_ tokens python2. 7/contextlib. py", line 24, in __exit__ python2. 7/site- packages/ oslo_db/ sqlalchemy/ enginefacade. py", line 875, in _transaction_scope python2. 7/contextlib. py", line 24, in __exit__ python2. 7/site- packages/ oslo_db/ sqlalchemy/ enginefacade. py", line 522, in _session session_ transaction( self.session) python2. 7/site- packages/ oslo_db/ sqlalchemy/ enginefacade. py", line 543, in _end_session_ transaction python2. 7/site- packages/ sqlalchemy/ orm/session. py", line 813, in commit n.commit( ) python2. 7/site- packages/ sqlalchemy/ orm/session. py", line 396, in commit python2. 7/site- packages/ sqlalchemy/ engine/ base.py" , line 1574, in commit python2. 7/site- packages/ sqlalchemy/ engine/ base.py" , line 1605, in _do_commit ._commit_ impl() python2. 7/site- packages/ sqlalchemy/ engine/ base.py" , line 690, in _commit_impl dbapi_exception (e, None, None, None, None) python2. 7/site- packages/ sqlalchemy/ engine/ base.py" , line 1337, in _handle_ dbapi_exception from_cause( newraise, exc_info) python2. 7/site- packages/ sqlalchemy/ util/compat. py", line 200, in raise_from_cause type(exception) , exception, tb=exc_tb) python2. 7/site- packages/ sqlalchemy/ engine/ base.py" , line 688, in _commit_impl dialect. do_commit( self.connection ) python2. 7/site- packages/ sqlalchemy/ dialects/ mysql/base. py", line 2514, in do_commit n.commit( ) python2. 7/site- packages/ pymysql/ connections. py", line 719, in commit ok_packet( ) python2. 7/site- packages/ pymysql/ connections. py", line 698, in _read_ok_packet python2. 7/site- packages/ pymysql/ connections. py", line 906, in _read_packet check_error( ) python2. 7/site- packages/ pymysql/ connections. py", line 367, in check_error mysql_exception (self._ data) python2. 7/site- packages/ pymysql/ err.py" , line 120, in raise_mysql_ exception mysql_exception (errinfo) python2. 7/site- packages/ pymysql/ err.py" , line 115, in _check_ mysql_exception errno, errorvalue) err.InternalErr or) (1180, u'Got error 5 during COMMIT')
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.540 1013422 ERROR oslo_db.
2017-01-06 04:06:23.581 1013422 CRITICAL keystone [-] DBError: (pymysql.
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-
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/
2017-01-06 04:06:23.581 1013422 ERROR keystone cli.main(
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/
2017-01-06 04:06:23.581 1013422 ERROR keystone CONF.command.
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/
2017-01-06 04:06:23.581 1013422 ERROR keystone token_manager.
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/
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/
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/
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/
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/
2017-01-06 04:06:23.581 1013422 ERROR keystone self._end_
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/
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/
2017-01-06 04:06:23.581 1013422 ERROR keystone self.transactio
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/
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/
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/
2017-01-06 04:06:23.581 1013422 ERROR keystone self.connection
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/
2017-01-06 04:06:23.581 1013422 ERROR keystone self._handle_
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/
2017-01-06 04:06:23.581 1013422 ERROR keystone util.raise_
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/
2017-01-06 04:06:23.581 1013422 ERROR keystone reraise(
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/
2017-01-06 04:06:23.581 1013422 ERROR keystone self.engine.
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib64/
2017-01-06 04:06:23.581 1013422 ERROR keystone dbapi_connectio
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/
2017-01-06 04:06:23.581 1013422 ERROR keystone self._read_
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/
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/
2017-01-06 04:06:23.581 1013422 ERROR keystone packet.
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/
2017-01-06 04:06:23.581 1013422 ERROR keystone err.raise_
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/
2017-01-06 04:06:23.581 1013422 ERROR keystone _check_
2017-01-06 04:06:23.581 1013422 ERROR keystone File "/usr/lib/
2017-01-06 04:06:23.581 1013422 ERROR keystone raise InternalError(
2017-01-06 04:06:23.581 1013422 ERROR keystone DBError: (pymysql.
2017-01-06 04:06:23.581 1013422 ERROR keystone