[lit] Remove ANSI control character from xunit output

[arichardson]

Summary

Failing test output sometimes contains control characters like \x1b (e.g.
if there was some -fcolor-diagnostics output) which are not allowed inside
XML files. This causes problems with CI systems: for example, the Jenkins
JUnit XML will throw an exception when ecountering those characters and
similar problems also occur with GitLab CI.

[arichardson]

fix tests

[yln]

Thanks for adding a test, we definitely want to keep it!

Implementation: do you think that this is the best approach to solving this issue? Have you considered other options?
Is this a new issue or was this caused by my "report generators" refactoring?

[yln]

llvm/utils/lit/lit/reports.py

128

I just spotted a bug in this existing code, decode() returns a new string. It should be:

output = output.decode('utf-8', 'ignore')

Can you check if this would resolve your issue?

[arichardson]

In D84233#2167650, @yln wrote:

Thanks for adding a test, we definitely want to keep it!

Implementation: do you think that this is the best approach to solving this issue? Have you considered other options?
Is this a new issue or was this caused by my "report generators" refactoring?

No this issue has been around for a while, I originally added a workaround to our fork in 2018 (https://github.com/CTSRD-CHERI/llvm-project/commit/3179f32c07f224c96d33f485747f508a34106c91).
I'm currently trying to reduce our diff to upstream and cleaning up local workarounds for upstreaming.

llvm/utils/lit/lit/reports.py

128

Good catch. But I don't believe this fixes the issue since those characters are valid utf-8 characters just not ones that the Jenkins JUnit XML parser accepts.

[arichardson]

Fix missing assignment

[yln]

@arichardson: can you double-check that this workaround is still needed?
Do we understand the semantics of CDATA blocks? I was under the impression we use it here to avoid problems like this.

Anyways, I am fine with this. Adding Joel as a second reviewer to get his feedback before accepting.

@jdenny:
Do you have opinions on this? Is llvm-lit responsible for this (or should the fix be in Jenkins/Jenkin's config)?
Any other reviewers we should include?

[arichardson]

In D84233#2170305, @yln wrote:

@arichardson: can you double-check that this workaround is still needed?
Do we understand the semantics of CDATA blocks? I was under the impression we use it here to avoid problems like this.

Anyways, I am fine with this. Adding Joel as a second reviewer to get his feedback before accepting.

I believe CDATA just avoids the need for escape XML special characters. However, characters 0-0x20 (with the exception of \t \r an \n are not valid anywhere in the document according to the XML spec (https://www.w3.org/TR/xml/#charsets):
Char ::= #x9 | #xA | #xD | [#x20-#xD7FF] | [#xE000-#xFFFD] | [#x10000-#x10FFFF] /* any Unicode character, excluding the surrogate blocks, FFFE, and FFFF. */

XML 1.1 seems to relax that an allow everything except NUL: https://www.w3.org/TR/xml11/#charsets

Maybe specifying version 1.1 for the XUnit output would make the Java parsers happy again, but escaping ANSI control characters might also be useful if you open the report XML file in a text editor.

[jdenny]

Thanks for working on this. I've been wanting to see this fixed too. I agree that lit is the culprit.

In D84233#2171536, @arichardson wrote:

Maybe specifying version 1.1 for the XUnit output would make the Java parsers happy again, but escaping ANSI control characters might also be useful if you open the report XML file in a text editor.

I'm not sure which fix is best:

• The current patch: If I understand correctly, the current patch's escaping for XML 1.0 is not reversible: the escape sequences are indistinguishable from any existing occurrences of the two-character sequence \x.
• Drop control characters instead: That would make the output more readable. It loses even more information, but that information's value is questionable.
• Use a reversible escape sequence: This doesn't seem worth it and might make simple output harder to read.
• XML 1.1: It looks like that would avoid the above issues (I think it's best to just drop nul bytes). Does anyone know how widely supported XML 1.1 is today? A quick google search turned up info from a decade ago saying it was not widely supported then.

If we cannot come to a conclusion soon, I think the current patch is an improvement, so we should commit it and then consider possible improvements.

llvm/utils/lit/lit/reports.py

72

Please add a comment here citing the relevant part of the XML 1.0 spec.

132

I had similar trouble with Gitlab CI around the end of last year. Maybe the main point this comment should make is that the XML is invalid without this escaping, and then the comment can mention CI failures as a practical consequence.

llvm/utils/lit/tests/shtest-format.py

35

Is this line intentional?

[arichardson]

• Improve comments
• Remove unnecessary line from test

[jdenny]

Other than the nit I just added about comment duplication, this LGTM. Thanks. However, let's a wait a couple of days in case anyone else has an opinion.

I still wonder whether it would be more helpful to drop control characters rather than irreversibly escape them. Dropping them makes the output more readable. Reversibly escaping them makes it possible to feed the text to a tool that can render the control codes. Irreversibly escaping them doesn't achieve either of those advantages, and I'm not sure if it serves a real use case. Any comments on this question?

llvm/utils/lit/lit/reports.py

138

You indeed did what I asked, but I didn't consider that we would end up with duplication of some comments at the caller and callee.

I think it would be better to consolidate these comments with the ones you just inserted into the escape_invalid_xml_chars definition, and place the consolidated version as header comments on escape_invalid_xml_chars and nowhere else.

[yln]

In D84233#2176397, @jdenny wrote

I still wonder whether it would be more helpful to drop control characters rather than irreversibly escape them. Dropping them makes the output more readable. Reversibly escaping them makes it possible to feed the text to a tool that can render the control codes. Irreversibly escaping them doesn't achieve either of those advantages, and I'm not sure if it serves a real use case. Any comments on this question?

I agree with Joel here and would like to see this done as part of this patch.

[yln]

llvm/utils/lit/lit/reports.py

76

Should this be a global to avoid building the dict on every call to this function?

[arichardson]

llvm/utils/lit/lit/reports.py

76

Yes, this could be called many times so that definitely makes sense.

Will update the patch tomorrow.

[arichardson]

• Remove instead of escaping. This avoids a py2 -> py3 difference
• fix comments

[arichardson]

fix python2 issue

[arichardson]

remove debug code

[yln]

LGTM with two small nits. Thanks!

llvm/utils/lit/lit/reports.py

71

This is now an _invalid_xml_chars_dict

83

Why reassign s? Just return.

[arichardson]

llvm/utils/lit/lit/reports.py

83

Leftover from when I had debug statements there. Will remove before committing.

[arichardson]

fix variable name and remove temporary

llvm/utils/lit/lit/reports.py

def write_results(self, tests, elapsed):
 
             tests_data.append(test_data)
 
         with open(self.output_file, 'w') as file:
             json.dump(data, file, indent=2, sort_keys=True)
             file.write('\n')
 
 
+def escape_control_chars(s):
+    escape_dict = {chr(c): '\\x' + hex(c)[2:] for c in range(32) if chr(c) not in ('\t', '\n', '\r')}
+    try:
+        s = s.translate(str.maketrans(escape_dict))
+    except AttributeError:
+        # python 2.7 string.translate() does not support multi-character
+        # replacing, so fall back to multiple str.replace() calls.
+        for k, v in escape_dict.items():
+            s = s.replace(k, v)
+    return s
+
+
 class XunitReport(object):
     def __init__(self, output_file):
         self.output_file = output_file
         self.skipped_codes = {lit.Test.EXCLUDED,
                               lit.Test.SKIPPED, lit.Test.UNSUPPORTED}
 
     def write_results(self, tests, elapsed):
         tests.sort(key=by_suite_and_test_path)
         tests_by_suite = itertools.groupby(tests, lambda t: t.suite)
def _write_test(self, file, test, suite_name):
             class_name=quo(class_name), name=quo(name), time=time))
 
         if test.isFailure():
             file.write('>\n  <failure><![CDATA[')
             # In the unlikely case that the output contains the CDATA
             # terminator we wrap it by creating a new CDATA block.
             output = test.result.output.replace(']]>', ']]]]><![CDATA[>')
             if isinstance(output, bytes):
                 output.decode("utf-8", 'ignore')
+
+            # The Jenkins JUnit XML parser throws an exception if the output
+            # contains control characters like \x1b (e.g. if there is some
+            # -fcolor-diagnostics output).
+            output = escape_control_chars(output)
             file.write(output)
             file.write(']]></failure>\n</testcase>\n')
         elif test.result.code in self.skipped_codes:
             reason = self._get_skip_reason(test)
             # file.write(f'>\n  <skipped message={quo(reason)}/>\n</testcase>\n')
             file.write('>\n  <skipped message={reason}/>\n</testcase>\n'.format(
                 reason=quo(reason)))
         else:
             file.write('/>\n')
 
     def _get_skip_reason(self, test):
         code = test.result.code
         if code == lit.Test.EXCLUDED:

llvm/utils/lit/tests/Inputs/shtest-format/external_shell/fail_with_control_chars.txt

+# Run a command that fails and prints control characters on stdout.
+# This tests checks that the xunit output correctly escapes them in the XML.
+#
+# RUN: %{python} %S/write-control-chars.py
+

llvm/utils/lit/tests/Inputs/shtest-format/external_shell/write-control-chars.py

+#!/usr/bin/env python
+
+from __future__ import print_function
+import sys
+
+print("a line with \x1b[2;30;41mcontrol characters\x1b[0m.", flush=True)
+sys.exit(1)

llvm/utils/lit/tests/shtest-format.py

 
 # CHECK: FAIL: shtest-format :: external_shell/fail_with_bad_encoding.txt
 # CHECK-NEXT: *** TEST 'shtest-format :: external_shell/fail_with_bad_encoding.txt' FAILED ***
 # CHECK: Command Output (stdout):
 # CHECK-NEXT: --
 # CHECK-NEXT: a line with bad encoding:
 # CHECK: --
 
+# CHECK: FAIL: shtest-format :: external_shell/fail_with_control_chars.txt
+# CHECK-NEXT: *** TEST 'shtest-format :: external_shell/fail_with_control_chars.txt' FAILED ***
+# CHECK: Command Output (stdout):
+# CHECK-NEXT: --
+# CHECK-NEXT: a line with {{.*}}control characters{{.*}}.
+# characters{{[:cntrl:].+}}.
+# CHECK: --
+
 # CHECK: PASS: shtest-format :: external_shell/pass.txt
 
 # CHECK: FAIL: shtest-format :: fail.txt
 # CHECK-NEXT: *** TEST 'shtest-format :: fail.txt' FAILED ***
 # CHECK-NEXT: Script:
 # CHECK-NEXT: --
 # CHECK-NEXT: printf "line 1
 # CHECK-NEXT: false

 # CHECK: XFAIL: shtest-format :: xfail.txt
 # CHECK: XPASS: shtest-format :: xpass.txt
 # CHECK-NEXT: *** TEST 'shtest-format :: xpass.txt' FAILED ***
 # CHECK-NEXT: Script
 # CHECK-NEXT: --
 # CHECK-NEXT: true
 # CHECK-NEXT: --
 
-# CHECK: Failed Tests (3)
+# CHECK: Failed Tests (4)
 # CHECK: shtest-format :: external_shell/fail.txt
 # CHECK: shtest-format :: external_shell/fail_with_bad_encoding.txt
+# CHECK: shtest-format :: external_shell/fail_with_control_chars.txt
 # CHECK: shtest-format :: fail.txt
 
 # CHECK: Unexpectedly Passed Tests (1)
 # CHECK: shtest-format :: xpass.txt
 
 # CHECK: Testing Time:
 # CHECK: Unsupported        : 4
 # CHECK: Passed             : 6
 # CHECK: Expectedly Failed  : 4
 # CHECK: Unresolved         : 3
-# CHECK: Failed             : 3
+# CHECK: Failed             : 4
 # CHECK: Unexpectedly Passed: 1
 
 
 # XUNIT: <?xml version="1.0" encoding="UTF-8"?>
 # XUNIT-NEXT: <testsuites time="{{[0-9.]+}}">
-# XUNIT-NEXT: <testsuite name="shtest-format" tests="21" failures="7" skipped="4">
+# XUNIT-NEXT: <testsuite name="shtest-format" tests="22" failures="8" skipped="4">
 
 # XUNIT: <testcase classname="shtest-format.external_shell" name="fail.txt" time="{{[0-9]+\.[0-9]+}}">
 # XUNIT-NEXT: <failure{{[ ]*}}>
 # XUNIT: </failure>
 # XUNIT-NEXT: </testcase>
 
 
 # XUNIT: <testcase classname="shtest-format.external_shell" name="fail_with_bad_encoding.txt" time="{{[0-9]+\.[0-9]+}}">
 # XUNIT-NEXT: <failure{{[ ]*}}>
 # XUNIT: </failure>
 # XUNIT-NEXT: </testcase>
 
+# XUNIT: <testcase classname="shtest-format.external_shell" name="fail_with_control_chars.txt" time="{{[0-9]+\.[0-9]+}}">
+# XUNIT-NEXT: <failure><![CDATA[Script:
+# XUNIT: Command Output (stdout):
+# XUNIT-NEXT: --
+# XUNIT-NEXT: a line with \x1b[2;30;41mcontrol characters\x1b[0m.
+# XUNIT: </failure>
+# XUNIT-NEXT: </testcase>
+
 # XUNIT: <testcase classname="shtest-format.external_shell" name="pass.txt" time="{{[0-9]+\.[0-9]+}}"/>
 
 # XUNIT: <testcase classname="shtest-format.shtest-format" name="fail.txt" time="{{[0-9]+\.[0-9]+}}">
 # XUNIT-NEXT: <failure{{[ ]*}}>
 # XUNIT: </failure>
 # XUNIT-NEXT: </testcase>
 
 # XUNIT: <testcase classname="shtest-format.shtest-format" name="no-test-line.txt" time="{{[0-9]+\.[0-9]+}}">