Debug Jinja2 in Google App Engine

Question

When I'm running Jinja2 in Google App Engine, I get useless debugging information. I gather this is because of this item in the FAQ:

My tracebacks look weird. What’s happening?

If the speedups module is not compiled and you are using a Python installation without ctypes (Python 2.4 without ctypes, Jython or Google’s AppEngine) Jinja2 is unable to provide correct debugging information and the traceback may be incomplete. There is currently no good workaround for Jython or the AppEngine as ctypes is unavailable there and it’s not possible to use the speedups extension.

While there is no 'good' workaround for this at the moment, is there any workaround so that the information printed when exceptions arise can be made more helpful?

Thank you for reading.

Brian

Answer 1

You can get around this by adding _ctypes and gestalt to the development server's C module whitelist with monkeypatching.

To do so, put the following snippet at the top of your main.py:

import os
if os.environ.get('SERVER_SOFTWARE', '').startswith('Dev'):
    # Enable ctypes for Jinja debugging
    from google.appengine.tools.dev_appserver import HardenedModulesHook
    HardenedModulesHook._WHITE_LIST_C_MODULES += ['_ctypes', 'gestalt']

You can also use this trick to enable other C modules, if you have similar local-only module needs. Do note that these modules still won't actually work once you deploy, so tread carefully.

On SDK 1.6.3 using python2.7 you need to change the above code to:

import os
if os.environ.get('SERVER_SOFTWARE', '').startswith('Dev'):
    # Enable ctypes for Jinja debugging
    import sys
    from google.appengine.tools.dev_appserver import HardenedModulesHook
    assert isinstance(sys.meta_path[0], HardenedModulesHook)
    sys.meta_path[0]._white_list_c_modules += ['_ctypes', 'gestalt']

On SDK 1.8.6 for python 2.7, try this:

PRODUCTION_MODE = not os.environ.get(
    'SERVER_SOFTWARE', 'Development').startswith('Development')
if not PRODUCTION_MODE:
    from google.appengine.tools.devappserver2.python import sandbox
    sandbox._WHITE_LIST_C_MODULES += ['_ctypes', 'gestalt']

Answer 2

Perhaps just use PyCharm's interactive debugger and step through the code:

http://www.jetbrains.com/pycharm/quickstart/#RunAndDebug

Answer 3

I use the following monkeypatch to enable slightly more helpful information when an exception occurs during Jinja2 template rendering:

# Enabling this monkeypatch can help track down hard to find errors that crop
# up during template rendering (since Jinja's own error reporting is so
# unhelpful on AppEngine).
real_handle_exception = environment.handle_exception
def handle_exception(self, *args, **kwargs):
    import logging, traceback
    logging.error('Template exception:\n%s', traceback.format_exc())
    real_handle_exception(self, *args, **kwargs)
environment.handle_exception = handle_exception

This will result in slightly more accurate exception tracebacks in your error logs. I don't think it usually shows you exactly what went wrong (but if I remember correctly it sometimes does), but it will at least narrow the exception down to the correct template.

Why this works, I do not know (or cannot remember).

As an example, I just added some code that will trigger an exception to one of my templates. Under the development server, this is what the "normal" exception handler shows me:

Traceback (most recent call last):
  File "/Users/will/Applications/GoogleAppEngineLauncher.app/Contents/Resources/GoogleAppEngine-default.bundle/Contents/Resources/google_appengine/google/appengine/ext/webapp/__init__.py", line 511, in __call__
    handler.get(*groups)
  File "/Users/will/workspace/keypremium/ki/shared/decorators.py", line 27, in inner
    return func(self, *args, **kwargs)
  File "/Users/will/workspace/keypremium/account/views.py", line 114, in get
    self.render_jinja('accounts/edit_card.html', ctx)
  File "/Users/will/workspace/keypremium/ki/webapp/handlers.py", line 186, in render_jinja
    return self.response.out.write(jinja.render(template_path, new_context))
  File "/Users/will/workspace/keypremium/ki/shared/jinja/__init__.py", line 21, in render
    return template.render(context)
  File "/Users/will/workspace/keypremium/ki/ext/jinja2/environment.py", line 705, in render
    return self.environment.handle_exception(exc_info, True)
  File "/Users/will/workspace/keypremium/ki/shared/jinja/environment.py", line 24, in handle_exception
    real_handle_exception(self, *args, **kwargs)
  File "/Users/will/workspace/keypremium/templates/accounts/edit_card.html", line 1, in top-level template code
    {% extends 'accounts/base.html' %}
UndefinedError: 'sequence' is undefined

But the exception is not in the accounts/base.html template, it's in accounts/edit_card.html. This is the most frustrating part of debugging Jinja2 template exceptions on App Engine: The source of the exception is almost always misrepresented. In my experience, the source is usually reported as either the parent template or as some template macro.

With the exception logging monkeypatch installed, the same exception generates this traceback in the logs:

Traceback (most recent call last):
  File "/Users/will/workspace/keypremium/ki/ext/jinja2/environment.py", line 702, in render
    return concat(self.root_render_func(self.new_context(vars)))
  File "/Users/will/workspace/keypremium/templates/accounts/edit_card.html", line 11, in root
    <div class="errors">
  File "/Users/will/workspace/keypremium/templates/accounts/base.html", line 11, in root
    </html>
  File "/Users/will/workspace/keypremium/templates/accounts/edit_card.html", line 54, in block_content
    <td>{{ form.cvv2|safe }}</td>
  File "/Users/will/workspace/keypremium/ki/ext/jinja2/environment.py", line 352, in getattr
    return getattr(obj, attribute)
  File "/Users/will/workspace/keypremium/ki/ext/jinja2/runtime.py", line 445, in _fail_with_undefined_error
    raise self._undefined_exception(hint)
UndefinedError: 'sequence' is undefined

There's still a lot of extraneous information here, but this traceback at least points me in the right direction. It claims that the problem is on line 54 of accounts/edit_card.html (the correct template), but the actual exception occurs at line 86.

But given the correct template and the correct exception, I can pretty easily find that the troublesome code is this

{% for x in sequence.sequence() %}
    {{ x.y }}
{% endfor %}

where there is no sequence variable in the template context.

This isn't a perfect solution, but I've found it mighty helpful.

Answer 4

A way to avoid monkey-patching (which depends on the changing internals of the SDK) is to use the imp module, which is at least currently not disabled in the local development environment. Then just load _ctypes like this to enable better Jinja2 debugging:

import imp
file, pathname, description =  imp.find_module('_ctypes')
imp.load_module('_ctypes', file, pathname, description)

Answer 5

Not sure if that will be helpful, but it might be possible to at least add block templatetag like django's 'debug' which will at least help to localize the problem.

Answer 6

When I hit a problem like that I try to debug it on my local iPython shell. I wonder what the code that generates such a bug is. There should be a way to write a test for it.