trac spawns enscript processes that never end

[eric@…]

I recently noticed that one of my tracd instances would fork enscript processes that'd just stay there doing nothing, and after a few days there would be hundreds of them.

I tracked it down to a problem in the mimeview renderer with a specific file and have a workaround that prevents it from happening, although it's clearly not a proper fix.

This change:

diff -Naur trac/mimeview/api.py trac-fix/mimeview/api.py
--- trac/mimeview/api.py	2009-07-21 15:09:01.000000000 +0200
+++ trac-fix/mimeview/api.py	2009-07-21 15:10:09.000000000 +0200
@@ -720,6 +720,9 @@
                                                      full_mimetype)
                         expanded_content = content.expandtabs(self.tab_width)
                     rendered_content = expanded_content
+                    if not rendered_content:
+                        self.log.debug('rendering empty content, skipping')
+                        continue
 
                 result = renderer.render(context, full_mimetype,
                                          rendered_content, filename, url)

triggers these debug messages when accessing that specific file in the browser:

2009-07-21 15:06:11,311 Trac[main] DEBUG: Dispatching <Request "GET u'/browser/trunk/contrib/patch-mpeg4ip-pascal-str.patch'">
2009-07-21 15:06:11,315 Trac[chrome] DEBUG: Prepare chrome data for request
2009-07-21 15:06:11,316 Trac[perm] DEBUG: No policy allowed anonymous performing TICKET_CREATE on None
2009-07-21 15:06:11,316 Trac[perm] DEBUG: No policy allowed anonymous performing TRAC_ADMIN on None
2009-07-21 15:06:11,316 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_GRANT on None
2009-07-21 15:06:11,316 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_REVOKE on None
2009-07-21 15:06:11,316 Trac[perm] DEBUG: No policy allowed anonymous performing TICKET_ADMIN on None
2009-07-21 15:06:11,320 Trac[browser] DEBUG: Rendering preview of node patch-mpeg4ip-pascal-str.patch@1242 with mime-type text/x-diff; charset=iso-8859-15
2009-07-21 15:06:11,320 Trac[api] DEBUG: Trying to render HTML preview using PatchRenderer [lineno]
2009-07-21 15:06:11,320 Trac[patch] DEBUG: expected +, - or \, got
2009-07-21 15:06:11,321 Trac[api] WARNING: HTML preview using <trac.mimeview.patch.PatchRenderer object at 0x8bde44c> failed (Invalid unified diff content)
Traceback (most recent call last):
  File "/usr/local/lib/python2.5/site-packages/Trac-0.11.5-py2.5.egg/trac/mimeview/api.py", line 728, in render
    rendered_content, filename, url)
  File "/usr/local/lib/python2.5/site-packages/Trac-0.11.5-py2.5.egg/trac/mimeview/patch.py", line 55, in render
    raise TracError(_('Invalid unified diff content'))
TracError: Invalid unified diff content
2009-07-21 15:06:11,321 Trac[api] DEBUG: Trying to render HTML preview using EnscriptRenderer [lineno]
2009-07-21 15:06:11,321 Trac[api] DEBUG: rendering empty content, skipping
2009-07-21 15:06:11,321 Trac[api] DEBUG: Trying to render HTML preview using PlainTextRenderer [lineno]
2009-07-21 15:06:11,321 Trac[api] DEBUG: rendering empty content, skipping

PatchRenderer fails to render the diff (because it has a trailing newline), then other renderers are given an empty string.

In the case of enscript, and without the change above, it ends up starting the enscript process (with NaivePopen) with no input piped into it, so it just blocks indefinitely.

You can get the faulty patch file at ​http://trac.handbrake.fr/export/1800/trunk/contrib/patch-mpeg4ip-pascal-str.patch

Environment: Debian Lenny x86, Python 2.5.2, Trac 0.11.5 (installed manually), lighttpd used as proxy in front of tracd

[Eric Petit <eric@…>]

I forgot to mention that other files render just fine with enscript (e.g. C files), so my guess would be that this issue only gets triggered when the enscript renderer is called as a fallback after another renderer fails.

[Christian Boos]

I recently noticed that one of my tracd instances would fork enscript processes that'd just stay there doing nothing, and after a few days there would be hundreds of them.

Ok, that counts as a serious issue for 0.11.6, if we can reproduce it ;-)

[rupert.thurner]

is enscript still necessary? i thought pygments is the most simple option, and enscript support could be dropped?

[Eric Petit <eric@…>]

I heard about enscript being dropped at some point, but since this issue doesn't seem to be in enscript itself but in Trac's rendering code, it might happen with other current and new renderers - so I figured it'd be worth looking into it.

[ebray]

Replying to Eric Petit <eric@…>:

I heard about enscript being dropped at some point, but since this issue doesn't seem to be in enscript itself but in Trac's rendering code, it might happen with other current and new renderers - so I figured it'd be worth looking into it.

We still use enscript for its VHDL support and don't have any problems with it. But I agree that for most users it's unnecessary.

Maybe the enscript renderer could be removed from the core and made a plugin. I'd be okay with that.

Of course, what I really should do is just write a VHDL lexer for Pygments. But there are only so many hours in the day :)

[Remy Blank]

I can reproduce the issue.

[Remy Blank]

There are two issues here:

• The Enscript renderer should not block when no input is passed. This is easy to fix in NativePopen.

• The content passed to render() can be a str, unicode, or any object having a read() method. This last case is problematic when a renderer fails, as the content will be consumed, and nothing will be passed to the next candidate.

I don't see an elegant solution to the latter. One possibility is to always read the full content into memory, something we do anyway when expanding tabs. Another possibility would be to require that content objects where read() must be called also define a seek() to be able to rewind to the beginning of the stream.

Or a combination of both: if the object has a 'tell() and a seek()`, we use that, otherwise we read the whole content into memory.

Thoughts?

[Remy Blank]

Oh, and EnscriptRenderer doesn't support objects with read() anyway, but that's not a problem as tabs have to be expanded beforehand, so the content is read into memory anyway.

[Remy Blank]

Simple fix, read whole content into memory.

[Remy Blank]

Should I interpret the absence of comments as "sure, go ahead"? ;-)

One additional argument in favor of reading the whole file into memory (and therefore keeping the code simple and clean) is that the maximum file size that is rendered is normally limited by the [mimeviewer] max_preview_size config option, and should therefore be low enough.

[Remy Blank]

Patch applied in [8704].

[Christian Boos]

Replying to rblank:

Should I interpret the absence of comments as "sure, go ahead"? ;-)

In this case, it was more "But what happens when rendering images… wait I should do some verifications before writing something stupid".

So, verifications being made… guess what happens now when a renderer just needs the URL (e.g. ImageRenderer)?

I think we need to address the concerns in comment:7, but only read the whole thing in memory when required, and only once. I'll try to come up with a patch.

[Remy Blank]

Replying to cboos:

In this case, it was more "But what happens when rendering images… wait I should do some verifications before writing something stupid".

Next time, just dump me the idea, and I can verify myself!

So, verifications being made… guess what happens now when a renderer just needs the URL (e.g. ImageRenderer)?

Good catch, I hadn't thought of that. So we will probably have to convert content into a lazy file-like object or something.

[Remy Blank]

Replying to cboos:

I think we need to address the concerns in comment:7, but only read the whole thing in memory when required, and only once.

This is done in [8748], by wrapping file-like objects into a file-like Content object that reads the content into a StringIO when required, and can be reset for the next candidate.