1569235 - Using ok(true, -1, "some message") in a test fails with cryptic message

Status: RESOLVED FIXED

(Developer Infrastructure :: Lint and Formatting, task, P3)

Description

[Julian Descottes [:jdescottes]]

We no longer support the passing 3 or more arguments to ok() since Bug 1467712.

However passing an int as second argument for ok() will fail but create a weird error message:

 0:03.99 TEST_START: devtools/client/webconsole/test/mochitest/browser_console_clear_method.js
 0:04.14 INFO Entering test bound 
Exception in thread ProcessReader:
Traceback (most recent call last):
  File "/usr/local/Cellar/python@2/2.7.15_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 801, in __bootstrap_inner
    self.run()
  File "/usr/local/Cellar/python@2/2.7.15_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 754, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/Users/jdescottes/Development/hg/fx-team-artifact/testing/mozbase/mozprocess/mozprocess/processhandler.py", line 1085, in _read
    callback(line.rstrip())
  File "/Users/jdescottes/Development/hg/fx-team-artifact/testing/mozbase/mozprocess/mozprocess/processhandler.py", line 995, in __call__
    e(*args, **kwargs)
  File "/Users/jdescottes/Development/hg/fx-team-artifact/objdir.noindex/_tests/testing/mochitest/runtests.py", line 2995, in processOutputLine
    message = handler(message)
  File "/Users/jdescottes/Development/hg/fx-team-artifact/objdir.noindex/_tests/testing/mochitest/runtests.py", line 3100, in dumpScreenOnTimeout
    and "Test timed out" in message['subtest']):
TypeError: argument of type 'int' is not iterable

Here we crash on "Test timed out" in message['subtest'] because message['subtest'] is an int.

I don't know if we should do some typecasting in runtests.py, but we can make sure we pass a string argument in the ok() checker:
https://searchfox.org/mozilla-central/rev/0bcdfa99339c0512e3730903835fb6f8ed45e3c4/testing/mochitest/browser-test.js#1573-1574

Comment 1

[Julian Descottes [:jdescottes]]

Attachment: Bug 1569235 - Ensure subtest name is a string when parsing test lines

Comment 2

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/54629c24e7c3
Ensure subtest name is a string when parsing test lines r=ahal

Comment 3

[Pulsebot]

Backout by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/dccb1e54f481
Backed out changeset 54629c24e7c3 for UnicodeEncodeError on a CLOSED TREE.

Comment 4

[Raul Gurzau (:RaulG)]

Backed out changeset 54629c24e7c3 (bug 1569235) for UnicodeEncodeError on a CLOSED TREE.

Backout link: https://hg.mozilla.org/integration/autoland/rev/dccb1e54f4814561d9e21944b3b2ead880aad7bc

**Push with failures:**https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=testfailed%2Cbusted%2Cexception&revision=54629c24e7c354bd8ea29477074e3dd93b4b093f&selectedJob=258541729

Log link: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=258541729&repo=autoland&lineNumber=18292

Log snippet:

[task 2019-07-26T19:16:09.797Z] 19:16:09 INFO - TEST-START | browser/components/syncedtabs/test/browser/browser_sidebar_syncedtabslist.js
[task 2019-07-26T19:16:09.858Z] 19:16:09 INFO - GECKO(2929) | ++DOMWINDOW == 2 (0x7f5a7a2b8c00) [pid = 3057] [serial = 2] [outer = 0x7f5a7983bd40]
[task 2019-07-26T19:16:10.488Z] 19:16:10 INFO - GECKO(2929) | [Child 3080, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 664
[task 2019-07-26T19:16:10.551Z] 19:16:10 INFO - GECKO(2929) | ++DOMWINDOW == 15 (0x7f35b8a95c00) [pid = 2929] [serial = 15] [outer = 0x7f35be671020]
[task 2019-07-26T19:16:10.995Z] 19:16:10 INFO - GECKO(2929) | --DOCSHELL 0x7fe7ba3cb000 == 0 [pid = 3001] [id = {ca864da5-9c93-4bcd-8776-f2c43f02de54}] [url = about:blank]
[task 2019-07-26T19:16:11.100Z] 19:16:11 INFO - Exception in thread ProcessReader:
[task 2019-07-26T19:16:11.100Z] 19:16:11 INFO - Traceback (most recent call last):
[task 2019-07-26T19:16:11.100Z] 19:16:11 INFO - File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
[task 2019-07-26T19:16:11.101Z] 19:16:11 INFO - self.run()
[task 2019-07-26T19:16:11.101Z] 19:16:11 INFO - File "/usr/lib/python2.7/threading.py", line 754, in run
[task 2019-07-26T19:16:11.102Z] 19:16:11 INFO - self.__target(*self.__args, **self.__kwargs)
[task 2019-07-26T19:16:11.103Z] 19:16:11 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 1085, in _read
[task 2019-07-26T19:16:11.104Z] 19:16:11 INFO - callback(line.rstrip())
[task 2019-07-26T19:16:11.107Z] 19:16:11 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozprocess/processhandler.py", line 995, in call
[task 2019-07-26T19:16:11.108Z] 19:16:11 INFO - e(*args, **kwargs)
[task 2019-07-26T19:16:11.110Z] 19:16:11 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 2996, in processOutputLine
[task 2019-07-26T19:16:11.111Z] 19:16:11 INFO - messages = self.harness.message_logger.parse_line(line)
[task 2019-07-26T19:16:11.112Z] 19:16:11 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 240, in parse_line
[task 2019-07-26T19:16:11.114Z] 19:16:11 INFO - self._fix_subtest_name(message)
[task 2019-07-26T19:16:11.115Z] 19:16:11 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 190, in _fix_subtest_name
[task 2019-07-26T19:16:11.116Z] 19:16:11 INFO - message['subtest'] = str(message['subtest'])
[task 2019-07-26T19:16:11.118Z] 19:16:11 INFO - UnicodeEncodeError: 'ascii' codec can't encode character u'\u2014' in position 75: ordinal not in range(128)
[task 2019-07-26T19:16:25.954Z] 19:16:25 INFO - TEST-INFO | Main app process: exit 0
[task 2019-07-26T19:16:25.954Z] 19:16:25 ERROR - TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite
[task 2019-07-26T19:16:25.956Z] 19:16:25 INFO - runtests.py | Application ran for: 0:00:30.124659
[task 2019-07-26T19:16:25.958Z] 19:16:25 INFO - zombiecheck | Reading PID log: /tmp/tmpXIMCe7pidlog
[task 2019-07-26T19:16:25.960Z] 19:16:25 INFO - ==> process 2929 launched child process 2947
[task 2019-07-26T19:16:25.961Z] 19:16:25 INFO - ==> process 2929 launched child process 2979

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/8ffcf324c349
Ensure subtest name is a string when parsing test lines r=ahal

Comment 6

[Cristina Coroiu [:ccoroiu]]

https://hg.mozilla.org/mozilla-central/rev/8ffcf324c349