1278496 - mozunit.py printFail masks errors

Status: RESOLVED DUPLICATE of bug 1278466

(Release Engineering :: General, defect)

Description

[Rob Thijssen [:grenade (EET/UTC+0300)]]

Attachment: null check

in mozunit printFail (https://hg.mozilla.org/mozilla-central/file/1828937da9493b2cd54862b9c520b2ba5c7db92b/config/mozunit.py#l76), there is a line which parses failure messages for their 1st line.
If the message property of the value object is empty, the logger itself throws an error which causes subsequent tests to be skipped and gives less than the most useful log output and the failing test is not identified in the log.

Output without patching printFail (https://public-artifacts.taskcluster.net/Buk9P8ENQHeGeZl9cqBO5w/0/public/logs/all_commands.log):

17:23:24     INFO - Traceback (most recent call last):
17:23:24     INFO -   File "x:/Task_1465228837/build/src/python/mozbuild/mozbuild/test/test_base.py", line 398, in <module>
17:23:24     INFO -     main()
17:23:24     INFO -   File "x:\Task_1465228837\build\src\config\mozunit.py", line 171, in main
17:23:24     INFO -     unittest.main(testRunner=MozTestRunner(), *args, **kwargs)
17:23:24     INFO -   File "c:\mozilla-build\python\Lib\unittest\main.py", line 95, in __init__
17:23:24     INFO -     self.runTests()
17:23:24     INFO -   File "c:\mozilla-build\python\Lib\unittest\main.py", line 232, in runTests
17:23:24     INFO -     self.result = testRunner.run(self.test)
17:23:24     INFO -   File "x:\Task_1465228837\build\src\config\mozunit.py", line 91, in run
17:23:24     INFO -     test(result)
17:23:24     INFO -   File "c:\mozilla-build\python\Lib\unittest\suite.py", line 70, in __call__
17:23:24     INFO -     return self.run(*args, **kwds)
17:23:24     INFO -   File "c:\mozilla-build\python\Lib\unittest\suite.py", line 108, in run
17:23:24     INFO -     test(result)
17:23:24     INFO -   File "c:\mozilla-build\python\Lib\unittest\suite.py", line 70, in __call__
17:23:24     INFO -     return self.run(*args, **kwds)
17:23:24     INFO -   File "c:\mozilla-build\python\Lib\unittest\suite.py", line 108, in run
17:23:24     INFO -     test(result)
17:23:24     INFO -   File "c:\mozilla-build\python\Lib\unittest\case.py", line 393, in __call__
17:23:24     INFO -     return self.run(*args, **kwds)
17:23:24     INFO -   File "c:\mozilla-build\python\Lib\unittest\case.py", line 353, in run
17:23:24     INFO -     result.addError(self, sys.exc_info())
17:23:24     INFO -   File "x:\Task_1465228837\build\src\config\mozunit.py", line 64, in addError
17:23:24     INFO -     self.printFail(test, err)
17:23:24     INFO -   File "x:\Task_1465228837\build\src\config\mozunit.py", line 76, in printFail
17:23:24     INFO -     message = value.message.splitlines()[0]
17:23:24     INFO - IndexError: list index out of range
17:23:24     INFO - x:/Task_1465228837/build/src/config/rules.mk:110: recipe for target 'mozbuild/mozbuild/test/test_base.py-run' failed
17:23:24     INFO - mozmake[1]: *** [mozbuild/mozbuild/test/test_base.py-run] Error 1


Output with printFail patched (https://public-artifacts.taskcluster.net/BRBNorjTRZuC6Fl1wxhr6Q/0/public/logs/command_000001.log):

09:26:49  WARNING - TEST-UNEXPECTED-FAIL | x:/Task_1465288437/build/src/python/mozbuild/mozbuild/test/test_base.py | TestMozbuildObject.test_config_guess, line 285: [Error 193] %1 is not a valid Win32 application
09:26:49     INFO - ERROR: test_config_guess (__main__.TestMozbuildObject)
09:26:49     INFO - Traceback (most recent call last):
09:26:49     INFO -   File "x:/Task_1465288437/build/src/python/mozbuild/mozbuild/test/test_base.py", line 285, in test_config_guess
09:26:49     INFO -     result = base._config_guess
09:26:49     INFO -   File "x:\Task_1465288437\build\src\python\mozbuild\mozbuild\base.py", line 471, in _config_guess
09:26:49     INFO -     self.mozconfig, self.topsrcdir)
09:26:49     INFO -   File "x:\Task_1465288437\build\src\python\mozbuild\mozbuild\base.py", line 403, in resolve_config_guess
09:26:49     INFO -     subprocess.check_output(args, cwd=topsrcdir).strip())
09:26:49     INFO -   File "c:\mozilla-build\python\Lib\subprocess.py", line 566, in check_output
09:26:49     INFO -     process = Popen(stdout=PIPE, *popenargs, **kwargs)
09:26:49     INFO -   File "c:\mozilla-build\python\Lib\subprocess.py", line 710, in __init__
09:26:49     INFO -     errread, errwrite)
09:26:49     INFO -   File "c:\mozilla-build\python\Lib\subprocess.py", line 958, in _execute_child
09:26:49     INFO -     startupinfo)
09:26:49     INFO - WindowsError: [Error 193] %1 is not a valid Win32 application