[CONNECTORS-571] MySQL operations time out when long transaction undertaken and need to be restarted

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: ManifoldCF 1.0, ManifoldCF 1.0.1
• Fix Version/s: ManifoldCF 1.1
• Component/s: Framework core
• Assignee: Karl Wright
• Reporter: Karl Wright
• Created: 28/Nov/12 08:18
• Updated: 28/Nov/12 08:40
• Resolved: 28/Nov/12 08:40

Description

If a transaction takes too long, MySQL handles this by aborting other threads that are trying to get locks on the resources being held. When it does this ManifoldCF does not handle the situation properly, and does not retry the aborted threads.

The SQLException that is thrown is:

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

The context that this happens in is varied:

2012/11/22 23:39:28 ERROR (Job start thread) - Job start thread aborting and restarting due to database connection reset: Database exception: Exception doing query: Lock wait timeout exceeded; try restarting transaction
org.apache.manifoldcf.core.interfaces.ManifoldCFException: Database exception: Exception doing query: Lock wait timeout exceeded; try restarting transaction
        at org.apache.manifoldcf.core.database.Database.executeViaThread(Database.java:681)
        at org.apache.manifoldcf.core.database.Database.executeUncachedQuery(Database.java:709)
        at org.apache.manifoldcf.core.database.Database$QueryCacheExecutor.create(Database.java:1394)
        at org.apache.manifoldcf.core.cachemanager.CacheManager.findObjectsAndExecute(CacheManager.java:144)
        at org.apache.manifoldcf.core.database.Database.executeQuery(Database.java:186)
        at org.apache.manifoldcf.core.database.DBInterfaceMySQL.performQuery(DBInterfaceMySQL.java:852)
        at org.apache.manifoldcf.crawler.jobs.JobManager.startJobs(JobManager.java:4711)
        at org.apache.manifoldcf.crawler.system.JobStartThread.run(JobStartThread.java:68)
Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3609)
        at com.mysql.jdbc.MysqlIO.nextRowFast(MysqlIO.java:1578)
        at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1434)
        at com.mysql.jdbc.MysqlIO.readSingleRowSet(MysqlIO.java:2925)
        at com.mysql.jdbc.MysqlIO.getResultSet(MysqlIO.java:477)
        at com.mysql.jdbc.MysqlIO.readResultsForQueryOrUpdate(MysqlIO.java:2631)
        at com.mysql.jdbc.MysqlIO.readAllResults(MysqlIO.java:1800)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2221)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2624)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2127)
        at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2293)
        at org.apache.manifoldcf.core.database.Database.execute(Database.java:826)
        at org.apache.manifoldcf.core.database.Database$ExecuteQueryThread.run(Database.java:641)
2012/11/22 23:39:28 ERROR (Finisher thread) - Finisher thread aborting and restarting due to database connection reset: Database exception: Exception doing query: Lock wait timeout exceeded; try restarting transaction
org.apache.manifoldcf.core.interfaces.ManifoldCFException: Database exception: Exception doing query: Lock wait timeout exceeded; try restarting transaction
        at org.apache.manifoldcf.core.database.Database.executeViaThread(Database.java:681)
        at org.apache.manifoldcf.core.database.Database.executeUncachedQuery(Database.java:709)
        at org.apache.manifoldcf.core.database.Database$QueryCacheExecutor.create(Database.java:1394)
        at org.apache.manifoldcf.core.cachemanager.CacheManager.findObjectsAndExecute(CacheManager.java:144)
        at org.apache.manifoldcf.core.database.Database.executeQuery(Database.java:186)
        at org.apache.manifoldcf.core.database.DBInterfaceMySQL.performQuery(DBInterfaceMySQL.java:852)
        at org.apache.manifoldcf.crawler.jobs.JobManager.finishJobs(JobManager.java:6469)
        at org.apache.manifoldcf.crawler.system.FinisherThread.run(FinisherThread.java:64)
Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3609)
        at com.mysql.jdbc.MysqlIO.nextRowFast(MysqlIO.java:1578)
        at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1434)
        at com.mysql.jdbc.MysqlIO.readSingleRowSet(MysqlIO.java:2925)
        at com.mysql.jdbc.MysqlIO.getResultSet(MysqlIO.java:477)
        at com.mysql.jdbc.MysqlIO.readResultsForQueryOrUpdate(MysqlIO.java:2631)
        at com.mysql.jdbc.MysqlIO.readAllResults(MysqlIO.java:1800)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2221)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2624)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2127)
        at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2293)
        at org.apache.manifoldcf.core.database.Database.execute(Database.java:826)
        at org.apache.manifoldcf.core.database.Database$ExecuteQueryThread.run(Database.java:641)
2012/11/22 23:39:30 ERROR (Worker thread '253') - Worker thread aborting and restarting due to database connection reset: Database exception: Exception doing query: Lock wait timeout exceeded; try restarting transaction
org.apache.manifoldcf.core.interfaces.ManifoldCFException: Database exception: Exception doing query: Lock wait timeout exceeded; try restarting transaction
        at org.apache.manifoldcf.core.database.Database.executeViaThread(Database.java:681)
        at org.apache.manifoldcf.core.database.Database.executeUncachedQuery(Database.java:709)
        at org.apache.manifoldcf.core.database.Database$QueryCacheExecutor.create(Database.java:1394)
        at org.apache.manifoldcf.core.cachemanager.CacheManager.findObjectsAndExecute(CacheManager.java:144)
        at org.apache.manifoldcf.core.database.Database.executeQuery(Database.java:186)
        at org.apache.manifoldcf.core.database.DBInterfaceMySQL.performModification(DBInterfaceMySQL.java:678)
        at org.apache.manifoldcf.core.database.DBInterfaceMySQL.performUpdate(DBInterfaceMySQL.java:275)
        at org.apache.manifoldcf.core.database.BaseTable.performUpdate(BaseTable.java:80)
        at org.apache.manifoldcf.crawler.jobs.JobQueue.updateCompletedRecord(JobQueue.java:722)
        at org.apache.manifoldcf.crawler.jobs.JobManager.markDocumentCompletedMultiple(JobManager.java:2435)
        at org.apache.manifoldcf.crawler.system.WorkerThread.run(WorkerThread.java:765)
Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3609)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3541)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2002)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2624)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2127)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2427)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2345)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2330)
        at org.apache.manifoldcf.core.database.Database.execute(Database.java:840)
        at org.apache.manifoldcf.core.database.Database$ExecuteQueryThread.run(Database.java:641)

and

ERROR 2012-11-22 19:36:28,593 (Worker thread '16') - Worker thread aborting and restarting due to database connection reset: Database exception: Exception doing query: Lock wait timeout exceeded; try restarting transaction
org.apache.manifoldcf.core.interfaces.ManifoldCFException: Database exception: Exception doing query: Lock wait timeout exceeded; try restarting transaction
        at org.apache.manifoldcf.core.database.Database.executeViaThread(Database.java:681)
        at org.apache.manifoldcf.core.database.Database.executeUncachedQuery(Database.java:709)
        at org.apache.manifoldcf.core.database.Database$QueryCacheExecutor.create(Database.java:1394)
        at org.apache.manifoldcf.core.cachemanager.CacheManager.findObjectsAndExecute(CacheManager.java:144)
        at org.apache.manifoldcf.core.database.Database.executeQuery(Database.java:186)
        at org.apache.manifoldcf.core.database.DBInterfaceMySQL.performModification(DBInterfaceMySQL.java:678)
        at org.apache.manifoldcf.core.database.DBInterfaceMySQL.performUpdate(DBInterfaceMySQL.java:275)
        at org.apache.manifoldcf.core.database.BaseTable.performUpdate(BaseTable.java:80)
        at org.apache.manifoldcf.crawler.jobs.HopCount.markForDelete(HopCount.java:1426)
        at org.apache.manifoldcf.crawler.jobs.HopCount.doDeleteInvalidation(HopCount.java:1356)
        at org.apache.manifoldcf.crawler.jobs.HopCount.doFinish(HopCount.java:1057)
        at org.apache.manifoldcf.crawler.jobs.HopCount.finishParents(HopCount.java:389)
        at org.apache.manifoldcf.crawler.jobs.JobManager.finishDocuments(JobManager.java:4309)
        at org.apache.manifoldcf.crawler.system.WorkerThread.run(WorkerThread.java:557)
Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3609)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3541)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2002)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2624)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2127)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2427)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2345)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2330)
        at org.apache.manifoldcf.core.database.Database.execute(Database.java:840)
        at org.apache.manifoldcf.core.database.Database$ExecuteQueryThread.run(Database.java:641)