users@glassfish.java.net

Re: Problem EJB Timer Service: A lock could not be obtained within the time

From: Mitesh Meswani <Mitesh.Meswani_at_Sun.COM>
Date: Wed, 08 Oct 2008 12:27:29 -0700

EJB are implemented using CMP as the persistence layer. Can you please
turn on sql logging for cmp and send out the log. I am curious to know
if there are any parallel updates going on to the table. You need to add
following property to log-service element of domain.xml to turn on the log.

  <log-service alarms="false"
file="${com.sun.aas.instanceRoot}/logs/server.log" ....>
         <property name="javax.enterprise.resource.jdo.sqlstore.sql"
value="FINEST"/>
       </module-log-levels>
</log-service>

If you are looking for a workaround - Since this seems to be derby
issue, you can bypass using derby and point timer service to any other
external data source you have. The instructions to do that can be found
here. https://glassfish.dev.java.net/javaee5/docs/AG/ablms.html#ablnh

Thanks,
Mtiesh

glassfish_at_javadesktop.org wrote:
> Hi,
>
> I've got same problem. Any idea?
>
> [#|2008-10-08T12:32:27.004+0200|INFO|sun-appserver9.1|javax.enterprise.system.container.ejb.mdb|_ThreadID=47;_ThreadName=p: thread-pool-1; w: 25;|javax.ejb.TransactionRolledbackLocalException
> javax.ejb.TransactionRolledbackLocalException: Exception thrown from bean; nested exception is: com.sun.jdo.api.persistence.support.JDODataStoreException: JDO76400: Got a JDBC SQLException while executing the SQL statement:
> SQL statement<select distinct t0."TIMERID" from "EJB__TIMER__TBL" t0 where t0."CONTAINERID" = CAST (? AS BIGINT) and t0."STATE" = CAST (? AS INTEGER)> with input values:java.lang.Long:80180773784846358, java.lang.Integer:0.
> Please examine the SQLException for more information.
> NestedException: java.sql.SQLTransactionRollbackException: A lock could not be obtained within the time requested
> com.sun.jdo.api.persistence.support.JDODataStoreException: JDO76400: Got a JDBC SQLException while executing the SQL statement:
> SQL statement<select distinct t0."TIMERID" from "EJB__TIMER__TBL" t0 where t0."CONTAINERID" = CAST (? AS BIGINT) and t0."STATE" = CAST (? AS INTEGER)> with input values:java.lang.Long:80180773784846358, java.lang.Integer:0.
> Please examine the SQLException for more information.
> NestedException: java.sql.SQLTransactionRollbackException: A lock could not be obtained within the time requested
> at com.sun.jdo.spi.persistence.support.sqlstore.SQLStoreManager.throwJDOSqlException(SQLStoreManager.java:645)
> at com.sun.jdo.spi.persistence.support.sqlstore.SQLStoreManager.executeQuery(SQLStoreManager.java:479)
> at com.sun.jdo.spi.persistence.support.sqlstore.SQLStoreManager.retrieve(SQLStoreManager.java:376)
> at com.sun.jdo.spi.persistence.support.sqlstore.impl.PersistenceManagerImpl.retrieve(PersistenceManagerImpl.java:1118)
> at com.sun.jdo.spi.persistence.support.sqlstore.query.QueryImpl.doExecute(QueryImpl.java:689)
> at com.sun.jdo.spi.persistence.support.sqlstore.query.QueryImpl.executeWithArray(QueryImpl.java:607)
> at com.sun.ejb.containers.TimerBean_2100919770_ConcreteImpl.ejbSelectTimerIdsByContainerAndState(TimerBean_2100919770_ConcreteImpl.java:1086)
> at com.sun.ejb.containers.TimerBean.ejbHomeSelectActiveTimerIdsByContainer(TimerBean.java:592)
> at sun.reflect.GeneratedMethodAccessor167.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:597)
> at com.sun.enterprise.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1067)
> at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:176)
> at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2895)
> at com.sun.ejb.containers.EJBLocalHomeInvocationHandler.invoke(EJBLocalHomeInvocationHandler.java:242)
> at $Proxy21.selectActiveTimerIdsByContainer(Unknown Source)
> at com.sun.ejb.containers.EJBTimerService.getTimerIds(EJBTimerService.java:1138)
> at com.sun.ejb.containers.EJBTimerServiceWrapper.getTimers(EJBTimerServiceWrapper.java:204)
> at de.mobilexag.centerware.sync.schedule.SchedulerIn.checkScheduling(SchedulerIn.java:109)
> at de.mobilexag.centerware.sync.schedule.SchedulerIn.onMessage(SchedulerIn.java:205)
> 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 com.sun.enterprise.security.SecurityUtil$2.run(SecurityUtil.java:182)
> at java.security.AccessController.doPrivileged(Native Method)
> at com.sun.enterprise.security.application.EJBSecurityManager.doAsPrivileged(EJBSecurityManager.java:1041)
> at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:187)
> at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2895)
> at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:3986)
> at com.sun.ejb.containers.MessageBeanContainer.deliverMessage(MessageBeanContainer.java:1111)
> at com.sun.ejb.containers.MessageBeanListenerImpl.deliverMessage(MessageBeanListenerImpl.java:74)
> at com.sun.enterprise.connectors.inflow.MessageEndpointInvocationHandler.invoke(MessageEndpointInvocationHandler.java:179)
> at $Proxy262.onMessage(Unknown Source)
> at com.sun.messaging.jms.ra.OnMessageRunner.run(OnMessageRunner.java:258)
> at com.sun.enterprise.connectors.work.OneWork.doWork(OneWork.java:76)
> at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)
>
> NestedStackTrace:
> java.sql.SQLTransactionRollbackException: A lock could not be obtained within the time requested
> at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
> at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
> at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
> at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
> at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedResultSet.closeOnTransactionError(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedResultSet.movePosition(Unknown Source)
> at org.apache.derby.impl.jdbc.EmbedResultSet.next(Unknown Source)
> at com.sun.jdo.spi.persistence.support.sqlstore.sql.ResultDesc.getResult(ResultDesc.java:490)
> at com.sun.jdo.spi.persistence.support.sqlstore.sql.generator.SelectQueryPlan.getResult(SelectQueryPlan.java:1576)
> at com.sun.jdo.spi.persistence.support.sqlstore.SQLStoreManager.executeQuery(SQLStoreManager.java:477)
> at com.sun.jdo.spi.persistence.support.sqlstore.SQLStoreManager.retrieve(SQLStoreManager.java:376)
> at com.sun.jdo.spi.persistence.support.sqlstore.impl.PersistenceManagerImpl.retrieve(PersistenceManagerImpl.java:1118)
> at com.sun.jdo.spi.persistence.support.sqlstore.query.QueryImpl.doExecute(QueryImpl.java:689)
> at com.sun.jdo.spi.persistence.support.sqlstore.query.QueryImpl.executeWithArray(QueryImpl.java:607)
> at com.sun.ejb.containers.TimerBean_2100919770_ConcreteImpl.ejbSelectTimerIdsByContainerAndState(TimerBean_2100919770_ConcreteImpl.java:1086)
> at com.sun.ejb.containers.TimerBean.ejbHomeSelectActiveTimerIdsByContainer(TimerBean.java:592)
> at sun.reflect.GeneratedMethodAccessor167.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:597)
> at com.sun.enterprise.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1067)
> at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:176)
> at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2895)
> at com.sun.ejb.containers.EJBLocalHomeInvocationHandler.invoke(EJBLocalHomeInvocationHandler.java:242)
> at $Proxy21.selectActiveTimerIdsByContainer(Unknown Source)
> at com.sun.ejb.containers.EJBTimerService.getTimerIds(EJBTimerService.java:1138)
> at com.sun.ejb.containers.EJBTimerServiceWrapper.getTimers(EJBTimerServiceWrapper.java:204)
> at de.mobilexag.centerware.sync.schedule.SchedulerIn.checkScheduling(SchedulerIn.java:109)
> at de.mobilexag.centerware.sync.schedule.SchedulerIn.onMessage(SchedulerIn.java:205)
> 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 com.sun.enterprise.security.SecurityUtil$2.run(SecurityUtil.java:182)
> at java.security.AccessController.doPrivileged(Native Method)
> at com.sun.enterprise.security.application.EJBSecurityManager.doAsPrivileged(EJBSecurityManager.java:1041)
> at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:187)
> at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2895)
> at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:3986)
> at com.sun.ejb.containers.MessageBeanContainer.deliverMessage(MessageBeanContainer.java:1111)
> at com.sun.ejb.containers.MessageBeanListenerImpl.deliverMessage(MessageBeanListenerImpl.java:74)
> at com.sun.enterprise.connectors.inflow.MessageEndpointInvocationHandler.invoke(MessageEndpointInvocationHandler.java:179)
> at $Proxy262.onMessage(Unknown Source)
> at com.sun.messaging.jms.ra.OnMessageRunner.run(OnMessageRunner.java:258)
> at com.sun.enterprise.connectors.work.OneWork.doWork(OneWork.java:76)
> at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)
> Caused by: java.sql.SQLException: A lock could not be obtained within the time requested
> at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
> at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(Unknown Source)
> ... 47 more
> javax.ejb.TransactionRolledbackLocalException: Exception thrown from bean; nested exception is: com.sun.jdo.api.persistence.support.JDODataStoreException: JDO76400: Got a JDBC SQLException while executing the SQL statement:
> SQL statement<select distinct t0."TIMERID" from "EJB__TIMER__TBL" t0 where t0."CONTAINERID" = CAST (? AS BIGINT) and t0."STATE" = CAST (? AS INTEGER)> with input values:java.lang.Long:80180773784846358, java.lang.Integer:0.
> Please examine the SQLException for more information.
> NestedException: java.sql.SQLTransactionRollbackException: A lock could not be obtained within the time requested
> at com.sun.ejb.containers.BaseContainer.checkExceptionClientTx(BaseContainer.java:3728)
> at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:3576)
> at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1354)
> at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1316)
> at com.sun.ejb.containers.EJBLocalHomeInvocationHandler.invoke(EJBLocalHomeInvocationHandler.java:251)
> at $Proxy21.selectActiveTimerIdsByContainer(Unknown Source)
> at com.sun.ejb.containers.EJBTimerService.getTimerIds(EJBTimerService.java:1138)
> at com.sun.ejb.containers.EJBTimerServiceWrapper.getTimers(EJBTimerServiceWrapper.java:204)
> at de.mobilexag.centerware.sync.schedule.SchedulerIn.checkScheduling(SchedulerIn.java:109)
> at de.mobilexag.centerware.sync.schedule.SchedulerIn.onMessage(SchedulerIn.java:205)
> 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 com.sun.enterprise.security.SecurityUtil$2.run(SecurityUtil.java:182)
> at java.security.AccessController.doPrivileged(Native Method)
> at com.sun.enterprise.security.application.EJBSecurityManager.doAsPrivileged(EJBSecurityManager.java:1041)
> at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:187)
> at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2895)
> at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:3986)
> at com.sun.ejb.containers.MessageBeanContainer.deliverMessage(MessageBeanContainer.java:1111)
> at com.sun.ejb.containers.MessageBeanListenerImpl.deliverMessage(MessageBeanListenerImpl.java:74)
> at com.sun.enterprise.connectors.inflow.MessageEndpointInvocationHandler.invoke(MessageEndpointInvocationHandler.java:179)
> at $Proxy262.onMessage(Unknown Source)
> at com.sun.messaging.jms.ra.OnMessageRunner.run(OnMessageRunner.java:258)
> at com.sun.enterprise.connectors.work.OneWork.doWork(OneWork.java:76)
> at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)
> |#]
> [Message sent by forum member 'hegalor' (hegalor)]
>
> http://forums.java.net/jive/thread.jspa?messageID=303947
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
> For additional commands, e-mail: users-help_at_glassfish.dev.java.net
>
>