749104 - Ensure Mozmill logging messages are being properly bucketized

Status: RESOLVED FIXED

(Testing Graveyard :: Mozmill, defect)

Description

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Right now --console-level=INFO is set as default. But it prints everything. That makes it kinda hard to spot problems and works differently as other applications. Normally there is by default lesser output and you can request more information by specifying --v or similar options.

The same should be done in mozmill. Why not make ERROR the default level?

Comment 1

[Jeff Hammel]

I feel like I've said this on another bug but personally I'd rather have more information than less by default.  If consensus is the other way, I'm fine with that, but it will lead to the situation where I will run once without specifying the console level and, when I get problems, running again with --console-level=INFO.

If there is particular INFO level information that is not helpful I am open moving that to DEBUG

Comment 3

[cmtalbert]

Re-tooling the bug thusly:
INFO is a good default to have. But it sounds like we have too much stuff going into the INFO bucket. So, let's review what buckets we're putting our log messages into and ensure they are all going to the right places.

That's ^ how we'll resolve this bug.

Comment 4

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Easy fix. Patch coming up in a bit.

Comment 5

[Henrik Skupin [:whimboo][⌚️UTC+2]]

With my patch we will get the following in the default INFO level:

TEST-UNEXPECTED-FAIL | radio_buttons.js | test
TEST-PASS | selector.js | test
TEST-SKIPPED | utf-8.js | Bug 761603 - UTF-8 handling is broken in Mozmill 2.0
TEST-SKIPPED | stale_element.js | Bug 761600 - Stale elements do not work since GPC has been landed
TEST-PASS | test1.js | testOne
TEST-PASS | test1.js | testTwo
TEST-PASS | test1.js | testThree
TEST-PASS | test1.js | testFour
TEST-PASS | test2.js | testOne
TEST-EXPECTED-FAIL | test3.js | testNoExpectedRestartByTimeout

Which looks pretty amazing with pprint-color!!

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: Patch

Pointer to Github pull-request

Comment 7

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 635696 [details]
Patch

This patch does the following:

* Updates the entries of available logger levels corresponding to Mochitest

* Updates the parser option declarations

* Moves all the test related events like pass, fail, and skip into the debug bucket for now. Reason is that we clutter the console way to much and it is risky that we can overlook an entry. I would propose that I file another bug which can safely extract the message from the error and shows that in the INFO level. Only in debug mode we should print the whole exception and stack. Jeff?

* Updated Mutt so we run tests in the INFO level but colored pprint output. That way we can ensure to not overlook failures. In the future we could add a --debug option to its command line. For now you can simply use mozmill itself with console level debug to investigate this problem.

Comment 8

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Here a copy of the latest output with the attached patch:

TEST-START | mozelement.js | setupModule
TEST-START | mozelement.js | test
TEST-PASS | mozelement.js | test
TEST-START | mozelement_window.js | setupModule
TEST-START | mozelement_window.js | testContent
TEST-PASS | mozelement_window.js | testContent
TEST-START | mozelement_window.js | testChrome
TEST-PASS | mozelement_window.js | testChrome
TEST-START | radio_buttons.js | setupModule
TEST-START | radio_buttons.js | test
TEST-UNEXPECTED-FAIL | radio_buttons.js | test
TEST-START | selector.js | setupModule
TEST-START | selector.js | test
TEST-PASS | selector.js | test
TEST-SKIPPED | utf-8.js | Bug 761603 - UTF-8 handling is broken in Mozmill 2.0
TEST-SKIPPED | stale_element.js | Bug 761600 - Stale elements do not work since GPC has been landed
RESULTS | Passed: 4
RESULTS | Failed: 1
RESULTS | Skipped: 2

Comment 9

[Henrik Skupin [:whimboo][⌚️UTC+2]]

(In reply to Henrik Skupin (:whimboo) from comment #7)
> * Updated Mutt so we run tests in the INFO level but colored pprint output.
> That way we can ensure to not overlook failures. In the future we could add
> a --debug option to its command line. For now you can simply use mozmill
> itself with console level debug to investigate this problem.

Keep in mind that with my patch on bug 762208 the DEBUG level will go away temporarily because we are making use of Mozmill directly.

Comment 10

[Jeff Hammel]

Comment on attachment 635696 [details]
Patch

Nit about spacing for function arguments which I'd like to see fixed.  Other than that, looks good

Comment 11

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Fixed nits and pushed to master:
https://github.com/mozautomation/mozmill/commit/ca87596f8b0063b43e5c1b5b3fb460d825fbfdf9