On 2/28/11, Cian Montgomery <[email protected]> wrote: > Thanks for your response. I installed and have been inspecting my > application with appstats. I have noticed a comple of things, 1 the > latency times and log times of appstats do not match what is reported > in the log. consider the following 5 calls, Particularly the 3rd call > where the difference is over 400ms. (log comparison is made more > difficult by time stamps not matching and the times of the log entries > being in different time zones.) > > > 2011-02-28 22:10:55.336 /reggie/dispatch 200 45ms 116cpu_ms 0kb > Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10_6_6; en-US) AppleWebKit/ > 534.13 (KHTML, like Gecko) Chrome/9.0.597.102 Safari/534.13,gzip(gfe) > 2011-02-28 22:07:27.537 /reggie/dispatch 200 64ms 154cpu_ms > 60api_cpu_ms 0kb Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US) > AppleWebKit/534.16 (KHTML, like Gecko) Chrome/10.0.648.82 Safari/ > 534.16,gzip(gfe) > 2011-02-28 22:07:08.333 /reggie/dispatch 200 473ms 177cpu_ms > 60api_cpu_ms 0kb Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US) > AppleWebKit/534.16 (KHTML, like Gecko) Chrome/10.0.648.82 Safari/ > 534.16,gzip(gfe) > 2011-02-28 22:06:55.387 /reggie/dispatch 200 60ms 107cpu_ms > 60api_cpu_ms 0kb Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US) > AppleWebKit/534.16 (KHTML, like Gecko) Chrome/10.0.648.82 Safari/ > 534.16,gzip(gfe) > 2011-02-28 22:06:54.179 /reggie/dispatch 200 52ms 130cpu_ms > 60api_cpu_ms 0kb Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US) > AppleWebKit/534.16 (KHTML, like Gecko) Chrome/10.0.648.82 Safari/ > 534.16,gzip(gfe) > > > (12)2011-03-01 06:10:55.308 "POST /reggie/dispatch" 200 real=20ms > cpu=0ms api=0ms overhead=0ms (6 RPCs) > (13) 2011-03-01 06:07:27.487 "POST /reggie/dispatch" 200 real=40ms > cpu=0ms api=0ms overhead=0ms (8 RPCs) > (14) 2011-03-01 06:07:08.264 "POST /reggie/dispatch" 200 real=55ms > cpu=0ms api=0ms overhead=0ms (8 RPCs) > (15) 2011-03-01 06:06:55.337 "POST /reggie/dispatch" 200 real=43ms > cpu=0ms api=0ms overhead=0ms (8 RPCs) > (16) 2011-03-01 06:06:54.140 "POST /reggie/dispatch" 200 real=32ms > cpu=0ms api=0ms overhead=0ms (8 RPCs) > > > > - checking for each capability enable costs 2-4ms best case. It would > be nice to be able to check all caps in 1 rpc. > - latency to the datastore is highly erratic, on subsiquent user > requests for the same data from the data store show the following > resutls: real=7ms api=85ms, real=305ms api=85ms. Is is normal to 40x > variance in executing the same query to the datastore? > > > Is there a way to put my own events in the appstats? I am using a > dispatch pattern in the server, so it is difficult to devine what > which handler I am looking at in the stats? > > > Thanks, > > Cian > > On Feb 28, 12:42 am, Robert Kluin <[email protected]> wrote: >> Hi Cian, >> Have you used Appstats to investigate? Perhaps there is some type >> of cleanup process, maybe by a session library, happening? >> >> Robert >> >> On Fri, Feb 25, 2011 at 17:00, Cian Montgomery >> >> >> >> >> >> >> >> <[email protected]> wrote: >> > My app (appid: mr-october, always on) is experiencing lots of problems >> > with latency problems over the last couple of days. >> >> > For a bunch of the calls to the same action dispatch handler over the >> > last there hours. >> > 2011-02-25 12:36:09.581 /reggie/dispatch 200 4829ms 4763cpu_ms >> > 236api_cpu_ms >> > 2011-02-25 12:35:31.683 /reggie/dispatch 200 159ms 405cpu_ms >> > 125api_cpu_ms >> > 2011-02-25 12:35:16.764 /reggie/dispatch 200 354ms 615cpu_ms >> > 125api_cpu_ms >> > 2011-02-25 12:20:37.208 /reggie/dispatch 200 232ms 452cpu_ms >> > 125api_cpu_ms >> > 2011-02-25 12:19:28.348 /reggie/dispatch 200 6380ms 4600cpu_ms >> > 190api_cpu_ms >> > 2011-02-25 10:47:19.700 /reggie/dispatch 200 171ms 452cpu_ms >> > 125api_cpu_ms >> > 2011-02-25 10:47:15.865 /reggie/dispatch 200 141ms 405cpu_ms >> > 125api_cpu_ms >> > 2011-02-25 10:47:15.731 /reggie/dispatch 200 385ms 475cpu_ms >> > 125api_cpu_ms >> > 2011-02-25 10:37:15.031 /reggie/dispatch 200 177ms 522cpu_ms >> > 125api_cpu_ms >> > 2011-02-25 10:36:48.890 /reggie/dispatch 200 3550ms 732cpu_ms >> > 125api_cpu_ms >> >> > Which is honestly much better then the past couple of days where saw >> > some times over 30000ms. >> >> > Or these where appengine did not even get to my log statement so I >> > have no idea what the request was: >> > 2011-02-23 09:36:35.922 /reggie/dispatch 500 141862ms 1395cpu_ms >> > 65api_cpu_ms >> > 2011-02-23 09:00:21.024 /reggie/dispatch 500 102858ms 793cpu_ms >> >> > I can reproduce this behavor just by hitting the same query from the >> > client, reliably 1 out of about every 20 exections of this action is >> > over 5 seconds of latency. >> >> > What can be done to address these latency issues? >> >> > Thanks, >> >> > Cian. >> >> > -- >> > You received this message because you are subscribed to the Google >> > Groups "Google App Engine" group. >> > To post to this group, send email to [email protected]. >> > To unsubscribe from this group, send email to >> > [email protected]. >> > For more options, visit this group >> > athttp://groups.google.com/group/google-appengine?hl=en. > > -- > You received this message because you are subscribed to the Google Groups > "Google App Engine" group. > To post to this group, send email to [email protected]. > To unsubscribe from this group, send email to > [email protected]. > For more options, visit this group at > http://groups.google.com/group/google-appengine?hl=en. > >
-- You received this message because you are subscribed to the Google Groups "Google App Engine" group. To post to this group, send email to [email protected]. To unsubscribe from this group, send email to [email protected]. For more options, visit this group at http://groups.google.com/group/google-appengine?hl=en.
