Use StructuredLog.jsm for mochitest's structured logging

RESOLVED FIXED in Firefox 44

Status

RESOLVED FIXED
4 years ago
3 years ago

People

(Reporter: akachkach, Assigned: ahal)

Tracking

unspecified
mozilla44
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox44 fixed)

Details

Attachments

(3 attachments, 1 obsolete attachment)

(Reporter)

Description

4 years ago
We should use the StructuredLog class implemented in bug 916265 in all JS-side structured logging (instead of using a class specific for mochitest), and also move the formatter implemented in bug 1041706 to that jsm or a separate one.
We'll either have to use SpecialPowers to access it or put the file in http://mxr.mozilla.org/mozilla-central/source/testing/mochitest/tests/SimpleTest/Makefile.in and make sure we don't become dependent on other modules.
Created attachment 8480159 [details] [diff] [review]
Use StructuredLog.jsm for mochitest logging.

This is pretty much works, but including a jsm like this is weird.
Assignee: nobody → cmanchester
Status: NEW → ASSIGNED
(Assignee)

Updated

3 years ago
Duplicate of this bug: 1201616
(Assignee)

Comment 4

3 years ago
Created attachment 8657115 [details]
MozReview Request: Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester

Bug 1042998 - Use StructuredLog.jsm for mochitest logging
(Assignee)

Updated

3 years ago
Attachment #8480159 - Attachment is obsolete: true
(Assignee)

Comment 5

3 years ago
Stealing this bug.
Assignee: cmanchester → ahalberstadt
(Assignee)

Comment 6

3 years ago
Try run: not stellar. I'm pretty lost as to why xpcshell selftests are breaking.. haven't looked into mochitest problems yet.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=33351482f3a7
(Assignee)

Comment 7

3 years ago
New try run:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=ba4fc7f838da

Fixed the xpcshell selftests issue. Opt builds look good, it's debug that have the various failures. Likely there are more types of data going through the StructuredLog.jsm. Should hopefully just be a matter of figuring out the difference between the old mochitest version and the new .jsm one.
(Assignee)

Comment 8

3 years ago
Still chipping away at this:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=1e47fe40e7d3

I think the Linux debug bc failures are known bustage, at least they fail on other people's try pushes too. I'm on the hook for the android and b2g mochitest-chrome bustage though.
(Assignee)

Comment 9

3 years ago
Finally figured it out:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=2b07c2c387bb

I'll do another full try run just in case while waiting for review.
(Assignee)

Comment 10

3 years ago
Comment on attachment 8657115 [details]
MozReview Request: Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester

Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester
Attachment #8657115 - Attachment description: MozReview Request: Bug 1042998 - Use StructuredLog.jsm for mochitest logging → MozReview Request: Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester
Attachment #8657115 - Flags: review?(cmanchester)
Comment on attachment 8657115 [details]
MozReview Request: Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester

https://reviewboard.mozilla.org/r/18321/#review17331

::: testing/mochitest/browser-harness.xul:87
(Diff revision 2)
> -      structuredLogger: new StructuredLogger(),
> +      structuredLogger: TestRunner.structuredLogger,

If there's a structured logger available from the TestRunner global, do we need to include StructuredLog.jsm in the script tag above?

::: testing/mochitest/runtests.py:152
(Diff revision 2)
> +            #print('%s: %s' % (type(message['message']), message['message']))

Leftover debug print.

::: testing/mochitest/runtests.py:153
(Diff revision 2)
> +            if isinstance(message['message'], bytes):
> +                message['message'] = message['message'].encode('utf-8', 'replace')

I think this may have been wrong before... isn't "encode" used to go from unicode to bytes?

::: testing/mochitest/runtests.py:156
(Diff revision 2)
> +            if not isinstance(message['message'], unicode):
> +                message['message'] = unicode(message['message'])
> +

I think mozlog does this coercion for us.

::: testing/mochitest/tests/index.html:4
(Diff revision 2)
> +    <script type="application/javascript" src="SimpleTest/StructuredLog.jsm"></script>

I think I mentioned this somewhere, but I don't think this is a great way to go about this, because it means we'll break mochitests if this jsm ever starts using the Components object. It doesn't, and I don't think it's going to need to any time soon, but I think using specialpowers to access the jsm through resource://testing-common

::: testing/modules/StructuredLog.jsm:38
(Diff revision 2)
> -StructuredLogger.prototype.testStart = function (test) {
> -  this._runningTests.add(test);
> +StructuredLogger.prototype = {
> +  testStart: function (test) {

I actually prefer the Foo.prototype.bar = function () { ... syntax. I think there's a lot of both in the code base, but is there a particular reason to change it here?

::: testing/modules/StructuredLog.jsm:94
(Diff revision 2)
> +    var data = {tests: tests};

Right... using this in content means s/let/var/, yuck.

::: testing/modules/StructuredLog.jsm:148
(Diff revision 2)
> +  isValid: function(message) {
> +    return message.action !== undefined && VALID_ACTIONS.indexOf(message.action) >= 0;
> +  },

Where is this called?
Attachment #8657115 - Flags: review?(cmanchester)
(Assignee)

Comment 12

3 years ago
https://reviewboard.mozilla.org/r/18321/#review17331

> If there's a structured logger available from the TestRunner global, do we need to include StructuredLog.jsm in the script tag above?

I think I tried importing it globally in TestRunner.js but couldn't get it to work across all platform and flavour combinations. See comment below as well.

> I think this may have been wrong before... isn't "encode" used to go from unicode to bytes?

Good catch. It worked in my try run because of the unicode coercion right after, but that may have failed on certain systems.

> I think mozlog does this coercion for us.

True, but all of the mochitest outputHandlers get called before the message ever reaches mozlog, so we need to do it a little earlier on.

> I think I mentioned this somewhere, but I don't think this is a great way to go about this, because it means we'll break mochitests if this jsm ever starts using the Components object. It doesn't, and I don't think it's going to need to any time soon, but I think using specialpowers to access the jsm through resource://testing-common

Ok, I'll take another look. But I've spent the better part of a week trying to get this imported across android/b2g/desktop on all flavours.. my frustration level at this problem is currently very high :p. So if I can't get it working right away, mind if I land as is and file a follow-up?

> I actually prefer the Foo.prototype.bar = function () { ... syntax. I think there's a lot of both in the code base, but is there a particular reason to change it here?

Not particularly.. I guess it's a matter of taste. I got used to it this way when working with the gaia automation, so figured might as well copy them. Now I find the Foo.prototype.bar method somewhat wordy and ugly looking.

> Where is this called?

It's not, but it used to exist in the mochitest version.. figured it could potentially be useful to a consumer, but I can remove it if you prefer.
(Assignee)

Comment 13

3 years ago
So when I import StructuredLog.jsm via SpecialPowers.Cu.import, I get errors like:
TEST-UNEXPECTED-FAIL: setup.js | error parsing http://mochi.test:8888/tests.json (TypeError: TestRunner.structuredLogger.info is not a function)
JavaScript error: http://mochi.test:8888/tests/SimpleTest/TestRunner.js, line 348: TypeError: TestRunner.structuredLogger.info is not a function

I'm not entirely sure why.. Also when importing via specialpowers you can't modify the structuredLogger object, i.e we can't add the 'disableBuffering' and 'enableBuffering' functions (though this is easily worked around).

Chris any ideas? Or is it ok if I land the patch with the server.js hack, and file a follow-up bug to fix it properly later? I really don't want to waste much more time on this.
Flags: needinfo?(cmanchester)
I can probably find time to figure out the problem with specialpowers, but maybe not in the next week or two.

What is this blocking? As far as I can tell this bug is mostly about cleaning things up by de-duplicating code, so I don't think landing temporary hacks really makes sense, but I don't think I'm up to speed on the overall plan here.
Flags: needinfo?(cmanchester)
(Assignee)

Comment 15

3 years ago
It technically isn't blocking anything, but I want to use StructuredLog.jsm for reftest. If we don't land this now, we'll have to deal with all of xpcshell, mochitest and reftest at the same time when we land it in the future. Plus if we don't land this now, there's a high probability that we'll forget about it again like last time.

I also don't really think serving it to content is that big of a hack. It's fine if you disagree, but as long as you agree this is an incremental improvement over the status quo.. then we might as well land it while the try run is still green.

Here is said try run btw:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=6c33a90b793b
I'd really rather figure out the specialpowers thing. I'm blocked on other stuff right now, I'll give it a go this week.
Flags: needinfo?(cmanchester)
(Assignee)

Comment 17

3 years ago
Comment on attachment 8657115 [details]
MozReview Request: Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester

Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester
Created attachment 8662521 [details] [diff] [review]
Patch to access StructuredLog.jsm from SpecialPowers

This approach works well locally. We can get jmaher to sign off on it as well, there might be a simpler approach. If this causes problems on android/b2g for some reason we can just drop it.
Flags: needinfo?(cmanchester)
(Assignee)

Comment 19

3 years ago
Didn't work quite as well on try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=a7f6a570b626

Let me know how you want to proceed.
Flags: needinfo?(cmanchester)
The b-c issue looks trivial, but it looks like the testing modules dir isn't even set on b2g/Android, so that could be a huge hassle to deal with.

I still have reservations, but we can take some form of the original patch.
Flags: needinfo?(cmanchester)
(Assignee)

Updated

3 years ago
Attachment #8657115 - Flags: review?(cmanchester)
(Assignee)

Comment 21

3 years ago
Comment on attachment 8657115 [details]
MozReview Request: Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester

Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester
(Assignee)

Comment 22

3 years ago
Apparently Chris got the specialpowers method working, but it slowed everything down, and even caused some b2g emulator mochitests to reach the per test timeout. Per discussion, re-requesting review.
Created attachment 8666854 [details] [diff] [review]
Access StructuredLog.jsm through specialpowers rather than serving it as a content script

The aformentioned patch in case we need to come back to this.
https://reviewboard.mozilla.org/r/18321/#review17331

> It's not, but it used to exist in the mochitest version.. figured it could potentially be useful to a consumer, but I can remove it if you prefer.

Let's remove it. Dead code makes code hard to understand.
Comment on attachment 8657115 [details]
MozReview Request: Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester

https://reviewboard.mozilla.org/r/18321/#review18455

::: testing/mochitest/runtests.py:155
(Diff revision 4)
> +            if not isinstance(message['message'], unicode):

Can this be `elif` ?
Attachment #8657115 - Flags: review?(cmanchester) → review+
(Assignee)

Comment 26

3 years ago
Comment on attachment 8657115 [details]
MozReview Request: Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester

Bug 1042998 - Use StructuredLog.jsm for mochitest logging, r=chmanchester
(Assignee)

Comment 27

3 years ago
Here's an updated try run:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=895a627d439d

Pretty sure the intermittents are unrelated. All those emulator debug xpcshell failures also show up on previous pushes.
(Assignee)

Comment 29

3 years ago
Oh, the other thing I just remembered w.r.t to SpecialPowers... there was talk of trying to kill it due to security concerns with the new addon signing requirements. I imagine this might never happen, and if it does, would be a long way away. But it still might be a good idea to avoid it whenever possible.
https://hg.mozilla.org/mozilla-central/rev/7a6ec65f10fd
Status: ASSIGNED → RESOLVED
Last Resolved: 3 years ago
status-firefox44: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla44
Depends on: 1216254
You need to log in before you can comment on or make changes to this bug.