Exception on Trac 1.4

[Massimo]

After upgrade to Trac 1.4, I found the following Traceback in the logs:

2019-11-18 14:17:00,513 Trac[web_ui] DEBUG: QuietEmailDistributor dispatching to EmailDistributor
2019-11-18 14:17:00,513 Trac[mail] DEBUG: QuietEmailDistributor has found the following formats capable of handling 'email' of 'ticket': text/plain
2019-11-18 14:17:00,514 Trac[mail] DEBUG: QuietEmailDistributor found the address 'massimo@localhost' for 'MB [1]' via SessionEmailResolver
2019-11-18 14:17:00,532 Trac[mail] WARNING: QuietEmailDistributor caught exception while formatting ticket to text/plain for email: <class 'trac.ticket.notification.TicketFormatter'>
Traceback (most recent call last):
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/trac/notification/mail.py", line 383, in distribute
    outputs[fmt] = formatter.format(transport, fmt, event)
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/trac/ticket/notification.py", line 143, in format
    return self._format_plaintext(event)
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/trac/ticket/notification.py", line 248, in _format_plaintext
    return self._format_body(data, 'ticket_notify_email.txt')
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/trac/ticket/notification.py", line 313, in _format_body
    template = chrome.load_template(template_name, text=True)
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/trac/web/chrome.py", line 1370, in load_template
    return self._load_jinja_template(filename, text)
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/trac/web/chrome.py", line 1396, in _load_jinja_template
    return (self.jenv_text if text else self.jenv).get_template(filename)
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/jinja2/environment.py", line 830, in get_template
    return self._load_template(name, self.make_globals(globals))
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/jinja2/environment.py", line 804, in _load_template
    template = self.loader.load(self, name, globals)
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/jinja2/loaders.py", line 125, in load
    code = environment.compile(source, name, filename)
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/jinja2/environment.py", line 591, in compile
    self.handle_exception(exc_info, source_hint=source_hint)
  File "/mnt/data/trac/.local/lib64/python2.7/site-packages/jinja2/environment.py", line 780, in handle_exception
    reraise(exc_type, exc_value, tb)
  File "/mnt/data/trac/projects/trac-pp/templates/ticket_notify_email.txt", line 24, in template
    pv = [(a[0].strip(), a[1].strip()) for a in [b.split(':') for b in
TemplateSyntaxError: expected token ',', got 'for'
2019-11-18 14:17:00,532 Trac[mail] DEBUG: QuietEmailDistributor is sending event as 'text/plain' to: massimo@localhost
2019-11-18 14:17:00,532 Trac[mail] WARNING: QuietEmailDistributor cannot send event 'ticket' as 'text/plain': massimo@localhost
2019-11-18 14:17:00,532 Trac[perm] DEBUG: DefaultPermissionPolicy allows MB performing TICKET_VIEW on <Resource u'ticket:1983'>
2019-11-18 14:17:00,823 Trac[main] DEBUG: Dispatching <RequestWithSession "GET '/ticket/1983'">
2019-11-18 14:17:00,823 Trac[main] DEBUG: Chosen handler is <Component trac.ticket.web_ui.TicketModule>
2019-11-18 14:17:00,825 Trac[session] DEBUG: Retrieving session for ID u'MB'

This happend on usual ticket changes and email notifications, whithout having the Quiet mode enabled.

[Jun Omae]

Your /mnt/data/trac/projects/trac-pp/templates/ticket_notify_email.txt is a Genshi template. That should be converted to a Jinja2 template to fix it.

[Jun Omae]

Replying to Jun Omae:

Your /mnt/data/trac/projects/trac-pp/templates/ticket_notify_email.txt is a Genshi template. That should be converted to a Jinja2 template to fix it.

Otherwise, remove temporally the template.

[Massimo]

I removed that. Now on ticket changes I get

2019-11-19 17:01:40,680 Trac[api] DEBUG: Adding (MB [1]) for 'always' on rule (TicketUpdaterSubscriber) for (email)
2019-11-19 17:01:40,681 Trac[web_ui] DEBUG: QuietEmailDistributor dispatching to EmailDistributor
2019-11-19 17:01:40,681 Trac[mail] DEBUG: QuietEmailDistributor has found the following formats capable of handling 'email' of 'ticket': text/plain
2019-11-19 17:01:40,681 Trac[mail] DEBUG: QuietEmailDistributor found the address 'massimo@localhost' for 'MB [1]' via SessionEmailResolver
2019-11-19 17:01:40,707 Trac[mail] DEBUG: QuietEmailDistributor is sending event as 'text/plain' to: massimo@localhost
2019-11-19 17:01:40,710 Trac[web_ui] ERROR: Failure sending notification on change to ticket #1977: TemplateSyntaxError: unexpected char u'$' at 1

Is there something else to remove?

We have some custom notification rules implemented as plugin, implementing INotificationSubscriber. Is there something to change there?

[Ryan J Ollos]

What is your ​[notification] ticket_subject_template and ​[notification] batch_subject_template?

[Jun Omae]

Replying to Massimo:

I removed that. Now on ticket changes I get

2019-11-19 17:01:40,710 Trac[web_ui] ERROR: Failure sending notification on change to ticket #1977: TemplateSyntaxError: unexpected char u'$' at 1

Please post stack trace logged below this error. I think that the stack trace is not same in description of the ticket.

[Massimo]

Replying to Ryan J Ollos:

What is your ​[notification] ticket_subject_template and ​[notification] batch_subject_template?

[notification]
batch_subject_template = Batch modify: ${tickets_descr}
ticket_subject_template = #${ticket.id}: ${summary}

[Massimo]

Replying to Jun Omae:

Please post stack trace logged below this error. I think that the stack trace is not same in description of the ticket.

At least in the trac.log with debug enabled there is no stack trace after the ERROR line.

[Jun Omae]

Reproduced it. It might be good to fix in Trac.# character is configured as ​line statement prefix in Trac. As the result, #$... in ticket_subject_template option leads the exception.

Work around is to use ${'#'} for leading # character in Jinja2 template:

[notification]
ticket_subject_template = ${'#'}${ticket.id}: ${summary}

>>> from trac.util.text import jinja2template
>>> data = {'ticket': {'id': 42}, 'summary': 'Summary...'}
>>> jinja2template('${ticket.id}', text=True).render(**data)
u'42'
>>> jinja2template('#${ticket.id}', text=True).render(**data)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "trac/util/text.py", line 86, in jinja2template
    return jinja2env(autoescape=not text).from_string(template)
  File "/venv/py27/local/lib/python2.7/site-packages/jinja2/environment.py", line 880, in from_string
    return cls.from_code(self, self.compile(source), globals, None)
  File "/venv/py27/local/lib/python2.7/site-packages/jinja2/environment.py", line 591, in compile
    self.handle_exception(exc_info, source_hint=source_hint)
  File "/venv/py27/local/lib/python2.7/site-packages/jinja2/environment.py", line 780, in handle_exception
    reraise(exc_type, exc_value, tb)
  File "<unknown>", line 1, in template
jinja2.exceptions.TemplateSyntaxError: unexpected char u'$' at 1
>>> jinja2template('${"#"}${ticket.id}', text=True).render(**data)
u'#42'

[Massimo]

Thank you very much for the workaround.

But this would mean, the issue is not about QuietPlugin, is it? This would also mean the issue happens with the Trac default as well: ​[trac] ticket_subject_template

[Jun Omae]

This would also mean the issue happens with the Trac default as well: ​[trac] ticket_subject_template

No. Default of the option is ${prefix} #${ticket.id}: ${summary}, and the issue doesn't occur because the default is not started with # character.

[Ryan J Ollos]

=> ​trac:#13225.