Server error: malformed header

[ntmlod]

When I noticed that the HTML escape sequences weren't interpreted in field default content, I upgraded to the trunk.

I got my usual tag importing problem

tracforms/api.py

@@ -9 +9 @@
 from trac.resource import IResourceManager, ResourceNotFound, \
                           get_resource_name, get_resource_shortname, \
                           get_resource_url
-from trac.util.html import tag
+from trac.util.html import html as tag
 from trac.util.translation import domain_functions
 from trac.web import IRequestHandler
 from trac.web.api import HTTPBadRequest

tracforms/util.py

@@ -7 +7 @@
 import codecs
 
 from trac.resource import ResourceSystem
-from trac.util.html import tag
+from trac.util.html import html as tag
 from trac.util.text import to_unicode
 
 from api import tag_

tracforms/web_ui.py

@@ -8 +8 @@
                           get_resource_shortname, get_resource_url
 from trac.search.api import ISearchSource, shorten_result
 from trac.util.datefmt import to_datetime
-from trac.util.html import tag
+from trac.util.html import html as tag
 from trac.web.api import IRequestFilter, IRequestHandler
 from trac.web.chrome import ITemplateProvider, add_ctxtnav, add_stylesheet
 

Then I reloaded my page with forms and got a server crash: malformed header from script 'trac.cgi': Bad header: (('wiki', u'PageTemplates/Work

The page name is not good as it missed the remainder of the name ('WorkPlanAction').
I remember having a similar server issue with WorkflowActionButtonsPlugin #12960 but after review it's probably not related at all.

[ntmlod]

I forgot to add that's the logging of the crash doesn't raise any unexpected events.

[Ryan J Ollos]

In 16946:

TracForms 0.5dev: Revise r16384 from compatibility with Trac < 1.0.2

Refs #13319.

[ntmlod]

Updated but the server still crashs with the same message

[Ryan J Ollos]

Yes, r16946 simply contains your Trac < 1.0.2 compatibility fix in comment:description.

[ntmlod]

Oh my bad I looked at the wrong changeset, with so many differences I thought it contains other stuff besides my small contribution.

[Ryan J Ollos]

In 16954:

TracForms 0.5dev: Show traceback on exception

Refs #13319.

[Ryan J Ollos]

You should get a more useful error message after r16954.

[ntmlod]

Not really, the same crash for the server and no additional warning in the log.

[Ryan J Ollos]

In 16958:

TracForms 0.5dev: Log exception from macro

Refs #13319.

[Ryan J Ollos]

You might get more information in the log after r16958. Otherwise, I'll need to see markup that reproduces the issue.

[ntmlod]

This issue definitely doesn't want to be traced.

For the rest of it, do you mean having the code of the page with ?hdfdump=1

[Ryan J Ollos]

Replying to ntmlod:

For the rest of it, do you mean having the code of the page with ?hdfdump=1

I need to see example of wiki markup that results in the error.

[ntmlod]

I have redacted most of the content while trying to keep the structure used with special syntax.

In particular, my wiki template form is combined with ParametrizedTemplatesPlugin and ExtractUrlPlugin

= \'\'\'\'\'{{Xxxxxx, Xxxxx, text,
xxxxxxxxxxxxxxxx}}\'\'\'\'\'\r\n\r\nxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\r\n\r\n==
xxxx\r\n\r\nxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx[[span(XXXX,
style=background-color:lightgrey)]], [[span(Xxxxxxxxxx, style
=background-color:lightblue)]] and [[span(Xxxxxxxx, style=background-
color:lightgreen)]].\\\\\r\nxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\r\n\r\n==
Xxxxxxxxx #xxxxxx\r\n\r\n||= \'\'\'Xxxxxx\'\'\'       =|| {{xxxxxx,
Xxxxxx, text, xxxxxxxxxxxxxxxx}}             ||\r\n||= \'\'\'XXX\'\'\'
=|| {{XXX, Xxxxxxxxxx, text, Xxxxxx}}
||\r\n{{{#!th\r\n\r\n\'\'\'Xxxxx\'\'\'\r\n\r\n}}}\r\n{{{#!td\r\n\r\n{{xxxxx,
Xxxxxx, textarea, Xxxxxxxxxxxxxxxxxxxxxx}}\r\n\r\n}}}\r\n|-\r\n
||\r\n||= \'\'\'Xxxxxx\'\'\'  =|| #0000
||\r\n||= \'\'\'Xxxxxxx\'\'\'   =|| [source:/branches/.....] ||\r\n||=
\'\'\'Xxxxx\'\'\'         =|| [[ExtractUrl(.)]]
||\r\n\r\n{{{#!comment\r\n\r\nXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX\r\n\r\n}}}\r\n==
==\r\n{{{#!comment\r\n\r\nXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXx\r\n\r\n}}}\r\n\r\n{{{#!Fold
title=Xxxxxx
tag=h2\r\n[=#xxxxxxx]\r\n\r\nxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\r\n\r\n{{{#!TracForm\r\n#!subcontext
xxxxxxx\r\n#!submit_label \'Save Xxxxxxxxx\'\r\n#!keep_history
yes\r\n\r\n=== Xxxxxxxxxx\r\n\r\n [tf.textarea:xxxxxxx -id=xxxx
-class=xxxx \'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\' 0
20]...........................................................\r\n\r\n\'\'\'\'\'Updated
on [tf.form_updated_on:] by
[tf.form_updater:]\'\'\'\'\'\r\n\r\n}}}\r\n\r\nxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\r\n\r\n}}}\r\n\r\n{{{#!Fold
title=Xxxxxxx
tag=h2\r\n[=#xxxxxx]\r\n\r\nxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\r\n\r\n{{{#!TracForm\r\n#!subcontext
xxxxxx_\r\n#!submit_label \'Save Xxxxxx\'\r\n\r\n||= Xxxxxxxx =||=
Xxxxxxx =||= Xxxxxx =||\r\n||
Xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx || [tf.select:2.1
-id=xxxxxx \'\' Yes No NR] || [tf.textarea:x.x -id=xxxxxx \'Xxxxxxxxxx\'
50 10]
||\r\n||.................................................................\r\n\r\n\'\'\'\'\'Updated
on [tf.form_updated_on:] by
[tf.form_updater:]\'\'\'\'\'\r\n\r\n}}}\r\n\r\n

[Ryan J Ollos]

I'm not sure what that is, I guess it's the redacted content copied from the output of hdfdump.

If you want me to debug this you will need to generate a minimal example of wiki markup that I can paste into a wiki page to reproduce the issue. That is, the content that is placed between the opening and closing brackets of a WikiProcessor calls: {{{#!TracForm and }}}.

[ntmlod]

The fact is the page has multiple calls of TracForms WikiProcessors, 4 to be specific, and I'm not very comfortable to paste all this stuff here.

Could I send it to you by email ?

[Ryan J Ollos]

I was hoping you could provide a minimal example of the call to reproduce the issue. For example, create a test page and start adding form content until the issue is reproduced. Can you experiment a bit to try and provide that minimal example?

[ntmlod]

Replying to Ryan J Ollos:

I was hoping you could provide a minimal example of the call to reproduce the issue. For example, create a test page and start adding form content until the issue is reproduced. Can you experiment a bit to try and provide that minimal example?

Sure, I was a bit lazy on this.

After few tests with my template I come to the conclusion that's the wiki content doesn't seem to be involved here.
All templates edited by removing one by one each TracForms section crashed when switching to 0.5dev, finally I create a page with solely a void form with the same outcome.

[Ryan J Ollos]

To be sure, the page consists of:

{{{#!TracForm
}}}

and nothing else? Is the error message the same as in comment:description?

TracFormMacro has a few debug statements: tracformsplugin/trunk/tracforms/macros.py@16958:141-142,145-146,168,173#L136​ Could you see what is logged at debug level when loading the page with your empty WikiProcessor call?

[ntmlod]

Replying to Ryan J Ollos:

To be sure, the page consists of:

{{{#!TracForm
}}}

and nothing else? Is the error message the same as in comment:description?

Exactly, nothing in TracForm Processor and I get the same error malformed header from script 'trac.cgi': Bad header: (('wiki', u'...

TracFormMacro has a few debug statements: tracformsplugin/trunk/tracforms/macros.py@16958:141-142,145-146,168,173#L136​ Could you see what is logged at debug level when loading the page with your empty WikiProcessor call?

2017-11-06 23:39:37,874 Trac[formatter] DEBUG: Executing Wiki macro TracForm by provider <tracforms.macros.TracFormMacro object at 0x4c1c550>
2017-11-06 23:39:37,874 Trac[macros] DEBUG: TracForms state =
2017-11-06 23:39:37,875 Trac[macros] DEBUG: TRACFORM_PARSER_OUT:
2017-11-06 23:39:37,875 Trac[macros] DEBUG: TracForms parsing finished

[Ryan J Ollos]

In 16960:

TracForms 0.5dev: Remove debug print statement from r16386

Refs #13319.

[Ryan J Ollos]

Please test again after r16960.

[ntmlod]

Bravo ! It was a tricky one.

[Ryan J Ollos]

Well, I should be more careful with my commits and stop trying to do multiple things at once! Thanks for your effort to debug the issue.