StackOverflow2013

Note that there are some explanatory texts on larger screens.

plurals

POVery high latency of python app engine app
text
Body
copied!<p>On both the dev server and after deployment, my app is showing very high latecy even for the lease CPU intensive request. On the dev server, a simple app that parses a JSON file could take upto 30 seconds and on appspot it's also slow with avg latency of around 800-1200ms. This same app when running in PHP responds in a couple seconds.</p> <p>I'm using a template engine (jinja2) but I know that's not the cause because I've tested without it.</p> <p>I'm left wondering If I want to keep wasting valueble time trying to optimize things and figuring out what's going on, or just going to a VPS like Linode and using PHP. The only thing holding me is the virtually unlimited memcache that app engine offers, and features like taskqueue, I like the platform overall.</p> <p>Is there a tool that I can analyse my code and tell me what's causing the latency or something? Please give me some recommendations.</p> <p><strong>cProfile trace after fixing issues found by appstats (was doing ~16s CPU, now much better):</strong> </p> <pre><code> 204343 function calls (195607 primitive calls) in 0.726 CPU seconds Ordered by: internal time List reduced from 782 to 80 due to restriction <80> ncalls tottime percall cumtime percall filename:lineno(function) 8875 0.090 0.000 0.160 0.000 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\decoder.py:96(py_scanstring) 11557 0.051 0.000 0.051 0.000 {built-in method match} 717/63 0.050 0.000 0.244 0.004 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\decoder.py:180(JSONObject) 59 0.039 0.001 0.039 0.001 {imp.find_module} 26173 0.027 0.000 0.027 0.000 {isinstance} 3315 0.023 0.000 0.023 0.000 {built-in method sub} 5535/3 0.020 0.000 0.244 0.081 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\scanner.py:32(_scan_once) 3281 0.020 0.000 0.046 0.000 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\encoder.py:45(py_encode_basestring_ascii) 1 0.017 0.017 0.017 0.017 {compile} 8084 0.015 0.000 0.063 0.000 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\encoder.py:389(_iterencode_dict) 1816 0.014 0.000 0.022 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\nodes.py:163(iter_child_nodes) 902/216 0.013 0.000 0.020 0.000 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\formatting.py:44(_format_value) 580/2 0.013 0.000 0.053 0.026 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\visitor.py:34(visit) 4 0.012 0.003 0.039 0.010 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\recording.py:578(get_call_stack) 8487 0.012 0.000 0.079 0.000 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\encoder.py:334(_iterencode_list) 20976 0.011 0.000 0.011 0.000 {method 'append' of 'list' objects} 21 0.011 0.001 0.041 0.002 C:\Program Files\Google\google_appengine\google\appengine\tools\dev_appserver_import_hook.py:1256(find_module) 1 0.010 0.010 0.016 0.016 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\environment.py:68(load_extensions) 1 0.009 0.009 0.611 0.611 C:\Program Files\Google\google_appengine\apps\myapp\webapp2.py:523(dispatch) 512 0.008 0.000 0.008 0.000 {repr} 10759 0.008 0.000 0.008 0.000 {built-in method groups} 8525 0.008 0.000 0.088 0.000 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\encoder.py:468(_iterencode) 154 0.008 0.000 0.101 0.001 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\encoder.py:192(encode) 203 0.008 0.000 0.008 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\lexer.py:227(__new__) 7/3 0.007 0.001 0.060 0.020 {imp.load_module} 11015 0.007 0.000 0.007 0.000 {built-in method end} 1 0.007 0.007 0.025 0.025 C:\Program Files\Google\google_appengine\apps\myapp\processForm.py:106(build_cities) 1 0.007 0.007 0.054 0.054 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\recording.py:21(<module>) 42/26 0.007 0.000 0.009 0.000 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\recording.py:944(synchronized_wrapper) 285 0.006 0.000 0.025 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\lexer.py:548(tokeniter) 2372 0.005 0.000 0.005 0.000 {built-in method search} 3995/3983 0.005 0.000 0.006 0.000 {getattr} 8917/8916 0.005 0.000 0.130 0.000 {method 'join' of 'unicode' objects} 685 0.004 0.000 0.011 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\_markupsafe\_native.py:14(escape) 4731 0.004 0.000 0.004 0.000 {method 'setdefault' of 'dict' objects} 695 0.004 0.000 0.005 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\environment.py:367(getattr) 3201 0.004 0.000 0.005 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\nodes.py:147(iter_fields) 225/55 0.004 0.000 0.240 0.004 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\decoder.py:272(JSONArray) 1 0.004 0.004 0.028 0.028 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\datamodel_pb.py:20(<module>) 1 0.004 0.004 0.004 0.004 C:\Program Files\Google\google_appengine\apps\myapp\processForm.py:58(cleanArray) 154 0.004 0.000 0.004 0.000 C:\Program Files\Google\google_appengine\lib\simplejson\simplejson\encoder.py:222(iterencode) 63 0.003 0.000 0.027 0.000 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\recording.py:606(get_frame_summary) 1 0.003 0.003 0.029 0.029 templates\my_template.html:60(loop) 447 0.003 0.000 0.004 0.000 C:\Program Files\Google\google_appengine\apps\myapp\processForm.py:90(calc_distance) 2668 0.003 0.000 0.003 0.000 {method 'replace' of 'unicode' objects} 1558 0.003 0.000 0.003 0.000 {hasattr} 657 0.003 0.000 0.007 0.000 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\datamodel_pb.py:234(ByteSize) 1830 0.003 0.000 0.005 0.000 C:\Program Files\Google\google_appengine\google\net\proto\ProtocolBuffer.py:372(putVarInt32) 1986 0.003 0.000 0.003 0.000 {method 'append' of 'array.array' objects} 296 0.002 0.000 0.003 0.000 {sorted} 1958 0.002 0.000 0.006 0.000 C:\Program Files\Google\google_appengine\google\net\proto\ProtocolBuffer.py:255(lengthString) 202 0.002 0.000 0.031 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\lexer.py:503(wrap) 1 0.002 0.002 0.002 0.002 C:\Program Files\Google\google_appengine\apps\myapp\processForm.py:21(buildCraigslistUrls) 578 0.002 0.000 0.004 0.000 C:\Program Files\Google\google_appengine\google\net\proto\ProtocolBuffer.py:453(putPrefixedString) 1958 0.002 0.000 0.003 0.000 C:\Program Files\Google\google_appengine\google\net\proto\ProtocolBuffer.py:241(lengthVarInt32) 114 0.002 0.000 0.003 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\nodes.py:126(__init__) 937 0.002 0.000 0.002 0.000 {built-in method __new__ of type object at 0x1E1CED38} 545/38 0.002 0.000 0.008 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\nodes.py:183(find_all) 78/6 0.002 0.000 0.082 0.014 C:\Program Files\Google\google_appengine\google\appengine\tools\dev_appserver_import_hook.py:649(Decorate) 720 0.002 0.000 0.005 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\_markupsafe\__init__.py:67(__new__) 80 0.002 0.000 0.008 0.000 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\datamodel_pb.py:414(ByteSize) 60 0.002 0.000 0.126 0.002 templates\my_template.html:5(root) 302/39 0.002 0.000 0.010 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\visitor.py:41(generic_visit) 586 0.002 0.000 0.002 0.000 C:\Python26\lib\re.py:229(_compile) 30 0.002 0.000 0.002 0.000 C:\Python26\lib\urllib.py:1192(quote) 575 0.002 0.000 0.006 0.000 C:\Python26\lib\re.py:139(search) 40 0.002 0.000 0.012 0.000 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\datamodel_pb.py:442(OutputUnchecked) 7/1 0.002 0.000 0.053 0.053 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\parser.py:844(subparse) 353 0.002 0.000 0.003 0.000 {method 'extend' of 'list' objects} 843 0.002 0.000 0.002 0.000 {method 'join' of 'str' objects} 268 0.002 0.000 0.002 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\lexer.py:237(test) 13 0.001 0.000 0.013 0.001 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\compiler.py:1212(visit_Output) 2055 0.001 0.000 0.001 0.000 C:\Program Files\Google\google_appengine\google\net\proto\ProtocolBuffer.py:244(lengthVarInt64) 241 0.001 0.000 0.006 0.000 C:\Program Files\Google\google_appengine\google\appengine\ext\appstats\datamodel_pb.py:254(OutputUnchecked) 580 0.001 0.000 0.003 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\visitor.py:26(get_visitor) 578 0.001 0.000 0.001 0.000 {method 'fromstring' of 'array.array' objects} 449 0.001 0.000 0.006 0.000 C:\Program Files\Google\google_appengine\apps\myapp\processForm.py:83(validField) 116/1 0.001 0.000 0.005 0.005 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\visitor.py:58(generic_visit) 5112 0.001 0.000 0.001 0.000 {len} 202 0.001 0.000 0.033 0.000 C:\Program Files\Google\google_appengine\apps\myapp\jinja2\lexer.py:336(next) </code></pre>

Querying!

Guidance

An individual column

Larger individual text columns get their own page to allow for proper reading.

SQuiL has stopped working due to an internal error.

If you are curious you may find further information in the browser console, which is accessible through the devtools (F12).

Reload