Closed Bug 1043015 Opened 6 years ago Closed 6 years ago
running mochitest-remote without ssltunnel gives bizarre errors (structured logging regression, I think)
4.42 KB, text/plain; charset=UTF-8
1.33 KB, patch
|Details | Diff | Splinter Review|
I just tried to run mochitest-remote without copying in assltunne to work around bug 1002545, and post-structured-logging this gives some pretty bizarre errors: File "/home/dbaron/builds/B2G-master-emulator/objdir-gecko-debugopt/_tests/testing/mochitest/runtests.py", line 833, in start log.error("INFO | runtests.py | expected to find ssltunnel at %s", ssltunnel) TypeError: log() takes exactly 2 arguments (3 given) and later: File "/home/dbaron/builds/B2G-master-emulator/../ssd/mozilla-central/mozilla/testing/mozbase/mozlog/mozlog/structured/formatters/tbplformatter.py", line 66, in suite_end time = int((data["time"] - start_time) / 1000) TypeError: unsupported operand type(s) for -: 'int' and 'NoneType'
The first error appears to be a typo; s/, / % / should work. The second error is that we're getting a suite_end message before suite_start. The logger should error for that case and refuse to emit the end message.
Well, I'm pretty sure it used to work, because I remember getting a useful error message the last time I hit the problem (although it may well have had an extra %s in it). Perhaps log.error() used to accomodate multiple arguments and no longer does? Fixing the typo seems reasonable, though, but have you checked that there aren't other similar log.error() or other log.*() calls?
Well I guess what actually happened was that the switch away from stdlib logging broke this because it interprets extra arguments as format parameters, but mozlog[.structured] doesn't. I can't be sure that there aren't more examples in anywhere in mochitest (without putting in a "morning" amount of effort, rather than a "middle of the night" amount of effort), but I can't see any more in that file at least.
Indeed, switching from using the stdlib logging module to using StructuredLogger forces us to supply a single argument to logging functions (info, error, warning, etc.); I apparently forgot to refactor that one error message! I'll try to check I didn't forget any other logging calls and will submit a patch. (Not sure what we can do about the missing suite_start message though, does it only happen when running without ssltunnel?)
Assuming the missing suite_start is basically because we fail and then later emit a suite end message to signal we're done, I have a patch that will "fix" it by emitting an error rather than a suite_end message. I don't think mild cascading of errors is a problem, and certainly less of one than violating the protocol.
I went through the code and couldn't find another instance of this bug, so this patch just fixes the typo on the ssl tunnel error. For the missing test_end, the StructuredLogger patch will make errors easier to understand.
Attachment #8461205 - Flags: review?(james)
Assignee: nobody → ahmed.kachkach
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla34
You need to log in before you can comment on or make changes to this bug.