[web2py] Re: Web2Py on GAE very slow
Hi all, i've been slow on this partially because i'm in the middle of some giant re-factorings to optimize for the new pricing model on GAE. here are some thoughts: - memcache is your friend. if you are querying for something on a request, toss it in memcache (you have to cast rows to dicts first). i have some lookup type tables that i keep in memcache - make your schema as flat a possible. joins don't exist so that is additional queries. also remember that things like row.ref.name runs a query behind the scenes in web2py - if you have more than a few tables, put table definitions in module files (perhaps as classes) then import and init them when needed. in one of my projects with about 50 tables this is going to save me about 30ms per request (and at 2.5 million requests per day that turns into instance hours) - be wary of validators. know that IS_IN_DB() and IS_NOT_IN_DB() will perform queries. IS_IN_DB() will cost you 1 read per row in the table that goes into the drop-down in your form. consider using IS_IN_SET() with a set built from a memcached copy of the data - i hear that python 2.7 is supposed to make a difference. i have not pulled the trigger on any of my production apps yet. i'm afraid to turn on multithreading because of this issue: http://code.google.com/p/googleappengine/issues/detail?id=6323 but i don't know if that will effect my app or not. - i'm planning to start using the cache-control headers for staticish pages (i have lots of pages that can be cached for at least 5 minutes). it is reported that google will then serve your page from its cache for free! - i've started to run task queue tasks on backend instances. this allows me to throttle them better and catch when i have written buggy code that goes out of control (yes, there was a $1000 bill for a day when that happened.) - i have been running cron jobs to aggregate data for reporting purposes since complex queries cannot be run on the fly. i'm starting to experiment with google cloud sql and putting reporting data in a SQL datastore so that site admins can run what they want when they want. those are my major thoughts for now. please let me know if you have questions about these techniques. cfh
[web2py] Re: Web2Py on GAE very slow
Christian, Did you manage to write this? I am looking for optimizing the GAE. Would appreciate your inputs. Thanks, Joseph
[web2py] Re: Web2Py on GAE very slow
Thanks, that would be much appreciated! On Oct 27, 3:28 am, howesc how...@umich.edu wrote: i will write something up for you soon
[web2py] Re: Web2Py on GAE very slow
i will write something up for you soon
[web2py] Re: Web2Py on GAE very slow
Hi Christian, thanks for your informative reply. You were right, I do use URL and A quite a lot, and most of LOGs come from that two helpers. I also managed to completely turn off logging by modifying logging.conf. Interesting, today my website is performing much much better - without any changes to the code. I am not getting deadline exceptions any more. I guess this has something to do with GAE performance in general - dont know. Im certain that some (mem)caching will additionally boost the performance. If I may; would you be so kind and list some of the tasks one should do, to optimize project for serving on production GAE? Some common steps like use this, instead of this, set foo to bar, never do this, etc. I hope this makes sense :) Cheers, Damien On Oct 24, 11:47 pm, howesc how...@umich.edu wrote: Damjan, i use GAE heavily, here's what i can say based on what i see: - each call to URL() puts at least one message in the debug log. so whatever you are doing has lots of calls to URL() in it. - logging can be affected by logging.conf, but i've never successfully suppressed logs i didn't care about and got logs i liked. - i don't get random deadline exceeded messages on GAE, i do get them when i write bad code. one such mistake i made was running a query in a model file (db.py) that returned lots of rows. if you can provide a simple model + controller that exhibits the problem we can help troubleshoot. christian
Re: [web2py] Re: Web2Py on GAE very slow
On Oct 25, 2011, at 10:31 AM, Damjan Malis i...@simplabs.si wrote: Hi Christian, thanks for your informative reply. You were right, I do use URL and A quite a lot, and most of LOGs come from that two helpers. I also managed to completely turn off logging by modifying logging.conf. That's good to know. What changes did you make? Interesting, today my website is performing much much better - without any changes to the code. I am not getting deadline exceptions any more. I guess this has something to do with GAE performance in general - dont know. Im certain that some (mem)caching will additionally boost the performance. If I may; would you be so kind and list some of the tasks one should do, to optimize project for serving on production GAE? Some common steps like use this, instead of this, set foo to bar, never do this, etc. I hope this makes sense :) Cheers, Damien On Oct 24, 11:47 pm, howesc how...@umich.edu wrote: Damjan, i use GAE heavily, here's what i can say based on what i see: - each call to URL() puts at least one message in the debug log. so whatever you are doing has lots of calls to URL() in it. - logging can be affected by logging.conf, but i've never successfully suppressed logs i didn't care about and got logs i liked. - i don't get random deadline exceeded messages on GAE, i do get them when i write bad code. one such mistake i made was running a query in a model file (db.py) that returned lots of rows. if you can provide a simple model + controller that exhibits the problem we can help troubleshoot. christian
[web2py] Re: Web2Py on GAE very slow
Jonathan, logging.conf file [loggers] #keys=root,rocket,markdown,web2py,rewrite,app,welcome keys=root On Oct 25, 9:13 pm, Jonathan Lundell jlund...@pobox.com wrote: On Oct 25, 2011, at 10:31 AM, Damjan Malis i...@simplabs.si wrote: Hi Christian, thanks for your informative reply. You were right, I do use URL and A quite a lot, and most of LOGs come from that two helpers. I also managed to completely turn off logging by modifying logging.conf. That's good to know. What changes did you make? Interesting, today my website is performing much much better - without any changes to the code. I am not getting deadline exceptions any more. I guess this has something to do with GAE performance in general - dont know. Im certain that some (mem)caching will additionally boost the performance. If I may; would you be so kind and list some of the tasks one should do, to optimize project for serving on production GAE? Some common steps like use this, instead of this, set foo to bar, never do this, etc. I hope this makes sense :) Cheers, Damien On Oct 24, 11:47 pm, howesc how...@umich.edu wrote: Damjan, i use GAE heavily, here's what i can say based on what i see: - each call to URL() puts at least one message in the debug log. so whatever you are doing has lots of calls to URL() in it. - logging can be affected by logging.conf, but i've never successfully suppressed logs i didn't care about and got logs i liked. - i don't get random deadline exceeded messages on GAE, i do get them when i write bad code. one such mistake i made was running a query in a model file (db.py) that returned lots of rows. if you can provide a simple model + controller that exhibits the problem we can help troubleshoot. christian
Re: [web2py] Re: Web2Py on GAE very slow
On Oct 25, 2011, at 12:29 PM, Damjan Malis wrote: Jonathan, logging.conf file [loggers] #keys=root,rocket,markdown,web2py,rewrite,app,welcome keys=root Thanks. That's interesting. On Oct 25, 9:13 pm, Jonathan Lundell jlund...@pobox.com wrote: On Oct 25, 2011, at 10:31 AM, Damjan Malis i...@simplabs.si wrote: Hi Christian, thanks for your informative reply. You were right, I do use URL and A quite a lot, and most of LOGs come from that two helpers. I also managed to completely turn off logging by modifying logging.conf. That's good to know. What changes did you make? Interesting, today my website is performing much much better - without any changes to the code. I am not getting deadline exceptions any more. I guess this has something to do with GAE performance in general - dont know. Im certain that some (mem)caching will additionally boost the performance. If I may; would you be so kind and list some of the tasks one should do, to optimize project for serving on production GAE? Some common steps like use this, instead of this, set foo to bar, never do this, etc. I hope this makes sense :) Cheers, Damien On Oct 24, 11:47 pm, howesc how...@umich.edu wrote: Damjan, i use GAE heavily, here's what i can say based on what i see: - each call to URL() puts at least one message in the debug log. so whatever you are doing has lots of calls to URL() in it. - logging can be affected by logging.conf, but i've never successfully suppressed logs i didn't care about and got logs i liked. - i don't get random deadline exceeded messages on GAE, i do get them when i write bad code. one such mistake i made was running a query in a model file (db.py) that returned lots of rows. if you can provide a simple model + controller that exhibits the problem we can help troubleshoot. christian
[web2py] Re: Web2Py on GAE very slow
It should. On Oct 24, 10:28 am, Jonathan Lundell jlund...@pobox.com wrote: On Oct 24, 2011, at 8:01 AM, Damjan Malis wrote: Hi guys, I'm having difficulties running simple app on GAE. I've created simple controller that selects all records (15) from table and passes them to my view. View just lists them. The issue is that 70% of requests made to this controller took 10-50 second to finish. Sometimes GAE even throws DeadlineExceeded error. This issue even occurs on controller with no DB involved. From logs, I can see that all such faulty requests start with: DEBUG: no file locking, this will cause problems You should see this message on all requests, I think; it's a consequence of importing portalocker under GAE and the fact that GAE apparently logs everything, even debug-level messages. It's harmless. Massimo, it's a misleading message (and makes for a noisy log file) under GAE. Shouldn't the portalocker logic make a special case of GAE and keep quiet? It makes a special case of just about everything else... On my local dev machine, there are no such problems. So this issue is limited to GAE prod environment and happens by random. 7 out of 3 refreshes of one page fail. Anyone had similar problems or know what could cause this strange behavior?
[web2py] Re: Web2Py on GAE very slow
On Oct 24, 2011, at 11:20 AM, Damjan Malis wrote: Thanks Jonathan for clarification. I am attaching full GAE log of one of the requests, please find it below. It is quite verbose, did I miss an important setting to lower log level? GAE has its own logging rules. I think it ignores the normal log-level rules, but I don't recall the details (I'm not using GAE myself; I played with it a while back). The routing messages are normal, but we should find a way to suppress them under GAE. Are you using the Python 2.7 option, by any chance? Requests that take a lot more time get this two lines appended to previous log: 2011-10-24 20:14:32.347 no file locking, this will cause problems D 2011-10-24 20:14:33.873 URL rewrite is on. configuration in /base/data/home/apps/myfoobar/ v2.354194700247763018/portal/routes.py Are you certain that these messages are correlated with your slow responses? The routing messages (below) are associated with requests (the incoming URL is getting routed). But both the messages above are associated with web2py starting up and doing its imports. I don't understand GAE well enough to know what's going on; perhaps someone more knowledgable can suggest something. Perhaps the slow requests are hanging and forcing a restart of web2py, when ordinarily it wouldn't be necessary? I don't know 2011-10-24 20:14:42.267 select routing parameters: BASE D 2011-10-24 20:14:42.269 routes_out: [/MyFooBar/forum/index/1942002] not rewritten D 2011-10-24 20:14:42.285 routes_out: [/MyFooBar/default/index] not rewritten D 2011-10-24 20:14:42.285 routes_out: [/admin/default/design/MyFooBar] not rewritten D 2011-10-24 20:14:42.285 routes_out: [/admin/default/edit/MyFooBar/controllers/forum.py] not rewritten D 2011-10-24 20:14:42.285 routes_out: [/admin/default/edit/MyFooBar/views/forum/index.html] not rewritten D 2011-10-24 20:14:42.286 routes_out: [/admin/default/edit/MyFooBar/views/layout.html] not rewritten D 2011-10-24 20:14:42.286 routes_out: [/admin/default/edit/MyFooBar/static/base.css] not rewritten D 2011-10-24 20:14:42.286 routes_out: [/admin/default/edit/MyFooBar/models/db.py] not rewritten D 2011-10-24 20:14:42.287 routes_out: [/admin/default/edit/MyFooBar/models/menu.py] not rewritten D 2011-10-24 20:14:42.287 routes_out: [/MyFooBar/appadmin/index] not rewritten D 2011-10-24 20:14:42.287 routes_out: [/admin/default/errors/MyFooBar] not rewritten D 2011-10-24 20:14:42.287 routes_out: [/admin/default/about/MyFooBar] not rewritten D 2011-10-24 20:14:42.758 routes_out: [/MyFooBar/static/css/style.css?v=1] not rewritten D 2011-10-24 20:14:42.758 routes_out: [/MyFooBar/static/css/960_12_col.css?v=1] not rewritten D 2011-10-24 20:14:42.758 routes_out: [/MyFooBar/static/js/libs/modernizr-2.0.6.min.js] not rewritten D 2011-10-24 20:14:42.758 routes_out: [/MyFooBar/default/index] not rewritten D 2011-10-24 20:14:42.759 routes_out: [/MyFooBar/default/index] not rewritten D 2011-10-24 20:14:42.759 routes_out: [/MyFooBar/forum/index] not rewritten D 2011-10-24 20:14:42.759 routes_out: [/MyFooBar/forum/index] not rewritten D 2011-10-24 20:14:42.759 routes_out: [/MyFooBar/forum/favorite] not rewritten D 2011-10-24 20:14:42.760 routes_out: [/MyFooBar/forum/favorite] not rewritten D 2011-10-24 20:14:42.760 routes_out: [/MyFooBar/forum/index/1878001] not rewritten D 2011-10-24 20:14:42.760 routes_out: [/MyFooBar/forum/index/5770001] not rewritten D 2011-10-24 20:14:42.760 routes_out: [/MyFooBar/forum/index/1879001] not rewritten D 2011-10-24 20:14:42.761 routes_out: [/MyFooBar/forum/index/1884001] not rewritten D 2011-10-24 20:14:42.761 routes_out: [/MyFooBar/forum/index/1997010] not rewritten D 2011-10-24 20:14:42.761 routes_out: [/MyFooBar/forum/index/1880002] not rewritten D 2011-10-24 20:14:42.761 routes_out: [/MyFooBar/forum/index/1880001] not rewritten D 2011-10-24 20:14:42.762 routes_out: [/MyFooBar/forum/index/4875121] not rewritten D 2011-10-24 20:14:42.762 routes_out: [/MyFooBar/forum/index/1960001] not rewritten D 2011-10-24 20:14:42.762 routes_out: [/MyFooBar/forum/index/1942002] not rewritten D 2011-10-24 20:14:42.762 routes_out: [/MyFooBar/forum/thread/8651112] not rewritten D 2011-10-24 20:14:42.763 routes_out: [/MyFooBar/forum/thread/8648761] not rewritten D 2011-10-24 20:14:42.763 routes_out: [/MyFooBar/forum/thread/8645596] not rewritten D 2011-10-24 20:14:42.764 routes_out: [/MyFooBar/forum/thread/8584541] not rewritten D 2011-10-24 20:14:42.764 routes_out: [/MyFooBar/forum/thread/8648293] not rewritten D 2011-10-24 20:14:42.764 routes_out: [/MyFooBar/forum/thread/8630465] not rewritten D 2011-10-24 20:14:42.765 routes_out: [/MyFooBar/forum/thread/8585170] not rewritten D 2011-10-24 20:14:42.765 routes_out: [/MyFooBar/forum/thread/8580201] not rewritten D 2011-10-24 20:14:42.765 routes_out: [/MyFooBar/forum/thread/8542298] not rewritten D 2011-10-24 20:14:42.766
[web2py] Re: Web2Py on GAE very slow
Yes, I am certain that all slow requests include log msg no file locking, this will cause problems. Also, it is very rare, but some of requests fail after no file locking, this will cause problems as GAE kills such request because of time limit is reached (60sec). I will most definitely gather more useful info in days to come. I am using py 2.5 on GAE. thanks again and thanks to all for web2py On Oct 24, 9:03 pm, Jonathan Lundell jlund...@pobox.com wrote: On Oct 24, 2011, at 11:20 AM, Damjan Malis wrote: Thanks Jonathan for clarification. I am attaching full GAE log of one of the requests, please find it below. It is quite verbose, did I miss an important setting to lower log level? GAE has its own logging rules. I think it ignores the normal log-level rules, but I don't recall the details (I'm not using GAE myself; I played with it a while back). The routing messages are normal, but we should find a way to suppress them under GAE. Are you using the Python 2.7 option, by any chance? Requests that take a lot more time get this two lines appended to previous log: 2011-10-24 20:14:32.347 no file locking, this will cause problems D 2011-10-24 20:14:33.873 URL rewrite is on. configuration in /base/data/home/apps/myfoobar/ v2.354194700247763018/portal/routes.py Are you certain that these messages are correlated with your slow responses? The routing messages (below) are associated with requests (the incoming URL is getting routed). But both the messages above are associated with web2py starting up and doing its imports. I don't understand GAE well enough to know what's going on; perhaps someone more knowledgable can suggest something. Perhaps the slow requests are hanging and forcing a restart of web2py, when ordinarily it wouldn't be necessary? I don't know 2011-10-24 20:14:42.267 select routing parameters: BASE D 2011-10-24 20:14:42.269 routes_out: [/MyFooBar/forum/index/1942002] not rewritten D 2011-10-24 20:14:42.285 routes_out: [/MyFooBar/default/index] not rewritten D 2011-10-24 20:14:42.285 routes_out: [/admin/default/design/MyFooBar] not rewritten D 2011-10-24 20:14:42.285 routes_out: [/admin/default/edit/MyFooBar/controllers/forum.py] not rewritten D 2011-10-24 20:14:42.285 routes_out: [/admin/default/edit/MyFooBar/views/forum/index.html] not rewritten D 2011-10-24 20:14:42.286 routes_out: [/admin/default/edit/MyFooBar/views/layout.html] not rewritten D 2011-10-24 20:14:42.286 routes_out: [/admin/default/edit/MyFooBar/static/base.css] not rewritten D 2011-10-24 20:14:42.286 routes_out: [/admin/default/edit/MyFooBar/models/db.py] not rewritten D 2011-10-24 20:14:42.287 routes_out: [/admin/default/edit/MyFooBar/models/menu.py] not rewritten D 2011-10-24 20:14:42.287 routes_out: [/MyFooBar/appadmin/index] not rewritten D 2011-10-24 20:14:42.287 routes_out: [/admin/default/errors/MyFooBar] not rewritten D 2011-10-24 20:14:42.287 routes_out: [/admin/default/about/MyFooBar] not rewritten D 2011-10-24 20:14:42.758 routes_out: [/MyFooBar/static/css/style.css?v=1] not rewritten D 2011-10-24 20:14:42.758 routes_out: [/MyFooBar/static/css/960_12_col.css?v=1] not rewritten D 2011-10-24 20:14:42.758 routes_out: [/MyFooBar/static/js/libs/modernizr-2.0.6.min.js] not rewritten D 2011-10-24 20:14:42.758 routes_out: [/MyFooBar/default/index] not rewritten D 2011-10-24 20:14:42.759 routes_out: [/MyFooBar/default/index] not rewritten D 2011-10-24 20:14:42.759 routes_out: [/MyFooBar/forum/index] not rewritten D 2011-10-24 20:14:42.759 routes_out: [/MyFooBar/forum/index] not rewritten D 2011-10-24 20:14:42.759 routes_out: [/MyFooBar/forum/favorite] not rewritten D 2011-10-24 20:14:42.760 routes_out: [/MyFooBar/forum/favorite] not rewritten D 2011-10-24 20:14:42.760 routes_out: [/MyFooBar/forum/index/1878001] not rewritten D 2011-10-24 20:14:42.760 routes_out: [/MyFooBar/forum/index/5770001] not rewritten D 2011-10-24 20:14:42.760 routes_out: [/MyFooBar/forum/index/1879001] not rewritten D 2011-10-24 20:14:42.761 routes_out: [/MyFooBar/forum/index/1884001] not rewritten D 2011-10-24 20:14:42.761 routes_out: [/MyFooBar/forum/index/1997010] not rewritten D 2011-10-24 20:14:42.761 routes_out: [/MyFooBar/forum/index/1880002] not rewritten D 2011-10-24 20:14:42.761 routes_out: [/MyFooBar/forum/index/1880001] not rewritten D 2011-10-24 20:14:42.762 routes_out: [/MyFooBar/forum/index/4875121] not rewritten D 2011-10-24 20:14:42.762 routes_out: [/MyFooBar/forum/index/1960001] not rewritten D 2011-10-24 20:14:42.762 routes_out: [/MyFooBar/forum/index/1942002] not rewritten D 2011-10-24 20:14:42.762 routes_out: [/MyFooBar/forum/thread/8651112] not rewritten D 2011-10-24 20:14:42.763 routes_out: [/MyFooBar/forum/thread/8648761] not rewritten D 2011-10-24 20:14:42.763 routes_out: [/MyFooBar/forum/thread/8645596] not
[web2py] Re: Web2Py on GAE very slow
Damjan, i use GAE heavily, here's what i can say based on what i see: - each call to URL() puts at least one message in the debug log. so whatever you are doing has lots of calls to URL() in it. - logging can be affected by logging.conf, but i've never successfully suppressed logs i didn't care about and got logs i liked. - i don't get random deadline exceeded messages on GAE, i do get them when i write bad code. one such mistake i made was running a query in a model file (db.py) that returned lots of rows. if you can provide a simple model + controller that exhibits the problem we can help troubleshoot. christian
