Sounds like scheduler issues. Do you see a pending ms in the logs (expand the entries)? Have you adjusted the scheduler knobs under app settings in your app's dashboard?
Robert On Jul 29, 2011 12:02 PM, "Pol" <i...@pol-online.net> wrote: > > Hi, > > All I'm im doing is reloading a web page that does a couple AJAX > requests to my app engine app (Python) and I'm often observing insane > latency: > > 2011-07-29 08:52:20.464 /api/user_info 200 10967ms 26cpu_ms 0kb > Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:5.0.1) Gecko/20100101 > Firefox/5.0.1 > > 10 seconds for a trivial OPTIONS request? > > class APIHandler(webapp.RequestHandler): > > def initialize(self, request, response): > super(APIHandler, self).initialize(request, response) > del self.response.headers['Content-Type'] > > def options(self): > self.response.headers['Access-Control-Allow-Origin'] = '*' > self.response.headers['Access-Control-Allow-Methods'] = 'POST, > GET, OPTIONS' > self.response.headers['Access-Control-Allow-Headers'] = 'X- > Requested-With, If-Modified-Since, Content-Type, Cache-Control' + ', ' > + VERSION_HEADER + ', ' + AUTHTOKEN_HEADER > > Note that I have 3 resident instances, nobody is using my app besides > me right now, and no, the log does not report the start of a new > instance when these very long requests happen. > > What's more incomprehensible is that I have App Stats running on the > server and it reports really low-latency: > > (1) 2011-07-29 07:48:14.041 "GET /api/status" 200 real=5ms cpu=46ms > api=0ms overhead=0ms (1 RPC) > (2) 2011-07-29 07:48:13.427 "OPTIONS /api/status" 200 real=0ms > cpu=1003ms api=0ms overhead=0ms (0 RPCs) > (3) 2011-07-29 07:48:12.537 "GET /api/user_info" 401 real=23ms > cpu=27ms api=12ms overhead=0ms (2 RPCs) > (4) 2011-07-29 07:48:12.025 "OPTIONS /api/user_info" 200 real=0ms > cpu=12ms api=0ms overhead=0ms (0 RPCs) > > Here are the same 4 requests in the dashboard log: > > 2011-07-29 08:48:14.053 /api/status 200 133ms 26cpu_ms 0kb Mozilla/5.0 > (Macintosh; Intel Mac OS X 10.6; rv:5.0.1) Gecko/20100101 Firefox/ > 5.0.1 > 2011-07-29 08:48:13.434 /api/status 200 401ms 213cpu_ms 0kb Mozilla/ > 5.0 (Macintosh; Intel Mac OS X 10.6; rv:5.0.1) Gecko/20100101 Firefox/ > 5.0.1 > 2011-07-29 08:48:12.572 /api/user_info 401 190ms 67cpu_ms 12api_cpu_ms > 0kb Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:5.0.1) Gecko/ > 20100101 Firefox/5.0.1 > 2011-07-29 08:48:12.068 /api/user_info 200 2446ms 35cpu_ms 0kb Mozilla/ > 5.0 (Macintosh; Intel Mac OS X 10.6; rv:5.0.1) Gecko/20100101 Firefox/ > 5.0.1 > > As you can't see 5~23ms turned into 133~2446ms. What could possibly be > happening? The latency clearly comes from outside my handler's code. > > Thanks for any help. > > - Pol > > -- > You received this message because you are subscribed to the Google Groups "Google App Engine" group. > To post to this group, send email to google-appengine@googlegroups.com. > To unsubscribe from this group, send email to google-appengine+unsubscr...@googlegroups.com. > 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 google-appengine@googlegroups.com. To unsubscribe from this group, send email to google-appengine+unsubscr...@googlegroups.com. For more options, visit this group at http://groups.google.com/group/google-appengine?hl=en.
