Hi Kristopher, On Wed, Aug 1, 2012 at 11:18 AM, Kristopher Giesing <[email protected]> wrote: > I've been working for some time on an app I plan to deploy. Over the > development period I have done testing on the QA instance of my app (which > is a separate app ID from the one I'll use in production) but have not paid > serious attention to performance since the functionality wasn't yet > complete. > > This past weekend I did some light real-world type testing, and the > performance was terrible. With QPS in the 5-10 range I was seeing latencies > in the range of 10-20s. Obviously, the first place I looked was my own > code, but after some easy optimizations I got my query handling down to the > 200ms range, and the response times on the client were still usually very > bad (1s minimum, up to 10-20s max). (Pings from the client to the > appspot.com domain are pretty stable at 30ms.)
Where are you accessing your app from? Ping result is just for our frontend facilities, so it doesn't reflect the real network latency of your app. > > Looking further, I discovered that Google App Engine is spawning new > instances of my app at a pathological rate. For example, I left the app > stats console open for a while, and found that just loading the appstats URI > by itself would cause a new instance to spawn! This is with zero QPS > otherwise - my app was completely idle, and none of my own code was running > at all. Sorry if I miss something, but I think it's the expected behavior. If you don't set min idle instances, your app doesn't need to have any instances with zero QPS, right? So if there's a new request, App Engine spins up a new instance for your application. > > I tried adjusting the min and max instance settings, but GAE seems to ignore > them, as far as I can tell; the max is not honored, and although it does > keep instances running to accommodate the min, those running instances don't > prevent new ones from spawning. It's as if GAE doesn't think they really > exist. I also have the min latency set to the max of 15.0s, which is far > beyond the rise time I'm seeing for GAE spawning new instances. > > Here's a set of logs taken from a very light load on the server, with a 2/2 > instance max/min setting. I include logs from a previous slice of time so > that you can see the /appstats URI also spawning new instances, but I want > to emphasize that this is a continuous set of logs - there are no requests > in this time window that aren't listed below. I also include a screenshot > of the instance panel in the console so you can see that the instances are, > in fact, being created. I think the cause of the high latency is the user facing loading requests. Can you try something like min idle instances=5(or 10)/max idle instances=automatic, and see how it goes first? Currently setting 'min idle instances' is the most reliable way to reduce user facing loading requests. Additionally, you shouldn't set 'max idle instances' because if you set max idle instances, App Engine will terminate your idle instances aggressively, as a result you will see more user facing loading requests. > > 2012-07-31 18:58:12.541 /_ah/channel/connected/ 200 101ms 0kb > 2012-07-31 18:58:10.894 /api/chat/G:1286432802 200 132ms 0kb Mozilla/5.0 > (iPad; CPU OS 5_1_1 like Mac OS X) AppleWebKit/534.46 (KHTML, like Gecko) > Mobile/9B206 > 2012-07-31 18:58:09.809 /_ah/channel/connected/ 200 1076ms 0kb > 2012-07-31 18:58:09.107 /api/game/72001/users 200 12312ms 0kb Mozilla/5.0 > (iPad; CPU OS 5_1_1 like Mac OS X) AppleWebKit/534.46 (KHTML, like Gecko) > Mobile/9B206 > 2012-07-31 18:58:07.725 /api/chat/G:658732847 200 7232ms 0kb Mozilla/5.0 > (iPad; CPU OS 5_1 like Mac OS X) AppleWebKit/534.46 (KHTML, like Gecko) > Mobile/9B176 > 2012-07-31 18:58:00.279 /api/game/72001/users 200 8820ms 0kb Mozilla/5.0 > (iPad; CPU OS 5_1 like Mac OS X) AppleWebKit/534.46 (KHTML, like Gecko) > Mobile/9B176 > I 2012-07-31 18:58:00.279 This request caused a new process to be started > for your application, and thus caused your application code to be loaded for > the first time. This requ > 2012-07-31 18:57:56.393 /api/game/72001 200 6044ms 3kb Mozilla/5.0 (iPad; > CPU OS 5_1_1 like Mac OS X) AppleWebKit/534.46 (KHTML, like Gecko) > Mobile/9B206 > 2012-07-31 18:57:55.920 /_ah/warmup 200 5105ms 0kb > I 2012-07-31 18:57:55.916 This request caused a new process to be started > for your application, and thus caused your application code to be loaded for > the first time. This requ > 2012-07-31 18:57:51.324 /api/game/72001 200 7151ms 3kb Mozilla/5.0 (iPad; > CPU OS 5_1 like Mac OS X) AppleWebKit/534.46 (KHTML, like Gecko) > Mobile/9B176 > 2012-07-31 18:57:49.779 /_ah/warmup 200 4629ms 0kb > I 2012-07-31 18:57:49.778 This request caused a new process to be started > for your application, and thus caused your application code to be loaded for > the first time. This requ > 2012-07-31 18:57:01.504 /_ah/warmup 200 5225ms 0kb > I 2012-07-31 18:57:01.503 This request caused a new process to be started > for your application, and thus caused your application code to be loaded for > the first time. This requ > 2012-07-31 18:13:56.599 /_ah/warmup 200 4784ms 0kb > I 2012-07-31 18:13:56.581 This request caused a new process to be started > for your application, and thus caused your application code to be loaded for > the first time. This requ > 2012-07-31 18:06:53.651 /appstats/stats 200 898ms 285kb Mozilla/5.0 > (Macintosh; Intel Mac OS X 10_7_4) AppleWebKit/536.25 (KHTML, like Gecko) > Version/6.0 Safari/536.25 > 2012-07-31 18:06:52.618 /appstats 302 33ms 0kb Mozilla/5.0 (Macintosh; Intel > Mac OS X 10_7_4) AppleWebKit/536.25 (KHTML, like Gecko) Version/6.0 > Safari/536.25 > 2012-07-31 18:06:14.538 /appstats/static/plus.gif 200 45ms 0kb Mozilla/5.0 > (Macintosh; Intel Mac OS X 10_7_4) AppleWebKit/536.25 (KHTML, like Gecko) > Version/6.0 Safari/536.25 > 2012-07-31 18:06:14.298 /appstats/static/app_engine_logo_sm.gif 200 4820ms > 3kb Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_4) AppleWebKit/536.25 > (KHTML, like Gecko) Version/6.0 Safari/536.25 > 2012-07-31 18:06:14.288 /appstats/static/appstats_js.js 200 4699ms 43kb > Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_4) AppleWebKit/536.25 (KHTML, > like Gecko) Version/6.0 Safari/536.25 > I 2012-07-31 18:06:14.288 This request caused a new process to be started > for your application, and thus caused your application code to be loaded for > the first time. This requ > > Can anyone explain why this might be happening? I don't understand why this > isn't clobbering everyone that uses GAE. With such aggressive instancing, > the performance just completely falls apart. > > If I can't solve this, I am faced with backing away from GAE entirely, > ripping out all the API dependencies and hosting the code on my own Tomcat > server somewhere. I don't really want to do that because I don't want to be > in the business of server maintenance - that's one of the key reasons I went > with GAE in the first place - but I can't ship a product with this behavior. > > Thanks, > > - Kris > > > -- > You received this message because you are subscribed to the Google Groups > "Google App Engine" group. > To view this discussion on the web visit > https://groups.google.com/d/msg/google-appengine/-/qErJJOQ63KYJ. > 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. -- Takashi Matsuo -- 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.
