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.
