Timeout trying to lock table: remove h2 pessimistic locks

[gschueler]

Issue #312 cropped up again when using H2 with larger size database and possibly slower disk-speed.

Updating LOCK_TIMEOUT didn't help.

The side-effect was that a Job would appear to never finish, because the lock failure would happen when updating the execution status after a job was done.

to fix: remove use of pessimistic locking, rely on optimistic locks with retries

additional: remove use of pessimistic locks in other places: job abort, job delete, takeover cluster schedule.

[atlasloewenherz]

this seems to still occurs : im using the rundeck-2.6.2 on Tomcat 7, just when the notification using a notification example plugin is triggered this happens:

ERROR SqlExceptionHelper: Timeout trying to lock table "EXECUTION"; SQL statement:
select execution0_.id as id1_2_0_, execution0_.version as version2_2_0_, execution0_.abortedby as abortedb3_2_0_, execution0_.arg_string as arg_stri4_2_0_, execution0_.cancelled as cancelle5_2_0_, execution0_.date_completed as date_com6_2_0_, execution0_.date_started as date_sta7_2_0_, execution0_.do_nodedispatch as do_noded8_2_0_, execution0_.failed_node_list as failed_n9_2_0_, execution0_.filter as filter10_2_0_, execution0_.loglevel as logleve11_2_0_, execution0_.node_exclude as node_ex12_2_0_, execution0_.node_exclude_name as node_ex13_2_0_, execution0_.node_exclude_os_arch as node_ex14_2_0_, execution0_.node_exclude_os_family as node_ex15_2_0_, execution0_.node_exclude_os_name as node_ex16_2_0_, execution0_.node_exclude_os_version as node_ex17_2_0_, execution0_.node_exclude_precedence as node_ex18_2_0_, execution0_.node_exclude_tags as node_ex19_2_0_, execution0_.node_include as node_in20_2_0_, execution0_.node_include_name as node_in21_2_0_, execution0_.node_include_os_arch as node_in22_2_0_, execution0_.node_include_os_family as node_in23_2_0_, execution0_.node_include_os_name as node_in24_2_0_, execution0_.node_include_os_version as node_in25_2_0_, execution0_.node_include_tags as node_in26_2_0_, execution0_.node_keepgoing as node_ke27_2_0_, execution0_.node_rank_attribute as node_ra28_2_0_, execution0_.node_rank_order_ascending as node_ra29_2_0_, execution0_.node_threadcount as node_th30_2_0_, execution0_.orchestrator_id as orchest31_2_0_, execution0_.outputfilepath as outputf32_2_0_, execution0_.project as project33_2_0_, execution0_.retry as retry34_2_0_, execution0_.retry_attempt as retry_a35_2_0_, execution0_.retry_execution_id as retry_e36_2_0_, execution0_.scheduled_execution_id as schedul37_2_0_, execution0_.server_nodeuuid as server_38_2_0_, execution0_.status as status39_2_0_, execution0_.succeeded_node_list as succeed40_2_0_, execution0_.timed_out as timed_o41_2_0_, execution0_.timeout as timeout42_2_0_, execution0_.rduser as rduser43_2_0_, execution0_.will_retry as will_re44_2_0_, execution0_.workflow_id as workflo45_2_0_ from execution execution0_ where execution0_.id=? [50200-176]
ERROR GrailsExceptionResolver: JdbcSQLException occurred when processing request: [POST] /execution/tailExecutionOutput
Timeout trying to lock table "EXECUTION"; SQL statement:
select execution0_.id as id1_2_0_, execution0_.version as version2_2_0_, execution0_.abortedby as abortedb3_2_0_, execution0_.arg_string as arg_stri4_2_0_, execution0_.cancelled as cancelle5_2_0_, execution0_.date_completed as date_com6_2_0_, execution0_.date_started as date_sta7_2_0_, execution0_.do_nodedispatch as do_noded8_2_0_, execution0_.failed_node_list as failed_n9_2_0_, execution0_.filter as filter10_2_0_, execution0_.loglevel as logleve11_2_0_, execution0_.node_exclude as node_ex12_2_0_, execution0_.node_exclude_name as node_ex13_2_0_, execution0_.node_exclude_os_arch as node_ex14_2_0_, execution0_.node_exclude_os_family as node_ex15_2_0_, execution0_.node_exclude_os_name as node_ex16_2_0_, execution0_.node_exclude_os_version as node_ex17_2_0_, execution0_.node_exclude_precedence as node_ex18_2_0_, execution0_.node_exclude_tags as node_ex19_2_0_, execution0_.node_include as node_in20_2_0_, execution0_.node_include_name as node_in21_2_0_, execution0_.node_include_os_arch as node_in22_2_0_, execution0_.node_include_os_family as node_in23_2_0_, execution0_.node_include_os_name as node_in24_2_0_, execution0_.node_include_os_version as node_in25_2_0_, execution0_.node_include_tags as node_in26_2_0_, execution0_.node_keepgoing as node_ke27_2_0_, execution0_.node_rank_attribute as node_ra28_2_0_, execution0_.node_rank_order_ascending as node_ra29_2_0_, execution0_.node_threadcount as node_th30_2_0_, execution0_.orchestrator_id as orchest31_2_0_, execution0_.outputfilepath as outputf32_2_0_, execution0_.project as project33_2_0_, execution0_.retry as retry34_2_0_, execution0_.retry_attempt as retry_a35_2_0_, execution0_.retry_execution_id as retry_e36_2_0_, execution0_.scheduled_execution_id as schedul37_2_0_, execution0_.server_nodeuuid as server_38_2_0_, execution0_.status as status39_2_0_, execution0_.succeeded_node_list as succeed40_2_0_, execution0_.timed_out as timed_o41_2_0_, execution0_.timeout as timeout42_2_0_, execution0_.rduser as rduser43_2_0_, execution0_.will_retry as will_re44_2_0_, execution0_.workflow_id as workflo45_2_0_ from execution execution0_ where execution0_.id=? [50200-176]. Stacktrace follows:
org.h2.jdbc.JdbcSQLException: Timeout trying to lock table "EXECUTION"; SQL statement:
select execution0_.id as id1_2_0_, execution0_.version as version2_2_0_, execution0_.abortedby as abortedb3_2_0_, execution0_.arg_string as arg_stri4_2_0_, execution0_.cancelled as cancelle5_2_0_, execution0_.date_completed as date_com6_2_0_, execution0_.date_started as date_sta7_2_0_, execution0_.do_nodedispatch as do_noded8_2_0_, execution0_.failed_node_list as failed_n9_2_0_, execution0_.filter as filter10_2_0_, execution0_.loglevel as logleve11_2_0_, execution0_.node_exclude as node_ex12_2_0_, execution0_.node_exclude_name as node_ex13_2_0_, execution0_.node_exclude_os_arch as node_ex14_2_0_, execution0_.node_exclude_os_family as node_ex15_2_0_, execution0_.node_exclude_os_name as node_ex16_2_0_, execution0_.node_exclude_os_version as node_ex17_2_0_, execution0_.node_exclude_precedence as node_ex18_2_0_, execution0_.node_exclude_tags as node_ex19_2_0_, execution0_.node_include as node_in20_2_0_, execution0_.node_include_name as node_in21_2_0_, execution0_.node_include_os_arch as node_in22_2_0_, execution0_.node_include_os_family as node_in23_2_0_, execution0_.node_include_os_name as node_in24_2_0_, execution0_.node_include_os_version as node_in25_2_0_, execution0_.node_include_tags as node_in26_2_0_, execution0_.node_keepgoing as node_ke27_2_0_, execution0_.node_rank_attribute as node_ra28_2_0_, execution0_.node_rank_order_ascending as node_ra29_2_0_, execution0_.node_threadcount as node_th30_2_0_, execution0_.orchestrator_id as orchest31_2_0_, execution0_.outputfilepath as outputf32_2_0_, execution0_.project as project33_2_0_, execution0_.retry as retry34_2_0_, execution0_.retry_attempt as retry_a35_2_0_, execution0_.retry_execution_id as retry_e36_2_0_, execution0_.scheduled_execution_id as schedul37_2_0_, execution0_.server_nodeuuid as server_38_2_0_, execution0_.status as status39_2_0_, execution0_.succeeded_node_list as succeed40_2_0_, execution0_.timed_out as timed_o41_2_0_, execution0_.timeout as timeout42_2_0_, execution0_.rduser as rduser43_2_0_, execution0_.will_retry as will_re44_2_0_, execution0_.workflow_id as workflo45_2_0_ from execution execution0_ where execution0_.id=? [50200-176]
        at org.h2.message.DbException.getJdbcSQLException(DbException.java:344)
        at org.h2.message.DbException.get(DbException.java:178)
        at org.h2.message.DbException.get(DbException.java:154)
        at org.h2.table.RegularTable.doLock(RegularTable.java:530)
        at org.h2.table.RegularTable.lock(RegularTable.java:464)
        at org.h2.table.TableFilter.lock(TableFilter.java:147)
        at org.h2.command.dml.Select.queryWithoutCache(Select.java:632)
        at org.h2.command.dml.Query.query(Query.java:323)
        at org.h2.command.dml.Query.query(Query.java:291)
        at org.h2.command.dml.Query.query(Query.java:37)
        at org.h2.command.CommandContainer.query(CommandContainer.java:91)
        at org.h2.command.Command.executeQuery(Command.java:197)
        at org.h2.jdbc.JdbcPreparedStatement.executeQuery(JdbcPreparedStatement.java:109)
        at rundeck.controllers.ExecutionController$_closure13.doCall(ExecutionController.groovy:755)
        at grails.plugin.cache.web.filter.PageFragmentCachingFilter.doFilter(PageFragmentCachingFilter.java:198)
        at grails.plugin.cache.web.filter.AbstractFilter.doFilter(AbstractFilter.java:63)
        at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:97)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
Trigger success fired for {id=26, href=http://localhost:18080/project/localtest/execution/follow/26, status=succeeded, user=admin, dateStarted=2016-02-26 13:12:41.583, dateStartedUnixtime=1456488761583, dateStartedW3c=2016-02-26T12:12:41Z, description=, argstring=null, project=localtest, failedNodeListString=null, failedNodeList=null, succeededNodeListString=ssh-proxy-cm-vi.zd.guj.de, succeededNodeList=[ssh-proxy-cm-vi.zd.guj.de], loglevel=DEBUG, dateEnded=2016-02-26 13:12:42.074, dateEndedUnixtime=1456488762074, dateEndedW3c=2016-02-26T12:12:42Z, abortedby=null, nodestatus={succeeded=1, failed=0, total=1}, job={id=b1547f7b-76ae-44b4-9a00-b2ab676bed76, href=http://localhost:18080/project/localtest/job/show/b1547f7b-76ae-44b4-9a00-b2ab676bed76, name=echo, group=, project=localtest, description=, averageDuration=1818}, context={job={loglevel=DEBUG, wasRetry=false, url=http://localhost:18080/project/localtest/execution/follow/26, id=b1547f7b-76ae-44b4-9a00-b2ab676bed76, project=localtest, username=admin, retryAttempt=0, user.name=admin, name=echo, serverUUID=null, group=null, serverUrl=http://localhost:18080/, execid=26}, option={}}}, configuration: {example=okay}

the notification as such works fine