app engine issue for java (using Spring) in production blocking requests

99 views
Skip to first unread message

Jorge Amat

unread,
Sep 6, 2013, 8:37:18 PM9/6/13
to google-a...@googlegroups.com
my website is getting blocked and not working every few time, getting the log I show below. Each time this happens, I have to go to my console, refresh the cache, and change in application settings the Frontend Instance Class from F1 to F2 or F4 to make possible the first loading, and once it´s done, changing back to F1 (which works perfectly after the first request). But after a while, I got again the server error and my website doesn´t work.

  1.  500 61172ms 0kb Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/29.0.1547.66 Safari/537.36
    109.255.25.214 - - [06/Sep/2013:17:31:03 -0700] "GET /blog HTTP/1.1" 500 0 "some url" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/29.0.1547.66 Safari/537.36" "my domain" ms=61172 cpu_ms=44941 loading_request=1 exit_code=104 app_engine_release=1.8.4 instance=00c61b117c83b77e2f32936923fc83b121bc82
  2. I2013-09-06 17:30:09.228
    javax.servlet.ServletContext log: Initializing Spring root WebApplicationContext
  3. I2013-09-06 17:30:45.225
    javax.servlet.ServletContext log: Initializing Spring FrameworkServlet 'mvc-dispatcher'
  4. W2013-09-06 17:31:03.615
    Error for /blog
    com.google.apphosting.runtime.HardDeadlineExceededError: This request (df2ff830a97e2023) started at 2013/09/07 00:30:03.406 UTC and was still executing at 2013/09/07 00:31:03.604 UTC.
    	at org.apache.jsp.WEB_002dINF.jsp.error.error_005fdinamic_jsp._jspService(error_005fdinamic_jsp.java:42)
    	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:97)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    	at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
    	at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:390)
    	at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    	at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
    	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
    	at org.mortbay.jetty.servlet.Dispatcher.forward(Dispatcher.java:327)
    	at org.mortbay.jetty.servlet.Dispatcher.forward(Dispatcher.java:126)
    	at org.springframework.web.servlet.view.InternalResourceView.renderMergedOutputModel(InternalResourceView.java:238)
    	at org.springframework.web.servlet.view.AbstractView.render(AbstractView.java:262)
    	at org.springframework.web.servlet.DispatcherServlet.render(DispatcherServlet.java:1208)
    	at org.springframework.web.servlet.DispatcherServlet.processDispatchResult(DispatcherServlet.java:992)
    	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:939)
    	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
    	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:915)
    	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:804)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
    	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:789)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    	at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
    	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
    	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:90)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.googlecode.objectify.cache.AsyncCacheFilter.doFilter(AsyncCacheFilter.java:59)
    	at com.googlecode.objectify.ObjectifyFilter.doFilter(ObjectifyFilter.java:49)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.google.apphosting.utils.servlet.JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter.java:60)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
    	at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    	at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
    	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
    	at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:266)
    	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    	at org.mortbay.jetty.Server.handle(Server.java:326)
    	at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
    	at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
    	at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
    	at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
    	at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:146)
    	at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(JavaRuntime.java:439)
    	at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:435)
    	at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:442)
    	at com.google.tracing.CurrentContext.runInContext(CurrentContext.java:186)
    	at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:306)
    	at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:298)
    	at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:439)
    	at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(ThreadGroupPool.java:251)
    	at java.lang.Thread.run(Thread.java:722)
    
  5. C2013-09-06 17:31:03.622
    Uncaught exception from servlet
    com.google.apphosting.runtime.HardDeadlineExceededError: This request (df2ff830a97e2023) started at 2013/09/07 00:30:03.406 UTC and was still executing at 2013/09/07 00:31:03.604 UTC.
    	at org.apache.jsp.WEB_002dINF.jsp.error.error_005fdinamic_jsp._jspService(error_005fdinamic_jsp.java:42)
    	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:97)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    	at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
    	at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:390)
    	at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    	at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
    	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
    	at org.mortbay.jetty.servlet.Dispatcher.forward(Dispatcher.java:327)
    	at org.mortbay.jetty.servlet.Dispatcher.forward(Dispatcher.java:126)
    	at org.springframework.web.servlet.view.InternalResourceView.renderMergedOutputModel(InternalResourceView.java:238)
    	at org.springframework.web.servlet.view.AbstractView.render(AbstractView.java:262)
    	at org.springframework.web.servlet.DispatcherServlet.render(DispatcherServlet.java:1208)
    	at org.springframework.web.servlet.DispatcherServlet.processDispatchResult(DispatcherServlet.java:992)
    	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:939)
    	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
    	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:915)
    	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:804)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
    	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:789)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    	at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
    	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
    	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:90)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.googlecode.objectify.cache.AsyncCacheFilter.doFilter(AsyncCacheFilter.java:59)
    	at com.googlecode.objectify.ObjectifyFilter.doFilter(ObjectifyFilter.java:49)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.google.apphosting.utils.servlet.JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter.java:60)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    	at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
    	at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    	at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
    	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
    	at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:266)
    	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    	at org.mortbay.jetty.Server.handle(Server.java:326)
    	at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
    	at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
    	at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
    	at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
    	at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:146)
    	at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(JavaRuntime.java:439)
    	at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:435)
    	at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:442)
    	at com.google.tracing.CurrentContext.runInContext(CurrentContext.java:186)
    	at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:306)
    	at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:298)
    	at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:439)
    	at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(ThreadGroupPool.java:251)
    	at java.lang.Thread.run(Thread.java:722)
    
  6. I2013-09-06 17:31:03.626
    This request caused a new process to be started for your application, and thus caused your application code to be loaded for the first time. This request may thus take longer and use more CPU than a typical request for your application.
  7. W2013-09-06 17:31:03.626
    A problem was encountered with the process that handled this request, causing it to exit. This is likely to cause a new process to be used for the next request to your application. If you see this message frequently, you may be throwing exceptions during the initialization of your application. (Error code 104)

    In my local environment I don´t get this problem. Looks like some kind of issues between the spring framework and the cache used by gae, but no idea what´s going on here... any suggestions please?

Vinny P

unread,
Sep 11, 2013, 10:52:42 PM9/11/13
to google-a...@googlegroups.com
On Fri, Sep 6, 2013 at 7:37 PM, Jorge Amat <jorge....@gmail.com> wrote:
and change in application settings the Frontend Instance Class from F1 to F2 or F4 to make possible the first loading, and once it´s done, changing back to F1 (which works perfectly after the first request). But after a while, I got again the server error and my website doesn´t work.
  1. W2013-09-06 17:31:03.615
    Error for /blog
    com.google.apphosting.runtime.HardDeadlineExceededError: This request (df2ff830a97e2023) started at 2013/09/07 00:30:03.406 UTC and was still executing at 2013/09/07 00:31:03.604 UTC.


In App Engine, frontend requests are limited to 60 seconds. It looks like your application is processing a request that takes more time than that. 

You may need to move or reformat your application logic so it can complete this task in under 60 seconds, or move it to a cron or task queue request which can last up to 10 minutes.

 
 
-----------------
-Vinny P
Technology & Media Advisor
Chicago, IL

App Engine Code Samples: http://www.learntogoogleit.com
 
 


--
You received this message because you are subscribed to the Google Groups "Google App Engine" group.
To unsubscribe from this group and stop receiving emails from it, send an email to google-appengi...@googlegroups.com.
To post to this group, send email to google-a...@googlegroups.com.
Visit this group at http://groups.google.com/group/google-appengine.
For more options, visit https://groups.google.com/groups/opt_out.

timh

unread,
Sep 11, 2013, 10:57:31 PM9/11/13
to google-a...@googlegroups.com
Have enabled warmup requests, that log shows the instance was started as well as trying to process the request.

T
Reply all
Reply to author
Forward
0 new messages