Dlaczego funkcja Django (1.5.1) wywoływałaby funkcję Loader.load_template_source() 69 razy?

Mój problem pierwotnie objawił się jako błąd "maksymalnej przekroczonej głębokości rekursji" w dość sprytnym ListView. Po przekopaniu znalazłem mnóstwo cache'ów pochodzących z dbtemplates za każdą próbę załadowania odpowiedniej strony. To skłoniło mnie do napisania własnego programu ładującego szablon, w którym to momencie okazało się, że Django wywołuje dokładnie sześćdziesiąt dziewięć razy za każdym razem, gdy strona jest ładowana.Dlaczego funkcja Django (1.5.1) wywoływałaby funkcję Loader.load_template_source() 69 razy?

Dlaczego Django miałby wielokrotnie dzwonić pod numer load_template_source?

visitor_index (szablon dB)

<!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 (aktualizacja z śladu)

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())) 

[...]

Źródło

2013-05-08 Wes

Czy możesz pokazać swoje ustawienie "TEMPLATE_LOADERS"? Wygląda na to, że jest to problem z konfiguracją. – alecxe

Oczywiście, zaktualizowałem pytanie, dołączając "TEMPLATE_LOADERS". – Wes

I powielana swój projekt bez dowolnym problemu.

Program ładujący jest wywoływany tylko raz bez żadnej rekursji. Dodałem również kilka prostych niezbędnych plików: videos/models.py, a także wideo/admin.py, dbtemplates/admin.py, aby dodać dwa nagrania Wideo i jeden szablon nagrania, który zapętla wideo: {% for video in videos %}...{% endfor %}

Nadal mogę nie wierzę, że rekurencja jest możliwa w Loader.load_template_source(). Więcej informacji jest konieczne. Postaraj się traceback z każdej rozmowy swojego Loader dodając te dwie linie do niego:

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

(obawiam się, że pętla lub rekurencji pochodzi z innego kodu, który zrodził wiele wątków, że wszyscy czekają przed operacja w bazie, aż operacja aktualnie uruchomione zostaną zakończone)

EDIT. problemem jest spowodowane django-debug-pasku.

Kursor bazy danych jest zawijany przez kod monitorujący debug_toolbar.
Próbuje dokonać introspekcji w stosie dla template_info szablonu używanego przez render.
Template_info używa przeładowania szablonu.
To znowu wymaga dostępu do bazy danych.

Można wyłączyć niektóre elementy paska narzędzi do debugowania związane z bazą danych lub szablonami (nie testowane, aby pomóc) lub całkowicie je wyłączyć. Operacje na bazach danych są bardzo dobrze monitorowane przez Django, a to samo zrobione przez pasek debugowania jest teraz mniej ważne.

Źródło

2013-05-09 23:00:00 hynekcer

Dzięki za poświęcenie czasu, aby spróbować odtworzyć to, hynekcer. Dostałem traceback, gdy zażądałeś i zaktualizowałeś część app.log mojego pytania z wynikami. – Wes

To załatwiło sprawę! Dziękuję bardzo za rozpatrzenie mojego pytania. To ogromna pomoc. Nawiasem mówiąc, próbowałem wyłączyć panele SQL i szablony indywidualnie przed odinstalowaniem aplikacji i oprogramowania pośredniego, ale bez efektu. – Wes

Dzięki hynekcer! Miałem podobny problem i zajęłoby to całe wieki. W moim przypadku usunięcie panelu "debug_toolbar.panels.sql.SQLDebugPanel" z django-debug-toolbar rozwiązało problem. –

Dlaczego funkcja Django (1.5.1) wywoływałaby funkcję Loader.load_template_source() 69 razy?

Odpowiedz

Powiązane problemy