Hi Im trying to understand the performance of my GAE app, which appears to be declining over time.
Here is a log from my Java app .. please note that my instance is running so this isnt "the first time" the code is being executed in the instance.. 2012-03-11 10:16:12.841 /resources/command? summary=true&start=0&end=16&preferred=true 200 892ms 7kb Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/ 17.0.963.78 Safari/535.11 67.176.95.243 - - [11/Mar/2012:09:16:12 -0700] "GET /resources/command? summary=true&start=0&end=16&preferred=true HTTP/1.1" 200 7282 - "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.78 Safari/535.11" "n3phele.appspot.com" ms=893 cpu_ms=376 api_cpu_ms=82 cpm_usd=0.011300 instance=00c61b117cca20def4d597294b9929c08f6983 I 2012-03-11 10:16:12.467 n3phele.service.rest.impl.BasicSecurityFilter$Authorizer isUserInRole: Checking role authenticated with user defined I 2012-03-11 10:16:12.469 n3phele.service.rest.impl.CommandResource$CommandManager getPreferredCollection: Starting owner fetch W 2012-03-11 10:16:12.469 n3phele.service.rest.impl.CommandResource list: list entered with summary true start 0 end 16 preferred true I 2012-03-11 10:16:12.486 n3phele.service.rest.impl.CommandResource$CommandManager getPreferredCollection: Finished owner key fetch I 2012-03-11 10:16:12.527 n3phele.service.rest.impl.CommandResource$CommandManager getPreferredCollection: Finished shared key fetch I 2012-03-11 10:16:12.814 n3phele.service.rest.impl.CommandResource$CommandManager getPreferredCollection: Finished collection fetch I 2012-03-11 10:16:12.832 n3phele.service.rest.impl.CommandResource list: partition commands start I 2012-03-11 10:16:12.832 n3phele.service.rest.impl.CommandResource list: partition commands end Sun Mar 11 16:16:12.832 UTC 2012 The first line at 10:16:12.467 represents some processing in the security filter associated with the request, and the last line 10:16:12.832 is in my applet code just before I return my reply. The overall log line itself ends at 10:16:12.841, and I am assuming that the 10ms difference is some final processing turning the reply into JSON. My real question here is about the elapsed time ms=893. If I look at the processing time spent in my code it is 365ms. Can any one suggest where the other 893-365=528 ms is being spent? (its this 500ms which is killing me from a performance perspective). Thx in advance.. \n -- You received this message because you are subscribed to the Google Groups "Google App Engine for Java" group. To post to this group, send email to google-appengine-java@googlegroups.com. To unsubscribe from this group, send email to google-appengine-java+unsubscr...@googlegroups.com. For more options, visit this group at http://groups.google.com/group/google-appengine-java?hl=en.
