Hi guys,
don't know if this Tapestry, Tynamo JPA or DataNucleus/GAE bug.
In my project I have task queue which triggers tapestry page (its
/job/run/).
The task get runned simultaneously (6 tasks per minute with bucket size =
5.0).
And I'm getting very strange error (stack trace below).
The error happens not on every task run, but on very random basis.
Here's RunJob's onActivate:
public void onActivate() {
String jobKey = request.getParameter("key");
logger.debug("Running job: " + stringToKey(jobKey).toString());
try {
Job job = jobDAO.find(stringToKey(jobKey));
if (job != null) {
application.runJob(job);
}
} catch (Exception e) {
// Prevent to run job once again on failure
logger.warn("Error running job", e);
}
}
Here's the source code of error method:
http://github.com/dmitrygusev/ping-service/blob/master/ping-service/src/dmitrygusev/ping/services/Application.java#L398
This looks like a multithreading issue and I'm actually don't know where to
start investigating.
Thanks in advance.
1.
1. 03-23 08:08AM 16.231
/job/run/?key=agxwaW5nLXNlcnZpY2VyGgsSCFNjaGVkdWxlGLe5KAwLEgNKb2IY7AcM
200 266ms 210cpu_ms 16api_cpu_ms 1kb AppEngine-Google; (+
http://code.google.com/appengine) See
details<https://appengine.google.com/logs/log_detail?app_id=ping-service&version_id=beta.340740221227144786&request_id=000482792EE8B158.CE4C88EF&layout=plain>
0.1.0.2 - - [23/Mar/2010:08:08:16 -0700] "GET
/job/run/?key=agxwaW5nLXNlcnZpY2VyGgsSCFNjaGVkdWxlGLe5KAwLEgNKb2IY7AcM
HTTP/1.1" 200 1306
"http://ping-service.appspot.com/cron/?schedule=every%205%20minutes";
"AppEngine-Google; (+http://code.google.com/appengine)"
"ping-service.appspot.com"
2. D 03-23 08:08AM 16.282
dmitrygusev.ping.pages.job.RunJob onActivate: Running job:
Schedule(662711)/Job(1004)
3. E 03-23 08:08AM 16.471
org.datanucleus.transaction.Transaction commit: Operation commit
failed on resource:
org.datanucleus.store.appengine.datastorexaresou...@11f03e4, error
code UNKNOWN and transaction: [DataNucleus Transaction, ID=Xid=
4. E 03-23 08:08AM 16.472
dmitrygusev.ping.services.Application runJob: Error executing
job Schedule(662711)/Job(1004)
javax.persistence.RollbackException: Transaction failed to commit
at
org.datanucleus.jpa.EntityTransactionImpl.commit(EntityTransactionImpl.java:118)
at
org.datanucleus.store.appengine.jpa.DatastoreEntityTransactionImpl.commit(DatastoreEntityTransactionImpl.java:50)
at
org.tynamo.jpa.internal.JPATransactionManagerImpl.commit(JPATransactionManagerImpl.java:53)
at
$JPATransactionManager_1278b888372.commit($JPATransactionManager_1278b888372.java)
at
$JPATransactionManager_1278b888338.commit($JPATransactionManager_1278b888338.java)
at
org.tynamo.jpa.internal.JPATransactionAdvisorImpl$1.advise(JPATransactionAdvisorImpl.java:46)
at
org.apache.tapestry5.ioc.internal.services.AbstractInvocation.proceed(AbstractInvocation.java:128)
at $JobDAO_1278b888370.update($JobDAO_1278b888370.java)
at $JobDAO_1278b88833e.update($JobDAO_1278b88833e.java)
at dmitrygusev.ping.services.Application.runJob(Application.java:427)
at dmitrygusev.ping.pages.job.RunJob.onActivate(RunJob.java:36)
at
dmitrygusev.ping.pages.job.RunJob$MethodAccess_onActivate_1278b888344.invoke(RunJob$MethodAccess_onActivate_1278b888344.java)
at
org.apache.tapestry5.internal.transform.BaseEventHandlerMethodInvoker.invokeEventHandlerMethod(BaseEventHandlerMethodInvoker.java:52)
at
org.apache.tapestry5.internal.transform.OnEventWorker$4.invokeEventHandlers(OnEventWorker.java:156)
at
org.apache.tapestry5.internal.transform.OnEventWorker$4.advise(OnEventWorker.java:135)
at
org.apache.tapestry5.internal.services.AbstractComponentMethodInvocation.proceed(AbstractComponentMethodInvocation.java:86)
at dmitrygusev.ping.pages.job.RunJob.dispatchComponentEvent(RunJob.java)
at
org.apache.tapestry5.internal.structure.ComponentPageElementImpl.dispatchEvent(ComponentPageElementImpl.java:938)
at
org.apache.tapestry5.internal.structure.ComponentPageElementImpl.triggerContextEvent(ComponentPageElementImpl.java:1126)
at
org.apache.tapestry5.internal.services.PageRenderRequestHandlerImpl.handle(PageRenderRequestHandlerImpl.java:57)
at
org.apache.tapestry5.services.TapestryModule$35.handle(TapestryModule.java:2253)
at
$PageRenderRequestHandler_1278b888327.handle($PageRenderRequestHandler_1278b888327.java)
at
$PageRenderRequestHandler_1278b888322.handle($PageRenderRequestHandler_1278b888322.java)
at
org.apache.tapestry5.internal.services.ComponentRequestHandlerTerminator.handlePageRender(ComponentRequestHandlerTerminator.java:48)
at
org.apache.tapestry5.services.InitializeActivePageName.handlePageRender(InitializeActivePageName.java:47)
at
$ComponentRequestHandler_1278b888323.handlePageRender($ComponentRequestHandler_1278b888323.java)
at
$ComponentRequestHandler_1278b88830e.handlePageRender($ComponentRequestHandler_1278b88830e.java)
at
org.apache.tapestry5.internal.services.PageRenderDispatcher.dispatch(PageRenderDispatcher.java:45)
at $Dispatcher_1278b888314.dispatch($Dispatcher_1278b888314.java)
at $Dispatcher_1278b88830b.dispatch($Dispatcher_1278b88830b.java)
at
org.apache.tapestry5.services.TapestryModule$RequestHandlerTerminator.service(TapestryModule.java:294)
at dmitrygusev.ping.services.AppModule$1.service(AppModule.java:191)
at $RequestFilter_1278b888309.service($RequestFilter_1278b888309.java)
at $RequestHandler_1278b88830c.service($RequestHandler_1278b88830c.java)
at dmitrygusev.ping.services.AppModule$2.service(AppModule.java:243)
at $RequestFilter_1278b88830a.service($RequestFilter_1278b88830a.java)
at $RequestHandler_1278b88830c.service($RequestHandler_1278b88830c.java)
at
org.apache.tapestry5.internal.services.RequestErrorFilter.service(RequestErrorFilter.java:26)
at $RequestHandler_1278b88830c.service($RequestHandler_1278b88830c.java)
at
org.apache.tapestry5.services.TapestryModule$4.service(TapestryModule.java:923)
at $RequestHandler_1278b88830c.service($RequestHandler_1278b88830c.java)
at
org.apache.tapestry5.services.TapestryModule$3.service(TapestryModule.java:913)
at $RequestHandler_1278b88830c.service($RequestHandler_1278b88830c.java)
at
org.apache.tapestry5.internal.services.StaticFilesFilter.service(StaticFilesFilter.java:85)
at $RequestHandler_1278b88830c.service($RequestHandler_1278b88830c.java)
at
org.apache.tapestry5.internal.services.CheckForUpdatesFilter$2.invoke(CheckForUpdatesFilter.java:90)
at
org.apache.tapestry5.internal.services.CheckForUpdatesFilter$2.invoke(CheckForUpdatesFilter.java:80)
at
org.apache.tapestry5.ioc.internal.util.ConcurrentBarrier.withRead(ConcurrentBarrier.java:85)
at
org.apache.tapestry5.internal.services.CheckForUpdatesFilter.service(CheckForUpdatesFilter.java:103)
at $RequestHandler_1278b88830c.service($RequestHandler_1278b88830c.java)
at $RequestHandler_1278b888300.service($RequestHandler_1278b888300.java)
at
org.apache.tapestry5.services.TapestryModule$HttpServletRequestHandlerTerminator.service(TapestryModule.java:245)
at
org.apache.tapestry5.internal.gzip.GZipFilter.service(GZipFilter.java:53)
at
$HttpServletRequestHandler_1278b888302.service($HttpServletRequestHandler_1278b888302.java)
at
org.apache.tapestry5.internal.services.IgnoredPathsFilter.service(IgnoredPathsFilter.java:62)
at
$HttpServletRequestFilter_1278b8882ff.service($HttpServletRequestFilter_1278b8882ff.java)
at
$HttpServletRequestHandler_1278b888302.service($HttpServletRequestHandler_1278b888302.java)
at
org.apache.tapestry5.services.TapestryModule$2.service(TapestryModule.java:866)
at
$HttpServletRequestHandler_1278b888302.service($HttpServletRequestHandler_1278b888302.java)
at
$HttpServletRequestHandler_1278b8882fd.service($HttpServletRequestHandler_1278b8882fd.java)
at org.apache.tapestry5.TapestryFilter.doFilter(TapestryFilter.java:147)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:97)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
at
org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at
org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at
org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:712)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:405)
at
com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:238)
at
org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.Server.handle(Server.java:313)
at
org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506)
at
org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:830)
at
com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381)
at
com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:135)
at
com.google.apphosting.runtime.JavaRuntime.handleRequest(JavaRuntime.java:235)
at
com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:5485)
at
com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:5483)
at
com.google.net.rpc.impl.BlockingApplicationHandler.handleRequest(BlockingApplicationHandler.java:24)
at com.google.net.rpc.impl.RpcUtil.runRpcInApplication(RpcUtil.java:363)
at com.google.net.rpc.impl.Server$2.run(Server.java:837)
at
com.google.tracing.LocalTraceSpanRunnable.run(LocalTraceSpanRunnable.java:56)
at
com.google.tracing.LocalTraceSpanBuilder.internalContinueSpan(LocalTraceSpanBuilder.java:
5. I 03-23 08:08AM 16.478
dmitrygusev.ping.services.AppModule$1 service: Request time: 198 ms
6. W 03-23 08:08AM 16.479
org.apache.tapestry5.ioc.internal.services.PerthreadManagerImpl
cleanup: Error invoking listener
org.tynamo.jpa.internal.jpatransactionmanageri...@808e07: Transaction
is not active. You need to define a transaction around this
java.lang.IllegalStateException: Transaction is not active. You
need to define a transaction around this
at
org.datanucleus.jpa.EntityTransactionImpl.assertActive(EntityTransactionImpl.java:211)
at
org.datanucleus.jpa.EntityTransactionImpl.rollback(EntityTransactionImpl.java:137)
at
org.datanucleus.store.appengine.jpa.DatastoreEntityTransactionImpl.rollback(DatastoreEntityTransactionImpl.java:65)
at
org.tynamo.jpa.internal.JPATransactionManagerImpl.threadDidCleanup(JPATransactionManagerImpl.java:69)
at
org.apache.tapestry5.ioc.internal.services.PerthreadManagerImpl.cleanup(PerthreadManagerImpl.java:106)
at
org.apache.tapestry5.ioc.internal.RegistryImpl.cleanupThread(RegistryImpl.java:388)
at
org.apache.tapestry5.ioc.internal.RegistryWrapper.cleanupThread(RegistryWrapper.java:36)
at org.apache.tapestry5.TapestryFilter.doFilter(TapestryFilter.java:155)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:97)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at
org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
at
org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at
org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at
org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:712)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:405)
at
com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:238)
at
org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.Server.handle(Server.java:313)
at
org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506)
at
org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:830)
at
com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381)
at
com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:135)
at
com.google.apphosting.runtime.JavaRuntime.handleRequest(JavaRuntime.java:235)
at
com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:5485)
at
com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:5483)
at
com.google.net.rpc.impl.BlockingApplicationHandler.handleRequest(BlockingApplicationHandler.java:24)
at com.google.net.rpc.impl.RpcUtil.runRpcInApplication(RpcUtil.java:363)
at com.google.net.rpc.impl.Server$2.run(Server.java:837)
at
com.google.tracing.LocalTraceSpanRunnable.run(LocalTraceSpanRunnable.java:56)
at
com.google.tracing.LocalTraceSpanBuilder.internalContinueSpan(LocalTraceSpanBuilder.java:536)
at com.google.net.rpc.impl.Server.startRpc(Server.java:792)
at com.google.net.rpc.impl.Server.processRequest(Server.java:367)
at
com.google.net.rpc.impl.ServerConnection.messageReceived(ServerConnection.java:448)
at
com.google.net.rpc.impl.RpcConnection.parseMessages(RpcConnection.java:319)
at
com.google.net.rpc.impl.RpcConnection.dataReceived(RpcConnection.java:290)
at com.google.net.async.Connection.handleReadEvent(Connection.java:474)
at
com.google.net.async.EventDispatcher.processNetworkEvents(EventDispatcher.java:774)
at
com.google.net.async.EventDispatcher.internalLoop(EventDispatcher.java:205)
at com.google.net.async.EventDispatcher.loop(EventDispatcher.java:101)
at
com.google.net.rpc.RpcService.runUntilServerShutdown(RpcService.java:251)
at
com.google.apphosting.runtime.JavaRuntime$RpcRunnable.run(JavaRuntime.java:394)
at java.lang.Thread.run(Unknown Source)
--
Dmitry Gusev
AnjLab Team
http://anjlab.com
