Hi Steve, I read your link. What I am referring to does include JVM startup. Those are the times I get right after a redeploy.
Here are some more lines from my logs, included with my info logs that I omitted last time: 03-20 04:07PM 41.084 /donothing 200 891ms 796cpu_ms 0kb Mozilla/5.0, AC.Log info: JVMID: -4270362285924610791 - ReqNum: 0 03-20 04:11PM 22.290 /donothing 200 1240ms 777cpu_ms 0kb Mozilla/5.0, AC.Log info: JVMID: -5678405964618118370 - ReqNum: 0 03-20 04:12PM 06.574 /donothing 200 81ms 58cpu_ms 0kb Mozilla/5.0, AC.Log info: JVMID: -5678405964618118370 - ReqNum: 1 03-20 04:14PM 31.684 /donothing 200 1105ms 835cpu_ms 0kb Mozilla/5.0, AC.Log info: JVMID: -5439702848547505668 - ReqNum: 0 03-20 04:14PM 52.309 /donothing 200 71ms 58cpu_ms 0kb Mozilla/5.0, AC.Log info: JVMID: -5439702848547505668 - ReqNum: 1 Here are the corresponding times for my browser to receive a response (captured with firebug): 1.11s 1.38s 188ms 1.22s 172ms In the logs, the lines that say "ReqNum: 0" were cold starts that happened because I redeployed my app. One of them even took less than a second :). I have spent many months learning how to optimize my cold start time. I took my original app that took 15 seconds for a cold start, and have brought it down quite a bit :). I wrote a guide on my blog for cold start optimization if you are interested. Here is the link - http://www.answercow.com/2010/03/google-app-engine-cold-start-guide-for.html . On Mar 20, 1:24 pm, Steve Pritchard <steve...@gmail.com> wrote: > Hi, > As I explained > inhttp://groups.google.com/group/google-appengine-java/browse_thread/th... > > I have the notion of cold/warm/hot. > It calculates and records the service time when the top left-most GEM > is pressed.. Hovering over the gem after it returns will show the > stats. > > A cold start only happens after a redeploy. > > A warm start seems to add about 5000ms to my 'network' time which is > normally 400ms or so. My turnaround in the server goes from almost 0 > to about 2000ms, mostly doing a single cache-read from MemCache plus > the ensuing de-serialization. > > The 5000ms has to be JVM etc start up. Only the google folks can deal > with that one. Theoretically getting rid of the unneeded .jar files > can only help. > > In my hot mode there is no JVM start-up and I am able to service the > request in about 400ms. > > Your cold-start (which is my warm start equivalent) of 2867ms is not > including the JVM startup so I suspect at your browser the time is > longer. > > Hope this helps. > Steve > > On Mar 20, 11:42 am, Spines <kwste...@gmail.com> wrote: > > > > > Hey Steve, > > Yea, the elapsed time is usually higher than CPU usage, but I think > > maybe because I was doing my testing late last night I lucked into > > really low elapsed time too. I checked my cold start time this > > morning, and elapsed time was 2867ms with 1010cpu_ms. > > > Here are some lines from my logs: > > 03-20 08:30AM 05.838 /donothing 200 2867ms 1010cpu_ms 0kb Mozilla/5.0 > > 03-20 12:15AM 00.832 /donothing 200 2155ms 913cpu_ms 0kb Mozilla/5.0 > > 03-19 11:02PM 28.449 /donothing 200 1119ms 1166cpu_ms 0kb Mozilla/5.0 > > > The elapsed time seems to vary greatly, whereas cpu time seems to be a > > decent metric to see if an optimization of mine actually had an > > effect. The page I request for testing is a servlet which returns > > nothing. Note that if you are requesting a JSP it will increase your > > cold start times by at least a few hundred milliseconds. For some > > reason the first access to even the most simple JSP (like <%= 5+2 %> > > will take quite a while. > > > I'd really love to get my elapsed time down to around the same amount > > as my CPU time. Does anyone have any insights as to what exactly App > > Engine is doing during that time? > > > On Mar 20, 7:30 am, Steve Pritchard <steve...@gmail.com> wrote: > > > > Update to previous post. > > > I am measuring elapsed time (what I really care about), not CPU secs. > > > I could not figure out how a cold start was so fast (1200ms). > > > Steve > > > > On Mar 20, 10:26 am, Steve Pritchard <steve...@gmail.com> wrote: > > > > > Thanks for the tip. I am in the same boat in that I do not use JDO > > > > etc. I also do not need GWT stuff. So I deleted: > > > > > datanucleus-appengine-1.0.5.final.jar > > > > datanucleus-core-1.1.5.jar > > > > datanucleus-jpa-1.1.5.jar > > > > geronimo-jpa_3.0_spec-1.1.1.jar > > > > geronimo-jta_1.1_spec-1.1.1.jar > > > > gwt-servlet.jar > > > > jdo2-api-2.3-eb.jar > > > > > from my 1.3.1 war\lib and it keeps running. My 'warm' start (using > > > > MemCache) is around 3200ms. Previously I recall it fluctuated around > > > > 4000ms. > > > > Steve > > > > > On Mar 20, 2:09 am, Spines <kwste...@gmail.com> wrote: > > > > > > Well, I figured it out, I just deleted all of the jars I didn't need > > > > > from my ./build directory. I deleted all of the JDO, JPA, and > > > > > datanucleus jars. The result of doing this was I got my first cold > > > > > start that happened under 1200ms :). Previously the CPU time used by > > > > > a cold start was pretty consistently around 1500ms, and after deleting > > > > > those jars it is now around 1150ms :). -- 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-j...@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.
