ロック試行がタイムアウト
簡単なトランザクションができたところで、この前jfluteさんが言っていた
更新系の処理の後の検索をやるようなテストケースを試してみたところ、
見事同じエラーが出た。
調査は後ほど暇を見つけて。
やっと2日前のjfluteさんに追いついた感じ^^;
ログ
10:52:37 [http-8080-1] INFO atomikos - createCompositeTransaction ( 300000 ): created new ROOT transaction with id 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - addParticipant ( 192.168.0.3.tm0000100005192.168.0.3.tm1 ) for transaction 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - XAResource.start ( 192.168.0.3.tm0000100005192.168.0.3.tm1 , XAResource.TMNOFLAGS ) called on resource jdbc/h2/xaDatasource represented by XAResource instance xads1: url=jdbc:h2:tcp://127.0.0.1:9095/t2db user=sa 10:52:37 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - XAResource.end ( 192.168.0.3.tm0000100005192.168.0.3.tm1 , XAResource.TMSUCCESS ) called on resource jdbc/h2/xaDatasource represented by XAResource instance xads1: url=jdbc:h2:tcp://127.0.0.1:9095/t2db user=sa 10:52:37 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - addParticipant ( 192.168.0.3.tm0000100005192.168.0.3.tm1 ) for transaction 192.168.0.3.tm0000100005 10:52:37 [http-8080-1] INFO atomikos - XAResource.start ( 192.168.0.3.tm0000100005192.168.0.3.tm1 , XAResource.TMJOIN ) called on resource jdbc/h2/xaDatasource represented by XAResource instance xads2: url=jdbc:h2:tcp://127.0.0.1:9095/t2db user=sa 10:52:38 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:38 [http-8080-1] INFO atomikos - XAResource.end ( 192.168.0.3.tm0000100005192.168.0.3.tm1 , XAResource.TMSUCCESS ) called on resource jdbc/h2/xaDatasource represented by XAResource instance xads2: url=jdbc:h2:tcp://127.0.0.1:9095/t2db user=sa 10:52:38 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:38 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:38 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:38 [http-8080-1] INFO atomikos - setRollbackOnly() called for transaction 192.168.0.3.tm0000100005 10:52:38 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:38 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:38 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:38 [http-8080-1] INFO atomikos - getCompositeTransaction() returning instance with id 192.168.0.3.tm0000100005 10:52:39 [Atomikos:2] INFO atomikos - XAResource.rollback ( 192.168.0.3.tm0000100005192.168.0.3.tm1 ) called on resource jdbc/h2/xaDatasource represented by XAResource instance xads2: url=jdbc:h2:tcp://127.0.0.1:9095/t2db user=sa 10:52:39 [http-8080-1] INFO atomikos - rollback() done of transaction 192.168.0.3.tm0000100005 10:52:39 [http-8080-1] ERROR o.t.t.h.i.GlobalExceptionHandlerImpl - Look! Read the message below. /* * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * The SQL failed to execute! [Advice] Please confirm the SQLException message. [SQLState] HYT00 [ErrorCode] 50200 [SQLException] org.h2.jdbc.JdbcSQLException テーブル EMPLOYEE のロック試行がタイムアウトしました Timeout trying to lock table EMPLOYEE [50200-69] [Behavior] EmployeePage.update() --> EmployeeServiceImpl.update() --> EmployeeBhv.selectList()... [ConditionBean] org.t2framework.samples.todo.dbflute.cbean.EmployeeCB [Statement] org.h2.jdbc.JdbcPreparedStatement [Display SQL] select dflocal.SAL as SAL, dflocal.VERSIONNO as VERSIONNO, dflocal.DEPTNO as DEPTNO, dflocal.MGR as MGR, dflocal.JOB as JOB, dflocal.ENAME as ENAME, dflocal.HIREDATE as HIREDATE, dflocal.EMPNO as EMPNO, dflocal.COMM as COMM from EMPLOYEE dflocal order by dflocal.EMPNO asc * * * * * * * * * */ 2009/01/20 10:52:39 org.apache.catalina.core.StandardWrapperValve invoke 致命的: サーブレット default のServlet.service()が例外を投げました org.h2.jdbc.JdbcSQLException: テーブル EMPLOYEE のロック試行がタイムアウトしました Timeout trying to lock table EMPLOYEE [50200-69] at org.h2.message.Message.getSQLException(Message.java:91) at org.h2.message.Message.getSQLException(Message.java:95) at org.h2.message.Message.getSQLException(Message.java:73) at org.h2.table.TableData.lock(TableData.java:377) at org.h2.table.TableFilter.lock(TableFilter.java:84) at org.h2.command.dml.Select.queryWithoutCache(Select.java:525) at org.h2.command.dml.Query.query(Query.java:231) at org.h2.command.CommandContainer.query(CommandContainer.java:78) at org.h2.command.Command.executeQueryLocal(Command.java:139) at org.h2.server.TcpServerThread.process(TcpServerThread.java:228) at org.h2.server.TcpServerThread.run(TcpServerThread.java:104) at java.lang.Thread.run(Thread.java:619) at org.h2.engine.SessionRemote.done(SessionRemote.java:319) at org.h2.command.CommandRemote.executeQuery(CommandRemote.java:137) at org.h2.jdbc.JdbcPreparedStatement.executeQuery(JdbcPreparedStatement.java:91) at org.seasar.dbflute.s2dao.sqlhandler.TnBasicSelectHandler.createResultSet(TnBasicSelectHandler.java:83) at org.seasar.dbflute.s2dao.sqlhandler.TnBasicSelectHandler.execute(TnBasicSelectHandler.java:75) at org.seasar.dbflute.s2dao.sqlhandler.TnBasicSelectHandler.execute(TnBasicSelectHandler.java:60) at org.seasar.dbflute.s2dao.sqlhandler.TnBasicSelectHandler.execute(TnBasicSelectHandler.java:48) at org.seasar.dbflute.bhv.core.execution.SelectCBExecution.execute(SelectCBExecution.java:59) at org.seasar.dbflute.bhv.core.BehaviorCommandInvoker.executeSql(BehaviorCommandInvoker.java:236) at org.seasar.dbflute.bhv.core.BehaviorCommandInvoker.doInvoke(BehaviorCommandInvoker.java:155) at org.seasar.dbflute.bhv.core.BehaviorCommandInvoker.invoke(BehaviorCommandInvoker.java:100) at org.seasar.dbflute.bhv.AbstractBehaviorReadable.invoke(AbstractBehaviorReadable.java:875) at org.t2framework.samples.todo.dbflute.bsbhv.BsEmployeeBhv.invoke(<generated>) at org.t2framework.samples.todo.dbflute.exbhv.EmployeeBhv.invoke(<generated>) at org.t2framework.samples.todo.dbflute.bsbhv.BsEmployeeBhv$$M$27ffc841.delegateSelectList(BsEmployeeBhv.java:462) at org.t2framework.samples.todo.dbflute.bsbhv.BsEmployeeBhv$$A$27ffc841.delegateSelectList(<generated>) at org.t2framework.samples.todo.dbflute.bsbhv.BsEmployeeBhv.delegateSelectList(<generated>) at org.t2framework.samples.todo.dbflute.exbhv.EmployeeBhv.delegateSelectList(<generated>) at org.t2framework.samples.todo.dbflute.bsbhv.BsEmployeeBhv$$M$27ffc841.selectList(BsEmployeeBhv.java:165) at org.t2framework.samples.todo.dbflute.bsbhv.BsEmployeeBhv$$A$27ffc841.selectList(<generated>) at org.t2framework.samples.todo.dbflute.bsbhv.BsEmployeeBhv.selectList(<generated>) at org.t2framework.samples.todo.dbflute.exbhv.EmployeeBhv.selectList(<generated>) at org.t2framework.samples.todo.service.impl.EmployeeServiceImpl$$M$cdf69e1a.update(EmployeeServiceImpl.java:39) at org.t2framework.samples.todo.service.impl.EmployeeServiceImpl$$A$cdf69e1a.update(<generated>) at org.t2framework.samples.todo.service.impl.EmployeeServiceImpl.update(<generated>) at org.t2framework.samples.todo.service.impl.EmployeeServiceImpl$$LucyAop$$13e584.update$$(EmployeeServiceImpl$$LucyAop$$13e584.java) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.t2framework.lucy.aop.impl.InvocationImpl.proceed(InvocationImpl.java:137) at org.t2framework.lucy.tx.interceptor.InvocationWorker.work(InvocationWorker.java:20) at org.t2framework.lucy.tx.JTATransactionProcesser.required(JTATransactionProcesser.java:28) at org.t2framework.lucy.tx.interceptor.RequiredInterceptor.process(RequiredInterceptor.java:11) at org.t2framework.lucy.tx.interceptor.AbstractTxInterceptor.intercept(AbstractTxInterceptor.java:38) at org.t2framework.lucy.aop.impl.InvocationImpl.proceed(InvocationImpl.java:134) at org.t2framework.lucy.aop.impl.InvocationImpl.doProceed(InvocationImpl.java:112) at org.t2framework.samples.todo.service.impl.EmployeeServiceImpl$$LucyAop$$13e584.update(EmployeeServiceImpl$$LucyAop$$13e584.java) at org.t2framework.samples.todo.page.EmployeePage$$M$bd026ad5.update(EmployeePage.java:69) at org.t2framework.samples.todo.page.EmployeePage$$A$bd026ad5.update(<generated>) at org.t2framework.samples.todo.page.EmployeePage.update(<generated>) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.t2framework.commons.util.Reflections$MethodUtil.invoke(Reflections.java:468) at org.t2framework.commons.meta.impl.MethodDescImpl.invoke(MethodDescImpl.java:87) at org.t2framework.t2.action.impl.ActionInvokerImpl.invokeAction(ActionInvokerImpl.java:199) at org.t2framework.t2.action.impl.ActionInvokerImpl.invoke(ActionInvokerImpl.java:143) at org.t2framework.t2.filter.T2Filter.doFilter(T2Filter.java:134) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.t2framework.t2.filter.MultiPartRequestFilter.doFilter(MultiPartRequestFilter.java:94) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:845) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583) at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447) at java.lang.Thread.run(Thread.java:619)