Output message + stack information in mach formatter for unexpected [sub]test results

RESOLVED FIXED in mozilla34

Status

Testing
Mozbase
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: jgraham, Assigned: Arnav Sharma, Mentored)

Tracking

({regression})

unspecified
mozilla34
x86_64
Linux
regression
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment, 5 obsolete attachments)

(Reporter)

Description

3 years ago
The mach formatter is currently a little too quiet; it would be useful if it gave error information when tests fail. This change needs to be made in machformatter.py [1] in both test_status and test_end. In test_status you will need to store the message data for anything with an "expected" field. In test_end you will need to output the stored test name and message for any subtests, and do something similar for the test itself.

[1] http://dxr.mozilla.org/mozilla-central/source/testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
(Assignee)

Comment 1

3 years ago
Created attachment 8454815 [details] [diff] [review]
Proposed patch to output details about unexpected results.

This is my first patch to anything on Mozilla, so I'm aware that I could have made some terrible mistakes. Please let me know about anything pertinent!
Attachment #8454815 - Flags: review?(james)
(Reporter)

Comment 2

3 years ago
Comment on attachment 8454815 [details] [diff] [review]
Proposed patch to output details about unexpected results.

Review of attachment 8454815 [details] [diff] [review]:
-----------------------------------------------------------------

Looks like a great start; thanks for taking the time to do this. There are just a couple of issues to address.

::: testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
@@ +54,5 @@
>          else:
>              expected_str = ""
>  
>          subtests = self._get_subtest_data(data)
> +        if subtests["count"] != 0:

Should be

if "expected" in data

I think. Could also add a flag like parent_unexpected to use below.

@@ +69,2 @@
>              data["status"], expected_str, subtests["pass"],
> +            subtests["count"], str(unexpected))

I think we need some more fancy formatting for unexpected than just str(unexpected). Something like:

rv = "Harness status %s%s. Subtests passed %i/%i. Unexpected [%s]" % (
    data["status"], expected_str, subtests["pass"], len(unexpected))

if unexpected:
    rv += "\nDetails:\n"
    if len(unexpected) == 1 and parent_unexpected:
        rv += "%s\n" % unexpected[0][1]
    else:
        for name, message in data:
        rv += "%s\n" % ("\n".join([name, "-" * len(name), message]))

return rv

That may add too many line breaks; you'll need to try it out and adjust as necessary.
Attachment #8454815 - Flags: review?(james) → review-
I believe this is a recent regression, and if my understanding is correct, for the tests it effects, it effectively makes those tests undiagnosable from the logs or reading stderr.
Keywords: regression
Hi Arnav -- Thanks for the patch!   My team really needs it!   Do you think you could create an update to your patch with jgraham's review comments addressed by tomorrow (Wednesday)?  

(See Comment 2 for jgraham's review comments.)

Thank you again, and welcome to Mozilla!
Flags: needinfo?(arnav.pokemonfan)
(Assignee)

Comment 5

3 years ago
Created attachment 8456719 [details] [diff] [review]
bug-1037521-adjust.patch

Just made the changes suggested by jgraham. Thanks a load!
Attachment #8454815 - Attachment is obsolete: true
Attachment #8456719 - Flags: review?(james)
Flags: needinfo?(arnav.pokemonfan)
(Assignee)

Comment 6

3 years ago
Created attachment 8456727 [details] [diff] [review]
bug-1037521-realadjust.patch

I'm an idiot and uploaded an empty patch. Sorry, new to this hg stuff. Anyways, I just added suggestions by jgraham. Thanks.
Attachment #8456719 - Attachment is obsolete: true
Attachment #8456719 - Flags: review?(james)
Attachment #8456727 - Flags: review?(james)
(Reporter)

Comment 7

3 years ago
Comment on attachment 8456727 [details] [diff] [review]
bug-1037521-realadjust.patch

Review of attachment 8456727 [details] [diff] [review]:
-----------------------------------------------------------------

Looking good, just a small number of fixups and I think we will be ready to go.

::: testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
@@ +59,2 @@
>          else:
>              expected_str = ""

Need to set parent_unexpected = False

@@ +59,4 @@
>          else:
>              expected_str = ""
>  
>          subtests = self._get_subtest_data(data)

This needs to be at the top of the method or subtests will be undefined above.

@@ +59,5 @@
>          else:
>              expected_str = ""
>  
>          subtests = self._get_subtest_data(data)
> +        

This seems to be a whitespace error.

@@ +68,3 @@
>          self.has_unexpected[test] = bool(unexpected)
>  
> +        rv = "Harness status %s%s. Subtests passed %i/%i. Unexpected [%s]" % (

Get rid of the square brackets around the unexpected count here.

Also, I'm not sure if we should do it in this patch, but it just occurred to me that this output should switch on whether there are subtests (using some imaginary has_subtests variable):

if subtests["count"] != 0:
    rv = "Harness status %s%s. Subtests passed %i/%i. Unexpected [%s]" % (
        data["status"], expected_str, subtests["pass"], len(unexpected))
else:
    rv = "Status %s%s" % (data["status"], expected_str)

@@ +82,1 @@
>      def test_status(self, data):

Need a linebreak between methods
Attachment #8456727 - Flags: review?(james) → review-
(Assignee)

Comment 8

3 years ago
Created attachment 8456743 [details] [diff] [review]
patch-1037521-fixes.patch

Heh, made a couple errors in the code that broke stuff (as well as some style errors). This patch should take care of them.
Attachment #8456727 - Attachment is obsolete: true
Attachment #8456743 - Flags: review?(james)
(Reporter)

Comment 9

3 years ago
Arnav: do you have a folded version of this patch ready?
Flags: needinfo?(arnav.pokemonfan)
(Reporter)

Comment 10

3 years ago
Created attachment 8460337 [details] [diff] [review]
Add information about unexpected results to mach output.
Attachment #8456743 - Attachment is obsolete: true
Attachment #8456743 - Flags: review?(james)
Attachment #8460337 - Flags: review?(cmanchester)
Comment on attachment 8460337 [details] [diff] [review]
Add information about unexpected results to mach output.

Review of attachment 8460337 [details] [diff] [review]:
-----------------------------------------------------------------

This still doesn't log the stack for tests with no subtests, so it doesn't address the issue debugging marionette failures locally.

::: testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
@@ +73,5 @@
> +
> +        if unexpected:
> +            rv += "\n"
> +            if len(unexpected) == 1 and parent_unexpected:
> +                rv += "%s" % unexpected[0][1]

This only gives the status of the test, we need the message too.
Attachment #8460337 - Flags: review?(cmanchester) → review-
(Reporter)

Comment 12

3 years ago
Created attachment 8460365 [details] [diff] [review]
Add information about unexpected results to mach output.
Attachment #8460337 - Attachment is obsolete: true
Attachment #8460365 - Flags: review?(cmanchester)
Comment on attachment 8460365 [details] [diff] [review]
Add information about unexpected results to mach output.

Review of attachment 8460365 [details] [diff] [review]:
-----------------------------------------------------------------

It might also be helpful to include the test name in the test_end message, but this looks good.
Attachment #8460365 - Flags: review?(cmanchester) → review+
(Reporter)

Comment 14

3 years ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/8ab7e0d27367
https://hg.mozilla.org/mozilla-central/rev/8ab7e0d27367
Assignee: nobody → arnav.pokemonfan
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla34
(Reporter)

Updated

3 years ago
Flags: needinfo?(arnav.pokemonfan)
You need to log in before you can comment on or make changes to this bug.