Django - Template rendering performance (I think) how to check if enabling LocMemCache is working?

Question

Ive noticed that randomly some pages take from 2 to 12 seconds to load, I have Debug toolbar installed and I know my queries are all efficient (i.e. no duplicates) and toolbar shows they are all running in milliseconds.

One particular page ive decide to focus on is my search page which uses haystack and elastic search.

I have a function which queries haystack and I have a timer that runs at the beginning of the server side function and the end and then churns out the query time, this Varys from 0.01 to 0.2 seconds, either way pretty fast (example of view below). but the page can take extremely long to load randomly.

ive added template timings panel to DJDT however it doesnt support Django 2.x, but it does still show a timings result which was varying from 2000ms to 10000ms+

Which lead me to research the template rendering where I come across this post (django: guidelines for speeding up template rendering performance). Whilst im not au fait with a lot of the things that are mentioned, I did look into caching. I have added the below to my settings.py file:

CACHES = {
    'default': {
        'BACKEND': 'django.core.cache.backends.locmem.LocMemCache',
        'LOCATION': 'unique-gugu-cache',
    }
}

TEMPLATES = [
    {
        'BACKEND': 'django.template.backends.django.DjangoTemplates',
        'DIRS': [
            BASE_DIR + '/templates/',
            ],
        'APP_DIRS': False,
        'OPTIONS': {
            'debug' : DEBUG,
            'context_processors': [
                'django.template.context_processors.debug',
                'django.contrib.auth.context_processors.auth',
                'django.contrib.messages.context_processors.messages',
                'django.template.context_processors.media',
                'django.template.context_processors.static',
                'django.template.context_processors.request',
                'django.template.context_processors.i18n',
                'itapp.context_processors.site_links',
                'itapp.context_processors.quick_jump_links',
            ],
            'loaders': [
            ('django.template.loaders.cached.Loader', [
                'django.template.loaders.filesystem.Loader',
                'django.template.loaders.app_directories.Loader',
            ]),
        ],
        },
    },
]

and in my base template I have a menu that shows or hides items based on permissions and also renders a menu based on types of site from a model, so I thought this would be a good thing to cache, as once the menu has been decided for a user and the db has been queried it doesnt change. (at least I think this is what I should be doing?)

so I added the below to my base template:

{% load static %} {% load extras %} {% load i18n %} {% load cache %}
{% cache 500 sidebar %}
{% if user.is_active and user.is_staff %}
 <a class="dropdown-item preview-item" href="{% url 'admin:index' %}">    
    <p class="preview-subject mb-1">{% trans 'Admin' %}</p>
...
 {% if user.is_authenticated %}
...etc all the html and template logic for the side bar
{% end cache %}

So my question is, do I have the correct approach here? and how do I know if the caching of the side bar is actually working or not? other than waiting to see if a page loads slowly or not how can I prove it?

Thank you

Views.py

@login_required
def search(request):
    from haystack.query import SearchQuerySet
    from haystack.inputs import AutoQuery, Exact, Clean
    from django.core.paginator import Paginator, EmptyPage, PageNotAnInteger
    start = datetime.now()

    query = request.GET['q']
    sqs = SearchQuerySet().filter(content=AutoQuery(query))

    results = sqs
    result_count = results.count()

    end = datetime.now()
    search_duration = (end - start).total_seconds()

    return render(request, 'search/search_no_pag.html', {
        'result_count' : result_count,
        'query' : query,
        'results': results,  
        'search_duration' : search_duration
    })  

Northeasterly

Create a repro project on GitHub. – Antimasque

Answer 1

The best results you would get from actually monitoring your application on production. It can be anything starting from HTTP logs with time in it or full fledged APM dedicated to Django that can summarize template rendering per view.

That's how you know:

1. If you should optimize at all
2. What to optimize
3. If whatever you've changed actually helped
4. When to stop optimizing

Please look at the example there: https://scoutapm.com/blog/monitoring-a-django-app-with-scout

If the "rendering" part gets smaller after deployment compared to similar working conditions, that is the way you can prove something has helped.

Starting from Django 1.11 the cached loader is enabled by default if you don't run with DEBUG mode.

This loader is automatically enabled if OPTIONS['loaders'] isn’t specified and OPTIONS['debug'] is False (the latter option defaults to the value of DEBUG).

https://docs.djangoproject.com/en/2.2/ref/templates/api/#django.template.loaders.cached.Loader

Which brings me to my last point: your problems are probably caused by DEBUG mode. Which brings me to my first sentence: measure performance on production.

Gautier

thank you, is there any open source alternatives to scout? – Northeasterly

@Northeasterly try jaegertracing.io with opentracing.io clients. – Gautier

Answer 2

Your problem may be the debug toolbar itself. Remove DT and try again, but use another tool like newrelic.

Mannerless