FWIW, I think I've seen this behavior too. But when I switched to another app instance everything was smooth again. I have pingdom numbers to back this up if you are interested.
- Koen On Sep 18, 11:43 am, Brandon Thomson <[email protected]> wrote: > Nick, the app id is conquer-on-contact. > > Now that I think I know where the problem is, I'll restructure my > imports such that each path through the code has fewer of them. But I > hope Google is working on this too, because as you can see from the > logs above it looks like there are requests in which my very first > statement ("import logging") in the python file described in app.yaml > as the handler for the URL is not complete until 10 seconds after the > beginning of the request. > > Or perhaps there is some other explanation for this behavior. I'm > limited in the testing I can do because this problem is highly > intermittent; right now all requests are finishing in < 200ms. > > On Sep 18, 5:07 am, Brandon Thomson <[email protected]> wrote: > > > > > I really apologize for all this spam, but here is a missing piece: > > > 09-18 01:54AM 13.915 /admin/tick 200 15228ms 659cpu_ms > > 56api_cpu_ms 0kb Python-urllib/2.5,gzip(gfe),gzip(gfe) > > See details > > > D 09-18 01:54AM 20.335 App loading... > > D 09-18 01:54AM 28.811 Handler starting... > > D 09-18 01:54AM 29.087 ... > > D 09-18 01:54AM 29.087 Handler is done. > > > I added: > > > class TickHandler(webapp.RequestHandler): > > def post(self): > > logging.debug("Handler starting...") > > > At this point I am 80% convinced this is due to slow imports, and that > > this is the same issue the django folks are seeing (for example > > inhttp://groups.google.com/group/google-appengine/browse_thread/thread/...) > > > On Sep 18, 4:49 am, Brandon Thomson <[email protected]> wrote: > > > > Aha, I found a counter-example: > > > > 09-18 01:38AM 44.571 /admin/tick 200 11435ms 659cpu_ms > > > 56api_cpu_ms 0kb Python-urllib/2.5,gzip(gfe),gzip(gfe) > > > See details > > > D 09-18 01:38AM 46.947 App loading... > > > D 09-18 01:38AM 55.957 ... > > > D 09-18 01:38AM 55.958 Handler is done. > > > > So maybe it is a problem inside my app? I will continue to research... > > > > On Sep 18, 4:24 am, Brandon Thomson <[email protected]> wrote: > > > > > Here is an example. This request took 9s to complete but it appears > > > > that only 200ms was spent inside my python file: > > > > > 09-18 01:17AM 00.930 /admin/tick 200 9379ms 113cpu_ms > > > > 16api_cpu_ms 0kb Python-urllib/2.5,gzip(gfe),gzip(gfe) > > > > D 09-18 01:17AM 10.064 App loading... > > > > W 09-18 01:17AM 10.258 ... > > > > D 09-18 01:17AM 10.259 Handler is done. > > > > > I also thought this might be related to contention in the datastore > > > > because I have a weird data model but this would seem to disprove that > > > > theory. > > > > > The top of the python file is literally: > > > > > #!/usr/bin/env python > > > > import logging > > > > logging.debug("App loading...") --~--~---------~--~----~------------~-------~--~----~ 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 -~----------~----~----~----~------~----~------~--~---
