Code

Opened 9 years ago

Closed 8 years ago

Last modified 8 years ago

#603 closed defect (fixed)

Improved template error messages

Reported by: rjwittams Owned by: adrian
Component: Template system Version:
Severity: normal Keywords:
Cc: Triage Stage: Unreviewed
Has patch: no Needs documentation: no
Needs tests: no Patch needs improvement: no
Easy pickings: UI/UX:

Description (last modified by rjwittams)

Template errors are annoying to find. This patch adds filename and line numbers to the error messages when the DEBUG setting is true.

Extracted from the new-admin branch.

Attachments (4)

django-template-errors.patch (10.6 KB) - added by rjwittams 9 years ago.
patch. Apply in the directory django/core/
django-template-errors-2.patch (13.1 KB) - added by rjwittams 9 years ago.
updated patch
django-template-errors-3.patch (16.1 KB) - added by rjwittams 9 years ago.
moved files with template reorg, fixes lexing bug.
django-template-errors-4.patch (16.4 KB) - added by anonymous 9 years ago.
updated for apploaders and got rid of exceptions in normal path of debug lexer.

Download all attachments as: .zip

Change History (20)

Changed 9 years ago by rjwittams

patch. Apply in the directory django/core/

comment:1 Changed 9 years ago by adrian

At first glance, I don't like adding that much code to tokenize(). Seems like it would slow down template compilation. Have you benchmarked this against the existing template system?

This is precisely why, when we wrote the template system, we intentionally avoided keeping track of line numbers. It was too much of an unneeded performance loss.

comment:2 Changed 9 years ago by C8E

What do you think about using

if DEBUG:

to conditionally enable this useful feature? In debug mode who cares of a little slow down, if it gives you more information about what's goin' on?

comment:3 Changed 9 years ago by robert@…

How about we actually find out what the performance impact is before dismissing it out of hand?

comment:4 Changed 9 years ago by adrian

Robert: That's why I asked whether you'd benchmarked it. :)

comment:5 Changed 9 years ago by robert@…

With this (copying the different copies of template.py to template_old and template_new) :

import timeit

t = open("admin_change_form.html").read()

old = timeit.Timer('tokenize(t)',
                   'from template_old import tokenize; from __main__ import t')
new = timeit.Timer('tokenize(t, "name")',
                   'from template_new import tokenize; from __main__ import t')

old_time = old.timeit(number=20000)
new_time = new.timeit(number=20000)

print "Old %s, new %s " % (old_time, new_time)

I get:

Old 19.277905941, new 33.4315948486

So a slightly more than 50% slowdown. Of course this says nothing about the impact in the real world with caching etc, and I really doubt this has a significant impact on overall runtime.

comment:6 Changed 9 years ago by robert@…

Ok, so I did some profiling using django-admin.py ( turned off the autoreloader as profile.py seems confused by threads).
This wasn't very scientific, and not a comparison, just wanted to get an idea of how much time is spent in tokenize.

So after messing about for a while, clicking around in the admin, it turns out that out of a CPU time of 3.5 seconds, 0.07 was used in tokenize. So if the penalty above holds, we are talking about a penalty of around 0.7% with no caching, in a very template heavy setting ( the new admin system, which does a lot of template inclusion via custom tags, no caching of compilation even in the same request at the moment) What do people think about that?

One surprise when I first looked at the template system: I didn't find anywhere compiled templates are cached, as half implied at:

http://www.djangoproject.com/documentation/templates_python/


_Behind the scenes_

The system only parses your raw template code once -- when you create the Template object. From then on, it's stored internally as a "node" structure for performance.


I think we should change this somehow. Reading this I was expecting compilation to only occur when the file changed, ie caching between requests. I get why that reading is wrong, but currently it makes it sound a lot better than it really is. (Almost every template is going to be compiled once and rendered once.) I think some form of optional compiled template caching would be possible and desirable in future, eg via memcached ( Or am I missing something?)

One thing that popped out during profiling was that parsing filters is taking quite long, possibly due to function call overhead ( at least a call to next_char for every character.) Could probably save more time there, and this is per render rather than at compile time.

comment:7 Changed 9 years ago by jacob

"""
I think some form of optional compiled template caching would be possible and desirable in future, eg via memcached ( Or am I missing something?)
"""

Yes, actually -- turns out that the cost of a cache miss is *more* than the cost of compiling a template (we profiled this about a year ago, so it may have changed in the meantime). So it turns out it's easier to just parse the template when it's needed. Premature optimization, and all that. Still, optional template caching might be a speed increase in some situations -- say, a given view gets hit far more often than others -- so I'm more than open to suggestions.

Great point about parsing filters -- I imagine there's a similar issue with template tag calls, as well. Stupid function call overhead... any ideas?

comment:8 Changed 9 years ago by robert@…

"turns out that the cost of a cache miss is *more* than the cost of compiling a template"

Erm: a cache miss would be compiling a template + finding out it was a miss, so I would expect it to cost more than just the former... do you mean a hit?

I can't see any obvious way to reduce the overhead for template tags without making them suck. Also, they didn't show up as a big issue afaik. The filter stuff could certainly be done in loops etc.

Changed 9 years ago by rjwittams

updated patch

comment:9 Changed 9 years ago by rjwittams

  • Description modified (diff)

Ok, so I gave in and made this just an option that gets enabled when DEBUG = true.

encapsulated tokenize and create_token in a Lexer class, then subclassed Lexer and Parser for debugging specific behaviour. So now this has no performance hit when people are not debugging.

Robert

comment:10 Changed 9 years ago by rjwittams

There is a horrible lexing bug I introduced here - praise be to unit tests! . Fix is in new-admin.
Will extract the patch soon and upload it - also updated for template re-org.

All this patch synchronisation has convinced me to try out svk ;-)

Changed 9 years ago by rjwittams

moved files with template reorg, fixes lexing bug.

Changed 9 years ago by anonymous

updated for apploaders and got rid of exceptions in normal path of debug lexer.

comment:11 Changed 8 years ago by rjwittams

This is kind of out of date.
Should I make a new patch or is it ok to assume this will go in with the rest of new-admin?

comment:12 Changed 8 years ago by adrian

  • Resolution set to fixed
  • Status changed from new to closed

(In [1379]) Fixed #603 -- Added template debugging errors to pretty error-page output, if TEMPLATE_DEBUG setting is True. Also refactored FilterParser for a significant speed increase and changed the template_loader interface so that it returns information about the loader. Taken from new-admin. Thanks rjwittams and crew

comment:13 Changed 8 years ago by 껑유중

<A HREF="http://www.xdx.jp.pn" target="_blank">

(최,대규,모)일.본.뽀.르.노.p.2.p 공,유,중

http://www.xdx.jp.pn

http://www.xdx.jp.pn

삭/제 momo8

</a>

comment:14 Changed 8 years ago by eric@…

  • Resolution fixed deleted
  • Status changed from closed to reopened
  • Type changed from enhancement to defect

When Debug=False, django emails the errors but the template source is missing.

comment:15 Changed 8 years ago by rjwittams

  • Resolution set to fixed
  • Status changed from reopened to closed

Open a new bug for a new issue.

comment:16 Changed 8 years ago by Seer

Hi all
im fine, gl all!

Add Comment

Modify Ticket

Change Properties
<Author field>
Action
as closed
as The resolution will be set. Next status will be 'closed'
The resolution will be deleted. Next status will be 'new'
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.