Logo Questions Linux Laravel Mysql Ubuntu Git Menu
HTML CSS JAVASCRIPT SQL PYTHON PHP BOOTSTRAP JAVA JQUERY R React Kotlin
 

Why would Django (1.5.1) call Loader.load_template_source() 69 times?

Tags:

django

django-views

django-templates

django-debug-toolbar

My problem originally manifested as a "maximum recursion depth exceeded" error in a fairly run-of-the-mill ListView. After digging around, I found a ton of cache hits originating in dbtemplates for every attempt I made to load the corresponding page. This prompted me to write my own template loader, at which point it became apparent that Django is calling load_template_source exactly sixty-nine times every time the page is loaded.

Why would Django call load_template_source multiple times?

visitor_index (db template)

<!DOCTYPE html>
<html lang="en">
    <head>
        <title>{{ site.name }}</title>
    </head>
    <body id="home">
    <pre>
        Starting
        {% for video in videos %}
            {{ video.headline }}
        {% endfor %}
    </pre>
    </body>
</html>

urls.py

from django.conf.urls import include, url
from django.conf.urls.defaults import patterns
from videos.views import *

urlpatterns = patterns('',
    url(r'^$', VisitorIndex.as_view(), name='index'),
)

views.py

import logging
from django.views.generic import ListView
from videos.models import Video

logger = logging.getLogger(__name__)

class VisitorIndex(ListView):
    context_object_name = 'videos'
    template_name = 'visitor_index'

    def get_queryset(self):
        logger.debug('VisitorIndex.get_queryset()')
        return Video.on_site.filter(privacy_mode='PUB')

loader.py

import logging
from django.template import TemplateDoesNotExist
from django.template.loader import BaseLoader
from dbtemplates.models import Template

logger = logging.getLogger(__name__)

class Loader(BaseLoader):
    is_usable = True

    def load_template_source(self, template_name, template_dirs=None):
        try:
            logger.debug('Loader.load_template_source(%s, %s)' % (template_name, template_dirs))
            template = Template.on_site.get(slug__exact=template_name).template_body
            logger.debug('Loaded template.')
            return template, template_name
        except Template.DoesNotExist:
            logger.debug('Template.DoesNotExist caught.')
            raise TemplateDoesNotExist, template_name

models.py

import logging
from django.contrib.sites.models import Site
from django.contrib.sites.managers import CurrentSiteManager
from django.db import models

logger = logging.getLogger('__name__')

class Template(models.Model):
    slug = models.CharField(max_length=80)
    template_body = models.TextField()
    site = models.ForeignKey(Site)

    objects = models.Manager()
    on_site = CurrentSiteManager('site')

    def __unicode__(self):
        return self.slug

settings.py

TEMPLATE_LOADERS = (
    'django.template.loaders.filesystem.Loader',
    'django.template.loaders.app_directories.Loader',
    'dbtemplates.loader.Loader',
)

app.log (updated with trace)

2013-05-09 19:15:43,634 [DEBUG] dynamicsites.middleware: ENV_HOSTNAMES lookup subdomain=None domain=mydomain.com domain_unsplit=mydomain.com
2013-05-09 19:15:43,634 [DEBUG] dynamicsites.middleware: Checking database for domain=mydomain.com
2013-05-09 19:15:43,679 [DEBUG] dynamicsites.middleware: Using site id=2 domain=mydomain.com
2013-05-09 19:15:43,714 [DEBUG] videos.views: VisitorIndex.get_queryset()
2013-05-09 19:15:43,716 [DEBUG] django.template.response: SimpleTemplateResponse.rendered_content()
2013-05-09 19:15:43,717 [DEBUG] django.template.response: Start self.resolve_template()
2013-05-09 19:15:43,717 [DEBUG] django.template.response: SimpleTemplateResponse.resolve_template().  Found list or tuple.
2013-05-09 19:15:43,717 [DEBUG] django.template.response: Calling loader.select_template(template=['visitor_index', u'videos/video_list.html'])
2013-05-09 19:15:43,720 [DEBUG] dbtemplates.loader: Loader.load_template_source(visitor_index, None)
2013-05-09 19:15:43,722 [DEBUG] dbtemplates.loader:   File "/usr/lib/python2.7/threading.py", line 525, in __bootstrap
    self.__bootstrap_inner()
  File "/usr/lib/python2.7/threading.py", line 552, in __bootstrap_inner
    self.run()
  File "/usr/lib/python2.7/threading.py", line 505, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/usr/lib/python2.7/SocketServer.py", line 593, in process_request_thread
    self.finish_request(request, client_address)
  File "/usr/lib/python2.7/SocketServer.py", line 334, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/core/servers/basehttp.py", line 150, in __init__
    super(WSGIRequestHandler, self).__init__(*args, **kwargs)
  File "/usr/lib/python2.7/SocketServer.py", line 649, in __init__
    self.handle()
  File "/usr/lib/python2.7/wsgiref/simple_server.py", line 124, in handle
    handler.run(self.server.get_app())
  File "/usr/lib/python2.7/wsgiref/handlers.py", line 85, in run
    self.result = application(self.environ, self.start_response)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/contrib/staticfiles/handlers.py", line 72, in __call__
    return self.application(environ, start_response)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/core/handlers/wsgi.py", line 255, in __call__
    response = self.get_response(request)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 140, in get_response
    response = response.render()
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/response.py", line 121, in render
    self.content = self.rendered_content
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/response.py", line 91, in rendered_content
    template = self.resolve_template(self.template_name)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/response.py", line 60, in resolve_template
    t = loader.select_template(template)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/loader.py", line 188, in select_template
    return get_template(template_name)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/loader.py", line 146, in get_template
    template, origin = find_template(template_name)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/loader.py", line 135, in find_template
    source, display_name = loader(name, dirs)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/loader.py", line 43, in __call__
    return self.load_template(template_name, template_dirs)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/loader.py", line 46, in load_template
    source, display_name = self.load_template_source(template_name, template_dirs)
  File "/home/wesley/howl/dbtemplates/loader.py", line 19, in load_template_source
    logger.debug(''.join(traceback.format_stack()))

2013-05-09 19:15:43,885 [DEBUG] dbtemplates.loader: Loaded template.
2013-05-09 19:15:43,886 [DEBUG] django.template.response: Done.
2013-05-09 19:15:43,887 [DEBUG] django.template.response: Done.  <django.template.base.Template object at 0x7fbdf8215050>
2013-05-09 19:15:43,887 [DEBUG] django.template.response: Start self.resolve_context()
2013-05-09 19:15:43,920 [DEBUG] django.template.response: Start template.render(context)
2013-05-09 19:15:43,920 [DEBUG] django.template.base: Template.render(context)
2013-05-09 19:15:43,920 [DEBUG] django.template.base:     context.render_context.push()
2013-05-09 19:15:43,920 [DEBUG] django.template.base:     Done.
2013-05-09 19:15:43,921 [DEBUG] django.template.base: Try self._render(context)
2013-05-09 19:15:43,932 [DEBUG] dbtemplates.loader: Loader.load_template_source(visitor_index, None)
2013-05-09 19:15:43,933 [DEBUG] dbtemplates.loader:   File "/usr/lib/python2.7/threading.py", line 525, in __bootstrap
    self.__bootstrap_inner()
  File "/usr/lib/python2.7/threading.py", line 552, in __bootstrap_inner
    self.run()
  File "/usr/lib/python2.7/threading.py", line 505, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/usr/lib/python2.7/SocketServer.py", line 593, in process_request_thread
    self.finish_request(request, client_address)
  File "/usr/lib/python2.7/SocketServer.py", line 334, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/core/servers/basehttp.py", line 150, in __init__
    super(WSGIRequestHandler, self).__init__(*args, **kwargs)
  File "/usr/lib/python2.7/SocketServer.py", line 649, in __init__
    self.handle()
  File "/usr/lib/python2.7/wsgiref/simple_server.py", line 124, in handle
    handler.run(self.server.get_app())
  File "/usr/lib/python2.7/wsgiref/handlers.py", line 85, in run
    self.result = application(self.environ, self.start_response)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/contrib/staticfiles/handlers.py", line 72, in __call__
    return self.application(environ, start_response)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/core/handlers/wsgi.py", line 255, in __call__
    response = self.get_response(request)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 140, in get_response
    response = response.render()
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/response.py", line 121, in render
    self.content = self.rendered_content
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/response.py", line 97, in rendered_content
    content = template.render(context)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/base.py", line 146, in render
    return self._render(context)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/test/utils.py", line 65, in instrumented_test_render
    return self.nodelist.render(context)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/base.py", line 837, in render
    bit = self.render_node(node, context)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/debug.py", line 74, in render_node
    return node.render(context)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/defaulttags.py", line 148, in render
    len_values = len(values)
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/db/models/query.py", line 90, in __len__
    self._result_cache = list(self.iterator())
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/db/models/query.py", line 301, in iterator
    for row in compiler.results_iter():
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/db/models/sql/compiler.py", line 775, in results_iter
    for rows in self.execute_sql(MULTI):
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/db/models/sql/compiler.py", line 840, in execute_sql
    cursor.execute(sql, params)
  File "/home/wesley/howl/debug_toolbar/utils/tracking/db.py", line 134, in execute
    template_info = get_template_info(node.source)
  File "/home/wesley/howl/debug_toolbar/utils/__init__.py", line 80, in get_template_info
    template_source = origin.reload()
  File "/home/wesley/environments/howl/local/lib/python2.7/site-packages/django/template/loader.py", line 80, in reload
    return self.loader(self.loadname, self.dirs)[0]
  File "/home/wesley/howl/dbtemplates/loader.py", line 19, in load_template_source
    logger.debug(''.join(traceback.format_stack()))

[...]
like image 708
Wes Avatar asked Oct 04 '22 04:10

Wes

1 Answers

I reproduced your project without any problem.

The Loader is called only once without any recursion. I added also some simple necessary files: videos/models.py and also videos/admin.py, dbtemplates/admin.py in order to add two records Video and one record Template that loops over videos: {% for video in videos %}...{% endfor %}

I still can not believe that a recursion is possible in Loader.load_template_source(). More information is necessary. Try to get a traceback from every call of your Loader by adding these two lines to it:

...
logger.debug('Loader.load_template_source......')
import traceback                                  # added
logger.debug(''.join(traceback.format_stack()))
...

(I am afraid that a loop or a recursion originated in other code that spawned many threads that all wait before the database operation until the currently running operation will be finished.)

EDIT: The problem is caused by django-debug-toolbar.

  • The database cursor is wrapped by debug_toolbar monitoring code.
  • It tries to introspect into the stack for the template_info of the template used by render.
  • Template_info uses template reloading.
  • That again needs the access to the database.

You can disable some parts of debug toolbar related to the database or to templates (not tested that it helps) or disable it completely. Database operations are very good monitored by Django itself and the same done by debug toolbar is less important now.

like image 102
hynekcer Avatar answered Oct 10 '22 00:10

hynekcer
Sign in to Comment

Related questions

Neo4django Relationship properties
Creating a new directory in Heroku
How to remove unsafe inline code for Content Security Policy?
Loading dictionary object causing memory spike
Django - how to change FileField upload_to path during testing
No module named registration.backends.default.urls
How to mention users with "@" in app like Instagram
Is a `django model` type abstraction available for c++?
Why does os.kill(pid, 0) return None although process has terminated?
Error loading pyodbc module while running on Apache
unable to create superuser after syncdb
Django upload and handle CSV file with right encoding
Django Forms : disable field if booleanfield is checked
Komodo 7 or 8 code completion for django
Django: How to integrate an app inside another app
How to register celery tasks across apps/projects in Django?
How to create a queryset that filters multiple fields based on a single condition in Django?
Cannot debug error message for psycopg2 with django and postgreSQL
Bulk Update data in Django Rest Framework
Django admin ordering in reverse

Donate For Us

If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!