You're absolutely right, David. Thanks for the response.
It is a transaction issue and the @Stateless EJB is holding a transaction
open and writing into 6 to 10 tables in a single database, which is also
the database accessed by JSF components (by endusers). The @Stateless EJB
is on a timer ( @Schedule), checks email server for incoming requests from
customers, and takes that data and inserts it into database, so endusers
don't have to manually enter the data (that they receive from these
formmail results).
Below is the exception that I saw maybe an hour or two ago, and I confirmed
that it's a locking/transaction issue, and from the stacktrace, it seems as
though the JSF components cannot access the table, that is evidently locked
by @Stateless EJB. The @Stateless @EJB updated all tables on my
faster/dev/test server on average of 1 to 2 seconds, and/so in my opinion,
the data is not that much at all, maybe a few kbytes of data being inserted
into the database. Anyway, I've been reading up on pessismistic and
optimistic locking, and that's where I was in my reading before I noticed
your email. I really don't know what the database or JPA is defaulting to,
because honestly, I have no code that specifies any locks. Recently, I only
added query hint (readonly) to JPA queries. Personally, I feel as though I
can use 'no locking' for these inserts, since this is brand new data, but
the JSF components may be locking the entites/tables during simple queries
(SELECT statements). Feel free to change this email/topic to a more
suitable topic/subject, if necessary. :)
enCore(Unknown Source)
at org.apache.derby.impl.sql.execute.BasicNoPutResultSetImpl.open(Unknown
Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(Unknown
Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown
Source)
... 126 more
javax.ejb.EJBException: The bean encountered a non-application exception;
nested exception is:
Exception [EclipseLink-4002] (Eclipse Persistence Services -
2.3.2.v20111125-r10461):
org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLTransactionRollbackException: A lock could
not be obtained within the time requested
Error Code: 30000
Call: SELECT t0.ORDER_ID, t0.BALANCE, t0.CANCELLED, t0.CANCELLED_DATE,
t0.CHANGED_DT, t0.CONFIRMED, t0.CONFIRMED_DATE, t0.CONTRACT_SENT,
t0.CONTRACT_SENT_DATE, t0.CREATED_BY, t0.CREATED_DT, t0.DEPOSIT,
t0.DEPOSIT_PAID, t0.DEPOSIT_PAID_DATE, t0.DISCOUNT, t0.DISCOUNT_RATE,
t0.INTRASTATE, t0.INVOICE_SENT, t0.INVOICE_SENT_DATE, t0.PAID_IN_FULL,
t0.PAID_IN_FULL_DATE, t0.PASSENGERS, t0.QUOTE_SENT, t0.QUOTE_SENT_DATE,
t0.REPORT_DATE_TIME, t0.RETURN_DATE_TIME, t0.TOTAL_COST, t0.TRIP_DATE_TIME,
t0.BANK_FOR_BALANCE_ID, t0.BANK_FOR_DEPOSIT_ID, t0.CUSTOMER_ID,
t0.DETAILS_ID, t0.METHOD_OF_PAYMENT_FOR_BALANCE_ID,
t0.METHOD_OF_PAYMENT_FOR_DEPOSIT_ID, t0.NOTES_ID, t0.ROUTES_ID,
t0.TEMPLATE_ID FROM ORDERS t0 WHERE (((((t0.TRIP_DATE_TIME BETWEEN {ts
'2012-12-06 00:00:00.0'} AND {ts '2012-12-06 23:59:59.0'}) OR
(t0.RETURN_DATE_TIME BETWEEN {ts '2012-12-06 00:00:00.0'} AND {ts
'2012-12-06 23:59:59.0'})) OR ({ts '2012-12-06 00:00:00.0'} BETWEEN
t0.TRIP_DATE_TIME AND t0.RETURN_DATE_TIME)) OR ({ts '2012-12-06
23:59:59.0'} BETWEEN t0.TRIP_DATE_TIME AND t0.RETURN_DATE_TIME)) AND NOT
EXISTS (SELECT 1 FROM ORDER_TEMPLATE t2, ORDER_TEMPLATE t1 WHERE
((t1.TEMPLATE_ID = t2.TEMPLATE_ID) AND (t2.TEMPLATE_ID = t0.TEMPLATE_ID)))
) ORDER BY t0.REPORT_DATE_TIME ASC, t0.TRIP_DATE_TIME ASC
Query: ReadAllQuery(name="Orders.findAllBookedTrips" referenceClass=Orders
sql="SELECT t0.ORDER_ID, t0.BALANCE, t0.CANCELLED, t0.CANCELLED_DATE,
t0.CHANGED_DT, t0.CONFIRMED, t0.CONFIRMED_DATE, t0.CONTRACT_SENT,
t0.CONTRACT_SENT_DATE, t0.CREATED_BY, t0.CREATED_DT, t0.DEPOSIT,
t0.DEPOSIT_PAID, t0.DEPOSIT_PAID_DATE, t0.DISCOUNT, t0.DISCOUNT_RATE,
t0.INTRASTATE, t0.INVOICE_SENT, t0.INVOICE_SENT_DATE, t0.PAID_IN_FULL,
t0.PAID_IN_FULL_DATE, t0.PASSENGERS, t0.QUOTE_SENT, t0.QUOTE_SENT_DATE,
t0.REPORT_DATE_TIME, t0.RETURN_DATE_TIME, t0.TOTAL_COST, t0.TRIP_DATE_TIME,
t0.BANK_FOR_BALANCE_ID, t0.BANK_FOR_DEPOSIT_ID, t0.CUSTOMER_ID,
t0.DETAILS_ID, t0.METHOD_OF_PAYMENT_FOR_BALANCE_ID,
t0.METHOD_OF_PAYMENT_FOR_DEPOSIT_ID, t0.NOTES_ID, t0.ROUTES_ID,
t0.TEMPLATE_ID FROM ORDERS t0 WHERE (((((t0.TRIP_DATE_TIME BETWEEN ? AND ?)
OR (t0.RETURN_DATE_TIME BETWEEN ? AND ?)) OR (? BETWEEN t0.TRIP_DATE_TIME
AND t0.RETURN_DATE_TIME)) OR (? BETWEEN t0.TRIP_DATE_TIME AND
t0.RETURN_DATE_TIME)) AND NOT EXISTS (SELECT ? FROM ORDER_TEMPLATE t2,
ORDER_TEMPLATE t1 WHERE ((t1.TEMPLATE_ID = t2.TEMPLATE_ID) AND
(t2.TEMPLATE_ID = t0.TEMPLATE_ID))) ) ORDER BY t0.REPORT_DATE_TIME ASC,
t0.TRIP_DATE_TIME ASC")
at
org.apache.openejb.core.ivm.BaseEjbProxyHandler.convertException(BaseEjbProxyHandler.java:363)
at
org.apache.openejb.core.ivm.BaseEjbProxyHandler.invoke(BaseEjbProxyHandler.java:283)
at
jpa.session.OrdersFacade$LocalBeanProxy.filterBy(jpa/session/OrdersFacade.java)
at jsf.orders.pf_OrdersController.filterBy(pf_OrdersController.java:1755)
at
jsf.orders.pf_OrdersController.initLazyModel(pf_OrdersController.java:2625)
at
jsf.orders.pf_OrdersController.recreateModel(pf_OrdersController.java:16109)
at jsf.orders.pf_OrdersController.prepareList(pf_OrdersController.java:6000)
at jsf.orders.pf_OrdersController.prepareList(pf_OrdersController.java:5952)
at
jsf.orders.pf_OrdersController.filterTripDateFromSelected(pf_OrdersController.java:4876)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at
org.apache.webbeans.intercept.InterceptorHandler.invoke(InterceptorHandler.java:322)
at
org.apache.webbeans.intercept.NormalScopedBeanInterceptorHandler.invoke(NormalScopedBeanInterceptorHandler.java:117)
at
org.apache.webbeans.intercept.NormalScopedBeanInterceptorHandler.invoke(NormalScopedBeanInterceptorHandler.java:108)
at
jsf.orders.pf_OrdersController_$$_javassist_6.filterTripDateFromSelected(pf_OrdersController_$$_javassist_6.java)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at de.odysseus.el.tree.impl.ast.AstProperty.invoke(AstProperty.java:205)
at de.odysseus.el.tree.impl.ast.AstEval.invoke(AstEval.java:71)
at de.odysseus.el.TreeMethodExpression.invoke(TreeMethodExpression.java:132)
at
org.primefaces.component.behavior.ajax.AjaxBehaviorListenerImpl.processAjaxBehavior(AjaxBehaviorListenerImpl.java:52)
at
org.primefaces.event.DateSelectEvent.processListener(DateSelectEvent.java:42)
at
javax.faces.component.behavior.BehaviorBase.broadcast(BehaviorBase.java:74)
at javax.faces.component.UIComponentBase.broadcast(UIComponentBase.java:407)
at javax.faces.component.UIInput.broadcast(UIInput.java:359)
at javax.faces.component.UIData.broadcast(UIData.java:1596)
at javax.faces.component.UIViewRoot._broadcastAll(UIViewRoot.java:1028)
at javax.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:286)
at javax.faces.component.UIViewRoot._process(UIViewRoot.java:1375)
at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:752)
at
org.apache.myfaces.lifecycle.InvokeApplicationExecutor.execute(InvokeApplicationExecutor.java:38)
at
org.apache.myfaces.lifecycle.LifecycleImpl.executePhase(LifecycleImpl.java:170)
at
org.apache.myfaces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:117)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:197)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.primefaces.webapp.filter.FileUploadFilter.doFilter(FileUploadFilter.java:79)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.omnifaces.filter.GzipResponseFilter.doFilter(GzipResponseFilter.java:148)
at org.omnifaces.filter.HttpFilter.doFilter(HttpFilter.java:75)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at pf.LoginFilter.doFilter(LoginFilter.java:204)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
at org.apache.tomee.catalina.OpenEJBValve.invoke(OpenEJBValve.java:45)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:936)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1004)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589)
at
org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:1822)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: Exception [EclipseLink-4002] (Eclipse Persistence Services -
2.3.2.v20111125-r10461):
org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLTransactionRollbackException: A lock could
not be obtained within the time requested
Error Code: 30000
Call: SELECT t0.ORDER_ID, t0.BALANCE, t0.CANCELLED, t0.CANCELLED_DATE,
t0.CHANGED_DT, t0.CONFIRMED, t0.CONFIRMED_DATE, t0.CONTRACT_SENT,
t0.CONTRACT_SENT_DATE, t0.CREATED_BY, t0.CREATED_DT, t0.DEPOSIT,
t0.DEPOSIT_PAID, t0.DEPOSIT_PAID_DATE, t0.DISCOUNT, t0.DISCOUNT_RATE,
t0.INTRASTATE, t0.INVOICE_SENT, t0.INVOICE_SENT_DATE, t0.PAID_IN_FULL,
t0.PAID_IN_FULL_DATE, t0.PASSENGERS, t0.QUOTE_SENT, t0.QUOTE_SENT_DATE,
t0.REPORT_DATE_TIME, t0.RETURN_DATE_TIME, t0.TOTAL_COST, t0.TRIP_DATE_TIME,
t0.BANK_FOR_BALANCE_ID, t0.BANK_FOR_DEPOSIT_ID, t0.CUSTOMER_ID,
t0.DETAILS_ID, t0.METHOD_OF_PAYMENT_FOR_BALANCE_ID,
t0.METHOD_OF_PAYMENT_FOR_DEPOSIT_ID, t0.NOTES_ID, t0.ROUTES_ID,
t0.TEMPLATE_ID FROM ORDERS t0 WHERE (((((t0.TRIP_DATE_TIME BETWEEN {ts
'2012-12-06 00:00:00.0'} AND {ts '2012-12-06 23:59:59.0'}) OR
(t0.RETURN_DATE_TIME BETWEEN {ts '2012-12-06 00:00:00.0'} AND {ts
'2012-12-06 23:59:59.0'})) OR ({ts '2012-12-06 00:00:00.0'} BETWEEN
t0.TRIP_DATE_TIME AND t0.RETURN_DATE_TIME)) OR ({ts '2012-12-06
23:59:59.0'} BETWEEN t0.TRIP_DATE_TIME AND t0.RETURN_DATE_TIME)) AND NOT
EXISTS (SELECT 1 FROM ORDER_TEMPLATE t2, ORDER_TEMPLATE t1 WHERE
((t1.TEMPLATE_ID = t2.TEMPLATE_ID) AND (t2.TEMPLATE_ID = t0.TEMPLATE_ID)))
) ORDER BY t0.REPORT_DATE_TIME ASC, t0.TRIP_DATE_TIME ASC
Query: ReadAllQuery(name="Orders.findAllBookedTrips" referenceClass=Orders
sql="SELECT t0.ORDER_ID, t0.BALANCE, t0.CANCELLED, t0.CANCELLED_DATE,
t0.CHANGED_DT, t0.CONFIRMED, t0.CONFIRMED_DATE, t0.CONTRACT_SENT,
t0.CONTRACT_SENT_DATE, t0.CREATED_BY, t0.CREATED_DT, t0.DEPOSIT,
t0.DEPOSIT_PAID, t0.DEPOSIT_PAID_DATE, t0.DISCOUNT, t0.DISCOUNT_RATE,
t0.INTRASTATE, t0.INVOICE_SENT, t0.INVOICE_SENT_DATE, t0.PAID_IN_FULL,
t0.PAID_IN_FULL_DATE, t0.PASSENGERS, t0.QUOTE_SENT, t0.QUOTE_SENT_DATE,
t0.REPORT_DATE_TIME, t0.RETURN_DATE_TIME, t0.TOTAL_COST, t0.TRIP_DATE_TIME,
t0.BANK_FOR_BALANCE_ID, t0.BANK_FOR_DEPOSIT_ID, t0.CUSTOMER_ID,
t0.DETAILS_ID, t0.METHOD_OF_PAYMENT_FOR_BALANCE_ID,
t0.METHOD_OF_PAYMENT_FOR_DEPOSIT_ID, t0.NOTES_ID, t0.ROUTES_ID,
t0.TEMPLATE_ID FROM ORDERS t0 WHERE (((((t0.TRIP_DATE_TIME BETWEEN ? AND ?)
OR (t0.RETURN_DATE_TIME BETWEEN ? AND ?)) OR (? BETWEEN t0.TRIP_DATE_TIME
AND t0.RETURN_DATE_TIME)) OR (? BETWEEN t0.TRIP_DATE_TIME AND
t0.RETURN_DATE_TIME)) AND NOT EXISTS (SELECT ? FROM ORDER_TEMPLATE t2,
ORDER_TEMPLATE t1 WHERE ((t1.TEMPLATE_ID = t2.TEMPLATE_ID) AND
(t2.TEMPLATE_ID = t0.TEMPLATE_ID))) ) ORDER BY t0.REPORT_DATE_TIME ASC,
t0.TRIP_DATE_TIME ASC")
at
org.eclipse.persistence.exceptions.DatabaseException.sqlException(DatabaseException.java:333)
at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:644)
at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:535)
at
org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:1717)
at
org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:566)
at
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:207)
at
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:193)
at
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:264)
at
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:646)
at
org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2611)
at
org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRows(ExpressionQueryMechanism.java:2570)
at
org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:420)
at
org.eclipse.persistence.queries.ObjectLevelReadQuery.executeDatabaseQuery(ObjectLevelReadQuery.java:1081)
at
org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:844)
at
org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1040)
at
org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:392)
at
org.eclipse.persistence.internal.sessions.AbstractSession.internalExecuteQuery(AbstractSession.java:2831)
at
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1516)
at
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1498)
at
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1463)
at
org.eclipse.persistence.internal.jpa.EJBQueryImpl.executeReadQuery(EJBQueryImpl.java:485)
at
org.eclipse.persistence.internal.jpa.EJBQueryImpl.getResultList(EJBQueryImpl.java:742)
at jpa.session.OrdersFacade.filterBy(OrdersFacade.java:284)
at sun.reflect.GeneratedMethodAccessor561.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at
org.apache.openejb.core.interceptor.ReflectionInvocationContext$Invocation.invoke(ReflectionInvocationContext.java:181)
at
org.apache.openejb.core.interceptor.ReflectionInvocationContext.proceed(ReflectionInvocationContext.java:163)
at org.apache.openejb.cdi.CdiInterceptor.invoke(CdiInterceptor.java:128)
at org.apache.openejb.cdi.CdiInterceptor.access$000(CdiInterceptor.java:43)
at org.apache.openejb.cdi.CdiInterceptor$1.call(CdiInterceptor.java:64)
at
org.apache.openejb.cdi.CdiInterceptor.aroundInvoke(CdiInterceptor.java:70)
at sun.reflect.GeneratedMethodAccessor118.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at
org.apache.openejb.core.interceptor.ReflectionInvocationContext$Invocation.invoke(ReflectionInvocationContext.java:181)
at
org.apache.openejb.core.interceptor.ReflectionInvocationContext.proceed(ReflectionInvocationContext.java:163)
at
org.apache.openejb.monitoring.StatsInterceptor.record(StatsInterceptor.java:176)
at
org.apache.openejb.monitoring.StatsInterceptor.invoke(StatsInterceptor.java:95)
at sun.reflect.GeneratedMethodAccessor117.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at
org.apache.openejb.core.interceptor.ReflectionInvocationContext$Invocation.invoke(ReflectionInvocationContext.java:181)
at
org.apache.openejb.core.interceptor.ReflectionInvocationContext.proceed(ReflectionInvocationContext.java:163)
at
org.apache.openejb.core.interceptor.InterceptorStack.invoke(InterceptorStack.java:138)
at
org.apache.openejb.core.stateless.StatelessContainer._invoke(StatelessContainer.java:237)
at
org.apache.openejb.core.stateless.StatelessContainer.invoke(StatelessContainer.java:189)
at
org.apache.openejb.core.ivm.EjbObjectProxyHandler.synchronizedBusinessMethod(EjbObjectProxyHandler.java:253)
at
org.apache.openejb.core.ivm.EjbObjectProxyHandler.businessMethod(EjbObjectProxyHandler.java:248)
at
org.apache.openejb.core.ivm.EjbObjectProxyHandler._invoke(EjbObjectProxyHandler.java:92)
at
org.apache.openejb.core.ivm.BaseEjbProxyHandler.invoke(BaseEjbProxyHandler.java:279)
... 63 more
Caused by: 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.EmbedStatement.executeStatement(Unknown
Source)
at org.apache.derby.impl.jdbc.EmbedStatement.execute(Unknown Source)
at org.apache.derby.impl.jdbc.EmbedStatement.executeQuery(Unknown Source)
at sun.reflect.GeneratedMethodAccessor301.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at
org.apache.tomcat.jdbc.pool.interceptor.StatementDecoratorInterceptor$StatementProxy.invoke(StatementDecoratorInterceptor.java:252)
at $Proxy135.executeQuery(Unknown Source)
at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeSelect(DatabaseAccessor.java:929)
at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:607)
... 112 more
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)
... 128 more
Caused by: ERROR 40XL1: A lock could not be obtained within the time
requested
at org.apache.derby.iapi.error.StandardException.newException(Unknown
Source)
at
org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown
Source)
at
org.apache.derby.impl.services.locks.ConcurrentLockSet.zeroDurationLockObject(Unknown
Source)
at
org.apache.derby.impl.services.locks.AbstractPool.zeroDurationlockObject(Unknown
Source)
at
org.apache.derby.impl.services.locks.ConcurrentPool.zeroDurationlockObject(Unknown
Source)
at
org.apache.derby.impl.store.raw.xact.RowLocking2nohold.lockRecordForRead(Unknown
Source)
at
org.apache.derby.impl.store.access.conglomerate.OpenConglomerate.lockPositionForRead(Unknown
Source)
at
org.apache.derby.impl.store.access.conglomerate.GenericScanController.fetchRows(Unknown
Source)
at org.apache.derby.impl.store.access.heap.HeapScan.fetchNextGroup(Unknown
Source)
at
org.apache.derby.impl.sql.execute.BulkTableScanResultSet.reloadArray(Unknown
Source)
at
org.apache.derby.impl.sql.execute.BulkTableScanResultSet.getNextRowCore(Unknown
Source)
at
org.apache.derby.impl.sql.execute.ProjectRestrictResultSet.getNextRowCore(Unknown
Source)
at
org.apache.derby.impl.sql.execute.ProjectRestrictResultSet.getNextRowCore(Unknown
Source)
at
org.apache.derby.impl.sql.execute.SortResultSet.getRowFromResultSet(Unknown
Source)
at org.apache.derby.impl.sql.execute.SortResultSet.getNextRowFromRS(Unknown
Source)
at org.apache.derby.impl.sql.execute.SortResultSet.loadSorter(Unknown
Source)
at org.apache.derby.impl.sql.execute.SortResultSet.openCore(Unknown Source)
at org.apache.derby.impl.sql.execute.BasicNoPutResultSetImpl.open(Unknown
Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(Unknown
Source)
at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown
Source)
... 122 more
On Tue, Dec 11, 2012 at 2:10 PM, David Blevins <david.blev...@gmail.com>wrote:
> First a tip. Next time the server locks up, immediately do a thread dump.
>
> - http://docs.oracle.com/javase/1.5.0/docs/tooldocs/share/jstack.html
>
> Second, it sounds like this locking issue isn't a "threading" issue, but a
> transaction issue. Accessing all your databases in the same JTA
> transaction is not advised unless you're doing something like withdrawing
> $100 from database A and putting it in database B. This kind of work is
> fine to do, but you want it to be as focused and razor sharp as possible --
> only do it with the understanding you're locking the referenced tables/rows
> on both databases while that transaction is open. This can be tragic if
> pessimistic locking is used, less of a problem with more optimistic locking
> options. These options are all database specific. Again, this kind of
> thing is fine if the task requires it -- there's no other reliable way to
> solve the "transfer data from one database to the next problem" other then
> to enroll them both in a JTA transaction -- but such a thing must be done
> with full understanding of the cost.
>
> What kind of work are you attempting to do with this job that accesses all
> your databases?
>
>
> -David
>
> On Dec 11, 2012, at 8:40 AM, "Howard W. Smith, Jr." <
> smithh032...@gmail.com> wrote:
>
> > Okay, TomEE committers/users, I need your help/advice on this one. Please
> > read what I wrote in the email below.
> >
> > I am considering to use the @Asynchronous on one of the methods on
> > @Stateless EJB to complete this task, but I think I still may need to do
> > something on the Persistence end to avoid locking up the entire app,
> > database, etc...
> >
> > I guess this my first time experiencing a DEADLOCK, but I could be
> wrong. :)
> >
> >
> >
> > On Tue, Dec 11, 2012 at 11:01 AM, Howard W. Smith, Jr. <
> > smithh032...@gmail.com> wrote:
> >
> >> Wow, i'm reading this now, because I just experienced an issue on my
> >> production server that is TomEE 1.5.1 (Tomcat 7.0.34), and the whole
> server
> >> locked up all because I had a @Stateless EJB inserting data into
> multiple
> >> tables in the database, because @Schedule timed event triggered the EJB
> to
> >> check email server for incoming (customer) requests, and it literally
> took
> >> down the server. I was on it as well as few other endusers, and then one
> >> enduser captured a LOCK error and the screen capture (photo/pic) had an
> >> error message that showed a long SQL query with datatable table and
> column
> >> names t0..., t0...
> >>
> >> What I primarily saw was the word 'lock' at the top of that, and we
> >> definitely experienced a lockup. I'm about to check server logs and read
> >> this article.
> >>
> >> The @Stateless EJB had one transaction (entitymanager / persistence
> >> context) that made database updates to multiple tables in the database.
> I
> >> am only using entitymanager.persist(), flush(), and few lookups/queries
> >> during that process.
> >>
> >> But other endusers (including myself) could not do simple queries
> against
> >> the database at all. Most of my queries contain query hints (readonly,
> >> statement caching).
> >>
> >> Also, I never seen this behavior at all, but this is first time I added
> >> @Stateless EJB along with @Schedule that does database updates 'during
> >> business hours'. I thought this would be a no-brainer, but I guess it's
> >> not. Again, the server is TomEE 1.5.1 (tomcat 7.0.34).
> >>
> >> Any advise, then please let me know. Onto reading this post now.
> Thanks. :)
> >>
> >>
> >>
> >> On Tue, Dec 11, 2012 at 10:49 AM, Julien Martin <bal...@gmail.com>
> wrote:
> >>
> >>> Thank you very much for this exhaustive reply Christopher.
> >>>
> >>> 2012/12/11 Christopher Schultz <ch...@christopherschultz.net>
> >>>
> >>>> -----BEGIN PGP SIGNED MESSAGE-----
> >>>> Hash: SHA256
> >>>>
> >>>> Julien,
> >>>>
> >>>> Warning: this is long. Like, André-or-Mark-Eggers long.
> >>>>
> >>>> On 12/11/12 7:30 AM, Julien Martin wrote:
> >>>>> I am in reference to the following blog entry: Blog
> >>>>> entry<
> >>>>
> >>>
> http://blog.springsource.org/2012/05/06/spring-mvc-3-2-preview-introducing-servlet-3-async-support
> >>>>>
> >>>>>
> >>>>>
> >>>> about Spring MVC 3.2 asynchronous support.
> >>>>>
> >>>>> I understand Tomcat uses a thread pool in order to serve http/web
> >>>>> requests. Furthermore, the above article seems to indicate that
> >>>>> Spring MVC asynchronous support relieves Tomcat's thread pool and
> >>>>> allows for better concurrency in the webapp by using background
> >>>>> threads for "heavy-lift" operations.
> >>>>
> >>>> I believe you are misinterpreting what that post has to say. It's not
> >>>> that a "background" thread itself is more efficient, it's that
> >>>> processing that does not need to communicate with the client can be
> >>>> de-coupled from the request-processing thread-pool that exists for
> >>>> that purpose.
> >>>>
> >>>> An example - right from the blog post - will make much more sense than
> >>>> what I wrote above. Let's take the example of sending an email
> >>>> message. First, some assumptions:
> >>>>
> >>>> 1. Sending an email takes a long time (say, 5 seconds)
> >>>> 2. The client does not need confirmation that the email has been sent
> >>>>
> >>>> If your were to write a "classic" servlet, it would look something
> >>>> like this:
> >>>>
> >>>> doPost() {
> >>>> validateOrder();
> >>>>
> >>>> queueOrder();
> >>>>
> >>>> sendOrderConfirmation(); // This is the email
> >>>>
> >>>> response.sendRedirect("/order_complete.jsp");
> >>>> }
> >>>>
> >>>> Let's say that validation takes 500ms, queuing takes 800ms, and
> >>>> emailing (as above) takes 5000ms. That means that the request, from
> >>>> the client perspective, takes 6300ms (6.3 sec). That's a noticeable
> >>> delay.
> >>>>
> >>>> Also, during that whole time, a single request-processing thread (from
> >>>> Tomcat's thread pool) is tied-up, meaning that no other requests can
> >>>> be processed by that same thread.
> >>>>
> >>>> If you have a thread pool of size=1 (foolish, yet instructive), it
> >>>> means you can only process a single transaction every 6.3 seconds.
> >>>>
> >>>> Lets re-write the servlet with a background thread -- no
> >>>> "asynchronous" stuff from the servlet API, but just with a simple
> >>>> background thread:
> >>>>
> >>>> doPost() {
> >>>> validateOrder();
> >>>>
> >>>> queueOrder();
> >>>>
> >>>> (new Thread() {
> >>>> public void run() {
> >>>> sendOrderConfirmation();
> >>>> }
> >>>> }).start();
> >>>>
> >>>> response.sendRedirect("order_complete.jsp");
> >>>> }
> >>>>
> >>>> So, now the email is being sent by a background thread: the response
> >>>> returns to the client after 1.3 seconds which is a significant
> >>>> improvement. Now, we can handle a request once every 1.3 seconds with
> >>>> a request-processing thread-pool of size=1.
> >>>>
> >>>> Note that a better implementation of the above would be to use a
> >>>> thread pool for this sort of thing instead of creating a new thread
> >>>> for every request. This is what Spring provides. It's not that Spring
> >>>> can do a better job of thread management, it's that Tomcat's thread
> >>>> pool is special: it's the only one that can actually dispatch client
> >>>> requests. Off-loading onto another thread pool for background
> >>>> processing means more client requests can be handled with a smaller
> >>>> (or same-sized) pool.
> >>>>
> >>>> Looking above, you might notice that the validateOrder() and
> >>>> queueOrder() processes still take some time (1.3 seconds) to complete,
> >>>> and there is no interaction with the client during that time -- the
> >>>> client is just sitting there waiting for a response. Work is still
> >>>> getting done on the server, of course, but there's no real reason that
> >>>> the request-processing thread has to be the one doing that work: we
> >>>> can delegate the entire thing to a background thread so the
> >>>> request-processor thread can get back to dispatching new requests.
> >>>>
> >>>> This is where servlet 3.0 async comes into play.
> >>>>
> >>>> Let's re-write the servlet as an asynchronous one. I've never actually
> >>>> written one, so I'm sure the details are going to be wrong, but the
> >>>> idea is the same. This time, we'll do everything asynchronously.
> >>>>
> >>>> doPost() {
> >>>> final AsyncContext ctx = request.startAsync();
> >>>>
> >>>> (new Thread() {
> >>>> public void run() {
> >>>> validateOrder();
> >>>> queueOrder();
> >>>> sendOrderConfirmation();
> >>>>
> >>>> ctx.getResponse().sendRedirect("/order_complete.jsp");
> >>>>
> >>>> ctx.complete();
> >>>> }
> >>>> }).start();
> >>>> }
> >>>>
> >>>> So, how what happens? When startAsync is called, an AsyncContext is
> >>>> created and basically the request and response are packaged-up for
> >>>> later use. The doPost method creates a new thread and starts it (or it
> >>>> may start a few ms later), then returns from doPost. At this point,
> >>>> the request-processor thread has only spent a few ms (let's say 5ms)
> >>>> setting up the request and then it goes back into Tomcat's thread-pool
> >>>> and can accept another request. Meanwhile, the "background" thread
> >>>> will process the actual transaction.
> >>>>
> >>>> Let's assume that nothing in the run() method above interacts in any
> >>>> way with the client. In the first example (no async), the client waits
> >>>> the whole time for a response from the server, and the
> >>>> request-processing thread does all the work. So, the client waits 6.3
> >>>> seconds and the request-processing thread is "working" for 6.3
> seconds.
> >>>>
> >>>> In the async example, the client will probably still wait 6.3 seconds,
> >>>> but the request-processing thread is back and ready for more client
> >>>> requests after a tiny amount of time. Of course, the transaction is
> >>>> not complete, yet.
> >>>>
> >>>> The background thread will run and process the transaction, including
> >>>> the 5-second email process. Once the email confirmation has been sent,
> >>>> the background thread "sends" a redirect and completes the async
> >>>> request. I'm not sure of the exact details, here, but either the
> >>>> background thread itself (via getRequest().sendRedirect()) pushes the
> >>>> response back to the client, or Tomcat fetches a request-processing
> >>>> thread from the pool and uses that to do the same thing. I can't see
> >>>> why the background-thread wouldn't do that itself, but it's up to the
> >>>> container to determine who does what.
> >>>>
> >>>> The point is that, when using asynchronous requests, fewer
> >>>> request-processing threads can handle a whole lot of load. In the
> >>>> async example, still with a thread-pool of size=1 and an async-setup
> >>>> time of 5ms, that means that you can handle one client transaction
> >>>> every 5ms. That's much better than every 6.3 seconds, don't you think?
> >>>>
> >>>> (Note that this isn't magic: if your background threads are either
> >>>> limited or your system can't handle the number of transactions you are
> >>>> trying to asynchronously-process, eventually you'll still have
> >>>> everyone waiting 6.3 seconds no matter what).
> >>>>
> >>>> So, a recap of throughput (req/sec) of the above 3 implementations:
> >>>>
> >>>> Standard: .15873
> >>>> Background: .76923
> >>>> Async: 200.00000
> >>>>
> >>>> Using asynchronous dispatching can improve our throughput a huge
> >>>> number of times.
> >>>>
> >>>> It's worth repeating what I said earlier: if your server can't
> >>>> actually handle this much load (200 emails per second, let's say),
> >>>> then using asych isn't going to change anything. Honestly, this trick
> >>>> only works when you have a lot of heterogeneous requests. For example,
> >>>> maybe 10% of your traffic is handling orders as implemented above,
> >>>> while the rest of your traffic is for much smaller sub-500ms-requests.
> >>>> There's probably no reason to convert those short-running requests
> >>>> into asynchronous operations. Only long-running processes with no
> >>>> client interaction make any sense for this. If only 10% of your
> >>>> requests are orders, that means that maybe you can process 20 orders
> >>>> and 190 "small" requests per second. That's much better than, say,
> >>>> waiting 6.3 seconds for a single order and then processing a single
> >>>> short request, then another order and so on.
> >>>>
> >>>> Just remember that once all request-processing threads are tied-up
> >>>> doing something, everyone else waits in line. Asynchronous request
> >>>> dispatching aims to run through the line as quickly as possible. It
> >>>> does *not* improve the processing time of any one transaction.
> >>>>
> >>>> - -chris
> >>>> -----BEGIN PGP SIGNATURE-----
> >>>> Version: GnuPG/MacGPG2 v2.0.17 (Darwin)
> >>>> Comment: GPGTools - http://gpgtools.org
> >>>> Comment: Using GnuPG with undefined - http://www.enigmail.net/
> >>>>
> >>>> iEYEAREIAAYFAlDHTdkACgkQ9CaO5/Lv0PDrNACgsaeHmBzr9RMSFuZX9ksX3g9d
> >>>> bKYAniJzbqRjGBAjwxIYihvcyJYV5rIl
> >>>> =l+ie
> >>>> -----END PGP SIGNATURE-----
> >>>>
> >>>> ---------------------------------------------------------------------
> >>>> To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
> >>>> For additional commands, e-mail: users-h...@tomcat.apache.org
> >>>>
> >>>>
> >>>
> >>
> >>
>
>
