ninja-appengine
ninja-appengine copied to clipboard
ninjaframework
Start time
Hi,
Just tried to deploy an application on GAE and the load time is very slow. 9s I have an Exception, that can explain start time ?
thx
Full trace :
2013-04-09 14:05:28.277 / 200 9225ms 0kb Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_3) AppleWebKit/537.31 (KHTML, like Gecko) Chrome/26.0.1410.43 Safari/537.31
5.48.232.156 - - [09/Apr/2013:05:05:28 -0700] "GET / HTTP/1.1" 200 224 - "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_3) AppleWebKit/537.31 (KHTML, like Gecko) Chrome/26.0.1410.43 Safari/537.31" "1.testbetw.appspot.com" ms=9225 cpu_ms=5070 cpm_usd=0.000025 loading_request=1 instance=00c61b117c9b676bc5d77a7517e47f1f8d159b03
I 2013-04-09 14:05:23.185
com.google.inject.internal.util.$FinalizableReferenceQueue$SystemLoader loadFinalizer: Not allowed to access system class loader.
I 2013-04-09 14:05:23.192
com.google.inject.internal.util.$FinalizableReferenceQueue
\ \ | |\ \ | | / _ \
/ | | |/ | \ | |/ /\ \
/ | \ / | /| / |
__| /****| /__________| /
web/framework / /
I 2013-04-09 14:05:25.883
[s~testbetw/1.366550021591110251].
I 2013-04-09 14:05:26.162
[s~testbetw/1.366550021591110251].
I 2013-04-09 14:05:26.567
[s~testbetw/1.366550021591110251].
I 2013-04-09 14:05:28.277 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.
how did you deploy?
This looks like an issue you'll get when using mvn clean install appengine:update
I bet the issue goes away if you use mvn clean appengine:update . true?
ra
On Tue, Apr 9, 2013 at 2:14 PM, Samuel Liard [email protected]:
Hi,
Just tried to deploy an application on GAE and the load time is very slow. 9s I have an Exception, that can explain start time ?
thx
Full trace :
2013-04-09 14:05:28.277 / 200 9225ms 0kb Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_3) AppleWebKit/537.31 (KHTML, like Gecko) Chrome/26.0.1410.43 Safari/537.31 5.48.232.156 - - [09/Apr/2013:05:05:28 -0700] "GET / HTTP/1.1" 200 224 - "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_3) AppleWebKit/537.31 (KHTML, like Gecko) Chrome/26.0.1410.43 Safari/537.31" "1.testbetw.appspot.com" ms=9225 cpu_ms=5070 cpm_usd=0.000025 loading_request=1 instance=00c61b117c9b676bc5d77a7517e47f1f8d159b03 I 2013-04-09 14:05:23.185 com.google.inject.internal.util.$FinalizableReferenceQueue$SystemLoader loadFinalizer: Not allowed to access system class loader. I 2013-04-09 14:05:23.192 com.google.inject.internal.util.$FinalizableReferenceQueue : Failed to start reference finalizer thread. Reference cleanup will only occur when new references are created. java.lang.reflect.InvocationTargetException at com.google.appengine.runtime.Request.process-c3a2e572f96e3caa(Request.java) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:43) at com.google.inject.internal.util.$FinalizableReferenceQueue.(FinalizableReferenceQueue.java:124) at com.google.inject.internal.util.$MapMaker$QueueHolder.(MapMaker.java:787) at com.google.inject.internal.util.$MapMaker$WeakEntry.(MapMaker.java:946) at com.google.inject.internal.util.$MapMaker$Strength$1.newEntry(MapMaker.java:312) at com.google.inject.internal.util.$MapMaker$StrategyImpl.newEntry(MapMaker.java:498) at com.google.inject.internal.util.$MapMaker$StrategyImpl.newEntry(MapMaker.java:419) at com.google.inject.internal.util.$CustomConcurrentHashMap$ComputingImpl.get(CustomConcurrentHashMap.java:2029) at com.google.inject.internal.Annotations$AnnotationChecker.hasAnnotations(Annotations.java:116) at com.google.inject.internal.Annotations.isBindingAnnotation(Annotations.java:180) at com.google.inject.internal.Annotations.findBindingAnnotation(Annotations.java:161) at com.google.inject.internal.Annotations.getKey(Annotations.java:147) at com.google.inject.spi.InjectionPoint.(InjectionPoint.java:92) at com.google.inject.spi.InjectionPoint$InjectableField.toInjectionPoint(InjectionPoint.java:438) at com.google.inject.spi.InjectionPoint.getInjectionPoints(InjectionPoint.java:723) at com.google.inject.spi.InjectionPoint.forInstanceMethodsAndFields(InjectionPoint.java:356) at com.google.inject.spi.InjectionPoint.forInstanceMethodsAndFields(InjectionPoint.java:375) at com.google.inject.internal.BindingBuilder.toInstance(BindingBuilder.java:82) at ninja.scheduler.SchedulerSupport$1.configure(SchedulerSupport.java:81) at com.google.inject.AbstractModule.configure(AbstractModule.java:59) at com.google.inject.spi.Elements$RecordingBinder.install(Elements.java:223) at com.google.inject.spi.Elements.getElements(Elements.java:101) at com.google.inject.internal.InjectorShell$Builder.build(InjectorShell.java:133) at com.google.inject.internal.InternalInjectorCreator.build(InternalInjectorCreator.java:103) at com.google.inject.Guice.createInjector(Guice.java:95) at com.google.inject.Guice.createInjector(Guice.java:72) at ninja.servlet.NinjaBootstap.initInjector(NinjaBootstap.java:141) at ninja.servlet.NinjaBootstap.boot(NinjaBootstap.java:69) at ninja.servlet.NinjaServletListener.getInjector(NinjaServletListener.java:52) at com.google.inject.servlet.GuiceServletContextListener.contextInitialized(GuiceServletContextListener.java:45) at ninja.servlet.NinjaServletListener.contextInitialized(NinjaServletListener.java:40) at org.mortbay.jetty.handler.ContextHandler.startContext(ContextHandler.java:548) at org.mortbay.jetty.servlet.Context.startContext(Context.java:136) at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1250) at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:517) at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:467) at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50) at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:480) at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:487) at com.google.tracing.TraceContext.runInContext(TraceContext.java:774) at com.google.tracing.TraceContext$DoInTraceContext.runInContext(TraceContext.java:751) at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:342) at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:334) at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:484) at java.lang.Thread.run(Thread.java:679) Caused by: java.security.AccessControlException: access denied (java.lang.RuntimePermission modifyThreadGroup) at java.security.AccessControlContext.checkPermission(AccessControlContext.java:355) at java.security.AccessController.checkPermission(AccessController.java:567) at java.lang.SecurityManager.checkPermission(SecurityManager.java:549) at java.lang.ThreadGroup.checkAccess(ThreadGroup.java:315) at java.lang.Thread.init(Thread.java:353) at java.lang.Thread.(Thread.java:479) at com.google.inject.internal.util.$Finalizer.(Finalizer.java:92) at com.google.inject.internal.util.$Finalizer.startFinalizer(Finalizer.java:81) ... 48 more I 2013-04-09 14:05:25.883 [s~testbetw/1.366550021591110251].: _______ .___ _______ ____. _____
\ \ | |\ \ | | / _ \
/ | | |/ | \ | |/ /\
/ | \ / | /__| / |
| /|__ /______| / web/framework / /I 2013-04-09 14:05:25.883 [s~testbetw/1.366550021591110251].:
I 2013-04-09 14:05:26.162 [s~testbetw/1.366550021591110251].: 12:05:26.101 [Request C854F190] INFO ninja.lifecycle.LifecycleServiceImpl - Starting Ninja application...
I 2013-04-09 14:05:26.567 [s~testbetw/1.366550021591110251].: 12:05:26.567 [Request C854F190] INFO ninja.lifecycle.LifecycleServiceImpl - Ninja application started in 471ms
I 2013-04-09 14:05:28.277 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.
— Reply to this email directly or view it on GitHubhttps://github.com/reyez/ninja-appengine/issues/4 .
inc: http://ars-machina.raphaelbauer.com tech: http://ars-codia.raphaelbauer.com web: http://raphaelbauer.com
Yes I run : mvn clean install gae:deploy -Pdeployment (like explain on documentation)
But I have the same error with "mvn clean gae:deploy -Pdeployment"
and appengine:update don't work (No plugin found for prefix 'appengine') not declare in pom.xml
Edit : ok I use appengine plugin. but "mvn clean appengine:update -Pdeployment" make the same error
On Tue, Apr 9, 2013 at 2:24 PM, Samuel Liard [email protected]:
Yes I run : mvn clean install gae:deploy -Pdeployment (like explain on documentation)
But I have the same error with "mvn clean gae:deploy -Pdeployment"
and appengine:update don't work (No plugin found for prefix 'appengine') not declare in pom.xml
Hmm. That is strange. I got several applications up and runing on App Engine.
Can you post all logs?
Best,
Raphael
You have all logs :)
And for other application what is the average load time ? Because I remove spring MVC for that reason :/
2013-04-09 14:29:19.139 / 200 12248ms 0kb Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_3) AppleWebKit/537.31 (KHTML, like Gecko) Chrome/26.0.1410.43 Safari/537.31
109.190.56.9 - - [09/Apr/2013:05:29:19 -0700] "GET / HTTP/1.1" 200 224 - "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_3) AppleWebKit/537.31 (KHTML, like Gecko) Chrome/26.0.1410.43 Safari/537.31" "1.testbetw.appspot.com" ms=12248 cpu_ms=7842 cpm_usd=0.000025 loading_request=1 instance=00c61b117cf99392ae2a97cf792eb80c1e033f84
I 2013-04-09 14:29:10.823
com.google.inject.internal.util.$FinalizableReferenceQueue$SystemLoader loadFinalizer: Not allowed to access system class loader.
I 2013-04-09 14:29:10.831
com.google.inject.internal.util.$FinalizableReferenceQueue
\ \ | |\ \ | | / _ \
/ | | |/ | \ | |/ /\ \
/ | \ / | /| / |
__| /****| /__________| /
web/framework / /
I 2013-04-09 14:29:15.266
[s~testbetw/1.366551444915156870].
I 2013-04-09 14:29:15.537
[s~testbetw/1.366551444915156870].
I 2013-04-09 14:29:16.320
[s~testbetw/1.366551444915156870].
I 2013-04-09 14:29:19.139 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.
One difference with demo. I add logback :
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-core</artifactId>
<version>0.9.27</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.6.2</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>0.9.27</version>
</dependency>
To correct error :
[s~testbetw/1.366551506100638944].
But error is still here even without logback : access denied (java.lang.RuntimePermission modifyThreadGroup)
On Tue, Apr 9, 2013 at 2:32 PM, Samuel Liard [email protected]:
One difference with demo. I add logback :
<dependency> <groupId>ch.qos.logback</groupId> <artifactId>logback-core</artifactId> <version>0.9.27</version> </dependency> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-api</artifactId> <version>1.6.2</version> </dependency> <dependency> <groupId>ch.qos.logback</groupId> <artifactId>logback-classic</artifactId> <version>0.9.27</version> </dependency>— Reply to this email directly or view it on GitHubhttps://github.com/reyez/ninja-appengine/issues/4#issuecomment-16109663 .
Hi Sam,
I tried again, but cannot reproduce your issue. I just deployed my app via: mvn clean install gae:deploy
and it works fine...
this is the appengine module i am using:
<dependency>
<groupId>org.ninjaframework</groupId>
<artifactId>ninja-appengine-module</artifactId>
<version>1.0.1</version>
</dependency>
Maybe you can deploy to a new app version and restart the app. And maybe you can spot some more meaningful logs. Usually you get more than 1 log. And usually one of the many logs you get contains a clue where the real problem is...
The startup time of Ninja is limited (I guess) mostly by Guice. And guice is quite fast. Having said that I did not do any benchmarking - but I did either not run into any issues here...
Best,
Raphael
On Tue, Apr 9, 2013 at 5:07 PM, ludoch [email protected] wrote:
Worth looking at dagger as well? http://square.github.io/dagger/
imho Guice is lightweight enough :) And it is for sure not the problem you are facing.
Thanks for the zipped project - I'll have a look the next days :)
Best,
Raphael
On Tue, Apr 9, 2013 at 8:01 PM, Raphael André Bauer [email protected] wrote:
On Tue, Apr 9, 2013 at 5:07 PM, ludoch [email protected] wrote:
Worth looking at dagger as well? http://square.github.io/dagger/
imho Guice is lightweight enough :) And it is for sure not the problem you are facing.
Thanks for the zipped project - I'll have a look the next days :)
Hi Samuel,
I had a look and unfortunately cannot reproduce your issue.
I simply imported your project into eclipse, changed my app id and called: mvn appengine:update -Pdeployment
you can see your running app here: http://1.raplayground.appspot.com/
Best,
Raphael
My empty app works, it's not the problem :) The main problem is first loading time
And in GAE log we have Info logs with exception : com.google.inject.internal.util.$FinalizableReferenceQueue$SystemLoader loadFinalizer: Not allowed to access system class loader. Caused by: java.security.AccessControlException: access denied (java.lang.RuntimePermission modifyThreadGroup)
And maybe it's the reason of 13s starting time... You don't have this log on your server ?
Samuel
2013/4/10 Raphael A. Bauer [email protected]:
On Tue, Apr 9, 2013 at 8:01 PM, Raphael André Bauer [email protected] wrote:
On Tue, Apr 9, 2013 at 5:07 PM, ludoch [email protected] wrote:
Worth looking at dagger as well? http://square.github.io/dagger/
imho Guice is lightweight enough :) And it is for sure not the problem you are facing.
Thanks for the zipped project - I'll have a look the next days :)
Hi Samuel,
I had a look and unfortunately cannot reproduce your issue.
I simply imported your project into eclipse, changed my app id and called: mvn appengine:update -Pdeployment
you can see your running app here: http://1.raplayground.appspot.com/
Best,
Raphael
— Reply to this email directly or view it on GitHub.
Known guice log entry. Very annoying but has no impact: https://code.google.com/p/google-guice/wiki/GoogleAppEngine I wish Guice guys can fix it. Will try to reach them.
On Wed, Apr 10, 2013 at 4:09 PM, Samuel Liard [email protected]:
My empty app works, it's not the problem :) The main problem is first loading time
And in GAE log we have Info logs with exception : com.google.inject.internal.util.$FinalizableReferenceQueue$SystemLoader loadFinalizer: Not allowed to access system class loader. Caused by: java.security.AccessControlException: access denied (java.lang.RuntimePermission modifyThreadGroup)
And maybe it's the reason of 13s starting time... You don't have this log on your server ?
No. That is just an info message saying that guice uses a non thread based approach to clean references because App Engine is too restrictive. Nothing to worry about.
And for sure not the reason for 13s startup time :)
You have of course take into account that initial loading requests can be really slow. How big (in terms of war size) is the application where you are experiencing that startup time?
Best,
Raphael
Startup time is a big problem with GAE due to a bug with idle instance.
My experience : http://stackoverflow.com/questions/12396306/why-a-client-create-new-instance-on-gae-just-after-a-warmup-request Bug report : https://code.google.com/p/googleappengine/issues/detail?id=7865
Hope that ludoch work on it :)
So we have to work to have the minimum startup time. In other case some client have 13s of loading page :( It's the reason why I search for something more lightweight that spring. But for the moment, ninja and spring have the same startup time...
On Wed, Apr 10, 2013 at 4:34 PM, Samuel Liard [email protected]:
Startup time is a big problem with GAE due to a bug with idle instance.
My experience :
http://stackoverflow.com/questions/12396306/why-a-client-create-new-instance-on-gae-just-after-a-warmup-request Bug report : https://code.google.com/p/googleappengine/issues/detail?id=7865
Hope that ludoch work on it :)
So we have to work to have the minimum startup time. In other case some client have 13s of loading page :( It's the reason why I search for something more lightweight that spring. But for the moment, ninja and spring have the same startup time...
What startup time does an empty or minimal war project have?
You have to benchmark that against the "minimal" spring and ninja framework. I bet that Ninja's startup time is not really slower than an empty war project (with an equal amount of external libraries) You also have to take into account that starting the VM and unzipping your war on GAE's node will take some time.
Another "trick" you can do is: Schedule a task that touches one of your urls each minute. This keeps the instance warm... (But I guess Google does not like it that much)...
Hope that helps,
ra
Sample GAE app with 1 servlet takes between 2 and 3 secondes to start. I made a lot of tests :) Objectify add 1s on startup time.
Maybe the faster framework is Slim3 : https://sites.google.com/site/slim3appengine/
Look at this article, maybe we can find solution to speed up ninja : https://developers.google.com/appengine/articles/spring_optimization
And I try your trick with schedule task, it's doesn't work. Idle instance is the solution (without bug...)
Remember that the default setting for an instance is F1: 660Mhz, 128MB memory, 1 core. If your app (Spring, etc) starts in 1 second on your mac which has 2GHz, 8GB memory, SSD drive and 8 or 16 cores, you can do the math for the poor frontend:-) The real solution is optimizing web frameworks and doing as much as possible meta data computation at the GAE SDK level (i.e annotations processing etc) and not on the frontend CPU.
Dagger has some potential there. I will push for more work at the guice/servlet level to see what could be pre calculated at the GAE SDK level and just used at the frontend level.
Interesting discussion. Startup times on GAE are really important. Even using a cron job to keep an instance 'warm' is not a scalable solution. The time GAE needs an additional server as you are getting many requests, that user hitting your site is waiting for a long time. Note for small sites the 1s cron job does indeed work.
It's a pity Google/GAE does not provide a optimized framework like they provided for Python with Webapp. Just using the servlet api is not really an option as it's not really productive compared to modern web frameworks.
Hope to see Google/GAE reach out to framework developers to bring a decent/optimized web framework to GAE one day. Just like @ludoch is mentioning talking to the Guice devs.
@reyez as you have deployed ninjaframework apps to GAE, what are the startup times you are seeing?
@marceloverdijk all true. Under the hood Ninja uses Guice what is in general (gut feeling and common sense - no benchmarking) faster than a full fledged spring application. But: The GAE startup still takes time. In my experience the startup speed is also a lot depending on the size of the war file you are uploading. I guess the war has to be unzipped when starting up and that can take a while on a "slow" machine. But - the appengine sdk alone has 40MB...
Apart from that check out that thread from @stickfigure - he is very enthusiastic about the startup times - not. https://groups.google.com/forum/?fromgroups#!topic/google-appengine/Nz4Yt8V6PB0
Bottom line: Startup speed can be a problem. Ninja is reasonably "fast" and way fast enough for all apps we built. So for us it is no problem at all...
For my current apps startup times are also not important. They are mainly 'private' apps used by just a couple of users. So 1 instance is enough and I just keep it warm with a cron job. I use Spring, DI, AOP etc. and it works fine.
But for a scalable application I would not choose for GAE/J at the moment because of startup times.
I also experimented with Python on GAE and there I did not suffer these startup times.
It really seems we can't do much about it. If you are really dependent on startup times either don't use java - or don't use gae :(
After 4 month of development, we have always a big problem with starting time. Today it's between 25 and 40 seconds.
The worst is that warmup request don't help.
The warmup request don't really start all configuration (15s).
And request after warmup take 10s more with this log :
I chose Ninja because I thought that spring was too heavy. But with Spring warmup request load all element and first request is very fast after...
no solution to reduce request time ?? why "NinjaAppengineEnvironmentNull" is not done by warmup request ?
Hey Sam,
the message your are seeing regarding "NinjaAppengineEnvironmentNull" is just a note. There is no initialization going on.
I am not really sure what to say here. Our startup times are around 15s. What is not great, but our instances are up all the time and as such it is ok for us. So initially we pay 15s (I just benchmarked it again), but then everything is really fast and quick. But I have to admit that 15s startup is really bad.
40s sounds really long. How big is the ".war" you are trying to deploy? What version of Ninja and GAE are you using? If the startup time is "between" 25s and 40s this might be an issue on GAE' servers - but I am just guessing.
Other interesting (and possibly disappointing) reads are: https://groups.google.com/forum/#!topic/google-appengine/Nz4Yt8V6PB0 and: http://tech.small-improvements.com/2011/09/19/performance-tuning-for-google-app-engine-for-java/
I hope that helps a bit...
Best,
Raphael
You might also want to checkout https://developers.google.com/appengine/docs/adminconsole/performancesettings#Setting_the_Pending_Latency
I just played around with some settings and brought down our initial startup time to around 8 secs..
Cheers,
Raphael
And another quick update. I just tried with the default settings and a new project based on the ninja-appengine-blog-archetype archetype. The initial loading request (after an update on a F4 instance / automatic latency settings) is around 8 secs. All subsequent requests are ultrafast. Even if the application is not hit by any request for a while.
To me it seems that after an update a lot of stuff happens, that really kills performance at the first request to a new version of your app... @ludoch might now more...
At the beginning of the project, the starting time was around 10s and now it's 25s (average). During 4 month, we added a lot of services with Guice injection and all Guice configuration is made with annotation :/ My war weighs 37Mo (46Mo uncompress with 36Mo of lib). Il use ninja 1.6.0-rc1 (but same pb since 1.4), GAE 1.8.2
I have a pb with GAE starting time and AOP since long time. I already talked about that in a bar with @ludoch the last time I meet him in SF :)
But I think we have also a pb with ninja. Why warmup request don't start all conf ? The log "Loading NinjaAppengineEnvironmentNull (for devserver and production)" have to be display during warmup request. Why the request just after warmup take 15s and the third one only 300ms ?
With warmup : 1 - warmup = 15s 2 - index.do = 10s 3 - index.do = 300ms
Without warmup (when a request start a new instance) : 1 index.do = 25s 2 index.do = 300ms
Can we do something to load all in warmup ?
Hey Sam,
- regarding slow startup and slow first request: I think I can explain why you are seeing a long startup and a long first request. By default Ninja is using Guice in Stage "development". That means in essence a quicker startup, but the rest of the stuff is bound when needed at runtime. It might be the case that AOP (which is runtime bytecode enhancement) is slowing that down a lot.
I'd therefore check if there is a difference for you if you start the Guice injector in mode production: https://github.com/ninjaframework/ninja/blob/develop/ninja-servlet/src/main/java/ninja/servlet/NinjaBootstap.java stages described here: https://google-guice.googlecode.com/svn/trunk/latest-javadoc/com/google/inject/Stage.html
-
Try to use <enableJarClasses>true</enableJarClasses> in the appengine-maven-plugin and see if that helps (http://tech.small-improvements.com/2011/09/19/performance-tuning-for-google-app-engine-for-java/ recommends that).
-
Make sure you exclude any unneeded stuff from the war / deployment. Especially exclude java classes from the final deployment (and double check if the appengine:update command does not deploy them by using <retainUploadDir>true</retainUploadDir>in the maven plugin).
<resources>
<resource>
<directory>src/main/java</directory>
<includes>
<include>**/*</include>
</includes>
<excludes>
<exclude>**/*.java</exclude>
</excludes>
</resource>
<resource>
<directory>src/main/resources</directory>
<includes>
<include>**/*</include>
</includes>
</resource>
</resources>
-
Add some more timing and logging to NinjaBootstrap to really see were the performance decrease comes from. Is it really the creation of the injector or something else? You can also have a look at the DemoFilter (a simple servlet filter that measures the real duration of a request). Maybe there is something smelly going on. https://github.com/ninjaframework/ninja/blob/develop/ninja-core-demo/src/main/java/filters/DemoServletFilter.java
-
AOP is bytecode enhancement at runtime. This for sure will hit your - especially if you use AOP a lot. Maybe there is a way to refactor that. I stay away from AOP as much as possible (not because of the performance, but because I do not like the programming model a lot). Maybe that also explains why we do not see such a performance hit at startup. But I am just guessing...
Let us know if that helps... AND it would be really cool if we could continue the discussion on the mailing list :)
Thanks and cheers,
Raphael
It starts to be better !
I found my problem with Production Stage. I just add one line on application.conf : cache.implementation=ninja.appengine.AppEngineCacheImpl
I don't use ninja for asset management.
Still 4,5s for the first request after warmup, but much better than 17s ! One information : warmup start in 12s and Ninja injector started in 8,5s
Next step is to minimize Injection usage. I will write Poor Old Factory Object ;)
Thx for your help Raphael !
Samuel
PS : last log :
2013-08-28 22:20:03.785 /index.do 200 210ms 21kb
2013-08-28 22:19:47.987 /index.do 200 4564ms 21kb
2013-08-28 22:19:44.087 [xx].
2013-08-28 22:19:36.010 /ah/warmup 200 12226ms 0kb
2013-08-28 22:19:26.385 [xx].
2013-08-28 22:19:32.517
[s~betweather-prod/1-2-beta.369829181273162000].
2013/8/28 Raphael A. Bauer [email protected]:
Hi Sam,
two more things.
- I was really curious how Stage.PRODUCTION would perform. First thing is that it helped me to uncover some irregularities in the JPA and EHCache part of Ninja (not relevant for you).
Secondly I tried to deploy it to AppEngine and was really surprised. Somehow the startup times with the demo application further deceased (I'd have expected an increase). It takes now between 3s (!) and 7s to startup the app. That's not scientific, but quite interesting.
Conclusion => Ninja will from now in use Stage.Production as default. And it is also already pushed to develop on github...
- How big is your assets directory? You can try to brute force clean that directory and check if that has any influence on the deploy times. In good old Play1 times I observed, that it was much more performant to put static stuff into WEB-INF and not into a directory like src/main ... But that is just a wild guess...
Let us know if that has any influence...
Best,
Raphael
— Reply to this email directly or view it on GitHub.