AppEngine Plugin

app engine: slow grails initialization causes DeadlineExceededExceptions very frequently

Details

  • Type: Improvement Improvement
  • Status: Open Open
  • Priority: Blocker Blocker
  • Resolution: Unresolved
  • Affects Version/s: None
  • Fix Version/s: None
  • Component/s: None
  • Labels:
    None
  • Environment:
    grails 1.1.2 app-engine-0.8.5 gorm-jpa-0.6

Description

The issue is outlined here by Google:

http://googleappengine.blogspot.com/2009/12/request-performance-in-java.html?utm_source=feedburner&utm_medium=feed&utm_campaign=Feed%3A+GoogleAppEngineBlog+%28Google+App+Engine+Blog%29&utm_content=Google+Reader

If an app is idle app engine removes it and will spin up a new server when a request comes in for it. This causes DeadlineExceededExceptions almost all the time. The grails app must start up in under 30 seconds or app engine will throw a big ugly exception. I'm not sure what can be done. Maybe lazy loading things when needed instead of loading them upfront at startup?

This is a show stopper for using grails on appEngine in a production environment.

Maybe I am missing some "precompile" or "startupFaster" flag?

If anybody has any suggestions I'd love to hear them? (grails + appengine == so much goodness)

Activity

Hide
justin friedl added a comment -

Here's the exception app engine throws:

org.codehaus.groovy.grails.web.mapping.exceptions.UrlMappingException: Error mapping onto view [/index]: This request (4dcbead9a0750077) started at 2009/12/08 08:12:41.312 UTC and was still executing at 2009/12/08 08:13:09.892 UTC.
at org.codehaus.groovy.grails.web.mapping.filter.UrlMappingsFilter.renderViewForUrlMappingInfo(UrlMappingsFilter.java:253)
at org.codehaus.groovy.grails.web.mapping.filter.UrlMappingsFilter.doFilterInternal(UrlMappingsFilter.java:188)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.codehaus.groovy.grails.web.sitemesh.GrailsPageFilter.obtainContent(GrailsPageFilter.java:221)
at org.codehaus.groovy.grails.web.sitemesh.GrailsPageFilter.doFilter(GrailsPageFilter.java:126)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.codehaus.groovy.grails.web.servlet.filter.GrailsReloadServletFilter.doFilterInternal(GrailsReloadServletFilter.java:101)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.codehaus.groovy.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:65)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:96)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:236)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167)
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:139)
at com.google.apphosting.runtime.JavaRuntime.handleRequest(JavaRuntime.java:239)
at com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:5235)
at com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:5233)
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:838)
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:793)
at com.google.net.rpc.impl.Server.processRequest(Server.java:368)
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:466)
at com.google.net.async.EventDispatcher.processNetworkEvents(EventDispatcher.java:759)
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:396)
at java.lang.Thread.run(Unknown Source)
Caused by: com.google.apphosting.api.DeadlineExceededException: This request (4dcbead9a0750077) started at 2009/12/08 08:12:41.312 UTC and was still executing at 2009/12/08 08:13:09.892 UTC.
at groovyjarjarasm.asm.MethodWriter.visitLabel(Unknown Source)
at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:238)
at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
... 21 more

Show
justin friedl added a comment - Here's the exception app engine throws: org.codehaus.groovy.grails.web.mapping.exceptions.UrlMappingException: Error mapping onto view [/index]: This request (4dcbead9a0750077) started at 2009/12/08 08:12:41.312 UTC and was still executing at 2009/12/08 08:13:09.892 UTC. at org.codehaus.groovy.grails.web.mapping.filter.UrlMappingsFilter.renderViewForUrlMappingInfo(UrlMappingsFilter.java:253) at org.codehaus.groovy.grails.web.mapping.filter.UrlMappingsFilter.doFilterInternal(UrlMappingsFilter.java:188) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084) at org.codehaus.groovy.grails.web.sitemesh.GrailsPageFilter.obtainContent(GrailsPageFilter.java:221) at org.codehaus.groovy.grails.web.sitemesh.GrailsPageFilter.doFilter(GrailsPageFilter.java:126) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084) at org.codehaus.groovy.grails.web.servlet.filter.GrailsReloadServletFilter.doFilterInternal(GrailsReloadServletFilter.java:101) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084) at org.codehaus.groovy.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:65) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:96) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:236) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167) 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:139) at com.google.apphosting.runtime.JavaRuntime.handleRequest(JavaRuntime.java:239) at com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:5235) at com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:5233) 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:838) 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:793) at com.google.net.rpc.impl.Server.processRequest(Server.java:368) 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:466) at com.google.net.async.EventDispatcher.processNetworkEvents(EventDispatcher.java:759) 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:396) at java.lang.Thread.run(Unknown Source) Caused by: com.google.apphosting.api.DeadlineExceededException: This request (4dcbead9a0750077) started at 2009/12/08 08:12:41.312 UTC and was still executing at 2009/12/08 08:13:09.892 UTC. at groovyjarjarasm.asm.MethodWriter.visitLabel(Unknown Source) at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35) at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43) at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:238) at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76) ... 21 more
Hide
justin friedl added a comment -

This happens every time. This is the number 1 app-engine bug that will prevent people from using it. Please, please, please help. I know it's not a grails bug as server start up time should not be an issue, but google app engine makes it that way, so please, please, please help. thanks!

Show
justin friedl added a comment - This happens every time. This is the number 1 app-engine bug that will prevent people from using it. Please, please, please help. I know it's not a grails bug as server start up time should not be an issue, but google app engine makes it that way, so please, please, please help. thanks!
Hide
Keng Jungwa added a comment -

I got the exact same problem as Justin's with grails 1.2.0. Please please please help. Thanks!

Show
Keng Jungwa added a comment - I got the exact same problem as Justin's with grails 1.2.0. Please please please help. Thanks!
Hide
Graeme Rocher added a comment -

We are working on a solution with Google but it is going to take time as there are language and framework level changes required to optimize load times

Show
Graeme Rocher added a comment - We are working on a solution with Google but it is going to take time as there are language and framework level changes required to optimize load times
Hide
Felipe Rodrigues added a comment -

This makes app engine unusable for real apps in grails.

Show
Felipe Rodrigues added a comment - This makes app engine unusable for real apps in grails.
Hide
Stephan Linkel added a comment -

Is there any other grails version working on appengine without these problems?
I thought, i already read about grails apps running on appengine.

Show
Stephan Linkel added a comment - Is there any other grails version working on appengine without these problems? I thought, i already read about grails apps running on appengine.
Hide
Pelle Poluha added a comment -

Graeme, what are the prospects of this being fixed? As for now, Grails really is unusable on GAE since the applications seem to be unloaded within a few minutes of passivity. Fixing this must be a big problem as it would (perhaps) require GAE to have Grails preloaded.

Show
Pelle Poluha added a comment - Graeme, what are the prospects of this being fixed? As for now, Grails really is unusable on GAE since the applications seem to be unloaded within a few minutes of passivity. Fixing this must be a big problem as it would (perhaps) require GAE to have Grails preloaded.
Hide
Eduardo Leiva added a comment -

I arrived here with the the exact same problem. Any news? Thanks Graemme.

Show
Eduardo Leiva added a comment - I arrived here with the the exact same problem. Any news? Thanks Graemme.
Hide
Sebastien Pouillet added a comment -

From Graeme's twitter (http://twitter.com/graemerocher) :

Starting some investigative work to optimize load times for #grails on #appengine

Sounds like it

Show
Sebastien Pouillet added a comment - From Graeme's twitter (http://twitter.com/graemerocher) :
Starting some investigative work to optimize load times for #grails on #appengine
Sounds like it
Hide
Felipe Rodrigues added a comment - - edited

Meanwhile, the solution it having a script or cron job to ping the app every 30 seconds. This makes the app more usable on app engine and is a problem for every single java framework that has a considerable load time.

Here is mine. It pings every 30s.
http://gist.github.com/331403

[]'s

Felipe

Show
Felipe Rodrigues added a comment - - edited Meanwhile, the solution it having a script or cron job to ping the app every 30 seconds. This makes the app more usable on app engine and is a problem for every single java framework that has a considerable load time. Here is mine. It pings every 30s. http://gist.github.com/331403 []'s Felipe
Hide
Pelle Poluha added a comment -

Wouldn't the easiest way be to define a cron job in AppEngine? Like this:

<cronentries>
<cron>
<url>/</url>
<description>Ping the sajt to keep it alive</description>
<schedule>every 1 minutes</schedule>
</cron>
</cronentries>

But perhaps Google won't like it?

Show
Pelle Poluha added a comment - Wouldn't the easiest way be to define a cron job in AppEngine? Like this: <cronentries> <cron> <url>/</url> <description>Ping the sajt to keep it alive</description> <schedule>every 1 minutes</schedule> </cron> </cronentries> But perhaps Google won't like it?
Hide
Felipe Rodrigues added a comment - - edited

Pelle,

That could work too, but didn't work for me. The problem is a cron job smaller schedule is every minute. Turns out that 1 minute is enough idle time to google put the JVM to sleep.
The code on gist ping the app every 30s and it is much better, but you can try the cron job and let us know if it works for you.

PS: I know I mentioned 1 minute before, so I just edited my previous comment.

Show
Felipe Rodrigues added a comment - - edited Pelle, That could work too, but didn't work for me. The problem is a cron job smaller schedule is every minute. Turns out that 1 minute is enough idle time to google put the JVM to sleep. The code on gist ping the app every 30s and it is much better, but you can try the cron job and let us know if it works for you. PS: I know I mentioned 1 minute before, so I just edited my previous comment.
Hide
Graeme Rocher added a comment -

I've put several optimizations into Grails 1.3 for startup time improvements and on Tomcat I'm seeing Grails startup in 7-10 seconds. Unfortunately this doesn't translate to GAE as on app engine I am still seeing the hard limit exceeded exceptions. We're in touch with Google over the problem, and hope to have a solution at some point

Show
Graeme Rocher added a comment - I've put several optimizations into Grails 1.3 for startup time improvements and on Tomcat I'm seeing Grails startup in 7-10 seconds. Unfortunately this doesn't translate to GAE as on app engine I am still seeing the hard limit exceeded exceptions. We're in touch with Google over the problem, and hope to have a solution at some point
Hide
Gavin Aiken added a comment -

Thanks for looking into this Graeme, I really appreciate all your hard work. Grails + GAE will make web dev so much easier but for the time being my lovely app is only available @ localhost.

Show
Gavin Aiken added a comment - Thanks for looking into this Graeme, I really appreciate all your hard work. Grails + GAE will make web dev so much easier but for the time being my lovely app is only available @ localhost.
Hide
Pascal Voitot added a comment -

Hello guys,
I have exactly the same problem as anyone and here is my experience and questions.
I have performed some tests with Grails+GAE:

  • I create a raw grails project (the simpliest possible project with nothing in it) and I install it in GAE and I try to access it. Result:
    • 1st connection : 500 Error: Server Error
    • 2nd connection : I can access the site and it works
    • Wait a few minutes and I have to begin again from 0
  • I add 1Domain/1Controller/1Service and one plugin such as CookiePlugin.
    • 1st connection : 500 Error: the famous DeadLineExceededException
    • 2nd connection or 3rd sometimes : I can access the site and it works
    • Wait a few minutes and I have to begin again from 0

If I add more plugins or classes, it won't start at all even if I insist a lot!

Ok, this is what everyone can see...

Graeme, I would like to ask 2things:

  • Could you give some clue concerning your optimizations in grails startup to make it start quicker?
    I've been looking at the code and everything (appContext->beans+classloaders+classes+artefacts->listeners+filters+servlets) need to be initialized before being able to treat any webrequest and it's quite long to do that for sure. I thought about something such as Spring Lazy loading to make everything load when it's required and not before so that GAE startup is not monolithic. It could allow loading and instantiating things downstream but there are so many inter-dependent artefacts requiring beforehand initialization that I'm not sure it could help anyway!
  • What kind of optimizations Google envisions? Will it be a "structural" evolution that makes Java framework in appengine viable (because I know our problems are reported by other people using Java in GAE)? Or will it be an evolution in Grails to make it GAE-compliant? And will it appear in days, weeks, years?

If there are some tracks to follow immediately, I could help a bit because I feel like in jail due to this ignominious limitation

Show
Pascal Voitot added a comment - Hello guys, I have exactly the same problem as anyone and here is my experience and questions. I have performed some tests with Grails+GAE:
  • I create a raw grails project (the simpliest possible project with nothing in it) and I install it in GAE and I try to access it. Result:
    • 1st connection : 500 Error: Server Error
    • 2nd connection : I can access the site and it works
    • Wait a few minutes and I have to begin again from 0
  • I add 1Domain/1Controller/1Service and one plugin such as CookiePlugin.
    • 1st connection : 500 Error: the famous DeadLineExceededException
    • 2nd connection or 3rd sometimes : I can access the site and it works
    • Wait a few minutes and I have to begin again from 0
If I add more plugins or classes, it won't start at all even if I insist a lot! Ok, this is what everyone can see... Graeme, I would like to ask 2things:
  • Could you give some clue concerning your optimizations in grails startup to make it start quicker? I've been looking at the code and everything (appContext->beans+classloaders+classes+artefacts->listeners+filters+servlets) need to be initialized before being able to treat any webrequest and it's quite long to do that for sure. I thought about something such as Spring Lazy loading to make everything load when it's required and not before so that GAE startup is not monolithic. It could allow loading and instantiating things downstream but there are so many inter-dependent artefacts requiring beforehand initialization that I'm not sure it could help anyway!
  • What kind of optimizations Google envisions? Will it be a "structural" evolution that makes Java framework in appengine viable (because I know our problems are reported by other people using Java in GAE)? Or will it be an evolution in Grails to make it GAE-compliant? And will it appear in days, weeks, years?
If there are some tracks to follow immediately, I could help a bit because I feel like in jail due to this ignominious limitation

People

Vote (25)
Watch (28)

Dates

  • Created:
    Updated: