Marionette should always include the test filename in TEST-UNEXPECTED-FAIL messages

RESOLVED FIXED in Firefox 18

Status

Product:
Testing
Component:
Marionette
Type:
defect
Status:
RESOLVED FIXED
Opened:
7 years ago
Updated:
7 years ago

People

(Reporter: jgriffin, Assigned: jgriffin)

Tracking

Version:
unspecified
Target:
mozilla19
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox18 fixed, firefox19 fixed)

Details

Attachments

(1 attachment, 6 obsolete attachments)

Include test names in failure messages v0.3,
11.55 KB, patch
jgriffin
: review+
Details | Diff | Splinter Review 
Marionette should always include the test filename in TEST-UNEXPECTED-FAIL messages.  Currently it doesn't, at least not for JS tests, and this leads to vague messages in TBPL like:

20:12:50 INFO - TEST-UNEXPECTED-FAIL : ScriptTimeoutException: timed out

The test filename is in the Python exception block, but this doesn't get picked up by TBPL.

This will make Marionette hard to sheriff/star, until this is fixed.
Assignee: nobody → jgriffin
I'm going to land this on cedar to see how well it works.
Posted patch Fix for previous patch (obsolete) — — Splinter Review 
This patch lands on top of the previous, and fixes some of the issues I've seen while running this on cedar.  I will land this directly on cedar as well.
...since the latter breaks bug suggestions on TBPL.
Posted patch Another logging tweak (obsolete) — — Splinter Review 
This is running on cedar and works well.  We still have duplicate error messages showing for Marionette tests, but that's because the errors get dumped to logcat and the console, and in case there are failure, the mozharness script dumps the logcat.
Attachment #677197 - Flags: review?(ahalberstadt)
Attachment #675894 - Attachment is obsolete: true
Attachment #676799 - Attachment is obsolete: true
Attachment #676771 - Attachment is obsolete: true
Attachment #676754 - Attachment is obsolete: true
Comment on attachment 677197 [details] [diff] [review]
Include test names in failure messages

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

LGTM.

::: testing/marionette/client/marionette/marionette.py
@@ +272,5 @@
>          self.b2g = 'b2g' in self.session
>          return self.session
>  
> +    def set_test_name(self, test_name=None):
> +        return self._send_message('setTestName', 'ok', value=test_name)

Optional suggestion: Not sure if this would make sense (or if it's even possible), but what if we used property decorators instead. Something like:

@property
def test_name(self):
    return self._test_name

@test_name.setter
def test_name(self, value):
    if self._send_message('setTestName', 'ok', value=value) == 'ok':
        self._test_name = value

This way the python client could always see the latest value that has been sent to the js side and also wouldn't need to call the getInfo() method to get the test name. Anyway, like I said, I'm not super familiar with how everything fits together so feel free to disregard.

::: testing/marionette/client/marionette/marionette_test.py
@@ +116,5 @@
>      def setUp(self):
>          CommonTestCase.setUp(self)
> +        test_name = '%s.py %s.%s' % (self.__class__.__module__,
> +                                     self.__class__.__name__,
> +                                     self._testMethodName)

nit: shouldn't this call MarionetteTestResult.getInfo()?
Attachment #677197 - Flags: review?(ahalberstadt) → review+
(In reply to Andrew Halberstadt [:ahal] from comment #6)
> Comment on attachment 677197 [details] [diff] [review]
> Include test names in failure messages
> 
> Review of attachment 677197 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> LGTM.
> 
> ::: testing/marionette/client/marionette/marionette.py
> @@ +272,5 @@
> >          self.b2g = 'b2g' in self.session
> >          return self.session
> >  
> > +    def set_test_name(self, test_name=None):
> > +        return self._send_message('setTestName', 'ok', value=test_name)
> 
> Optional suggestion: Not sure if this would make sense (or if it's even
> possible), but what if we used property decorators instead. Something like:
> 
> @property
> def test_name(self):
>     return self._test_name
> 
> @test_name.setter
> def test_name(self, value):
>     if self._send_message('setTestName', 'ok', value=value) == 'ok':
>         self._test_name = value
> 
> This way the python client could always see the latest value that has been
> sent to the js side and also wouldn't need to call the getInfo() method to
> get the test name. Anyway, like I said, I'm not super familiar with how
> everything fits together so feel free to disregard.

Good suggestion, I'll make that change.

> 
> ::: testing/marionette/client/marionette/marionette_test.py
> @@ +116,5 @@
> >      def setUp(self):
> >          CommonTestCase.setUp(self)
> > +        test_name = '%s.py %s.%s' % (self.__class__.__module__,
> > +                                     self.__class__.__name__,
> > +                                     self._testMethodName)
> 
> nit: shouldn't this call MarionetteTestResult.getInfo()?

This method doesn't have access to a MarionetteTestResult instance.  But, I can move this logic into CommonTestCase, which can be called *from* MarionetteTestResult.  I'll make this change and try it on cedar.
Updated with review comments
Attachment #677197 - Attachment is obsolete: true
Comment on attachment 677851 [details] [diff] [review]
Include test names in failure messages

Carry r+ forward.
Attachment #677851 - Flags: review+
Please can we land this on m-c soon; I suspect philor will be re-hiding marionette soon otherwise...

16:07:50 - philor: "TEST-UNEXPECTED-FAIL : AssertionError"
16:08:01 - philor: oh, marionette, we're not going to get along, you and I, are we?
16:08:16 - AutomatedTester: philor: ?
16:08:25 - philor: https://tbpl.mozilla.org/php/getParsedLog.php?id=16753491&tree=Mozilla-Inbound
16:09:13 - AutomatedTester: philor: error could be made more helpful
16:09:21 - AutomatedTester: but the line above is what failed
16:09:38 - philor: yeah, there's the disconnect
16:10:18 - philor: because as far as I'm concerned, a TEST-UNEXPECTED-FAIL line with no test name, and no statement of what failed is utterly useless, beyond pointless, and unacceptable for being visible
Blocks: 808091
I'll land it today.
Thank you :-)
I'm not sure this will be enough - turning that into "07:49:26 INFO - TEST-UNEXPECTED-FAIL | test_switch_frame.TestSwitchFrame | AssertionError" still leaves us with a single bug for every AssertionError in test_switch_frame.TestSwitchFrame, with absolutely no way to see what AssertionError it was unless someone looks at the log in less than 30 days and copy-pastes it into the bug.
(In reply to Phil Ringnalda (:philor) from comment #14)
> I'm not sure this will be enough - turning that into "07:49:26 INFO -
> TEST-UNEXPECTED-FAIL | test_switch_frame.TestSwitchFrame | AssertionError"
> still leaves us with a single bug for every AssertionError in
> test_switch_frame.TestSwitchFrame, with absolutely no way to see what
> AssertionError it was unless someone looks at the log in less than 30 days
> and copy-pastes it into the bug.

I'll land this patch and we'll address that issue with a follow-up bug.
https://hg.mozilla.org/mozilla-central/rev/4e87d8355501
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Whiteboard: [automation-needed-in-aurora]
Try run for 0a5bbd3257c9 is complete.
Detailed breakdown of the results available here:
    https://tbpl.mozilla.org/?tree=Try&rev=0a5bbd3257c9
Results (out of 4 total builds):
    success: 4
Builds (or logs if builds failed) available at:
http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/jgriffin@mozilla.com-0a5bbd3257c9
(In reply to Jonathan Griffin (:jgriffin) from comment #17)
> https://hg.mozilla.org/mozilla-central/rev/4e87d8355501

This patch is empty.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
(In reply to :Ms2ger from comment #19)
> (In reply to Jonathan Griffin (:jgriffin) from comment #17)
> > https://hg.mozilla.org/mozilla-central/rev/4e87d8355501
> 
> This patch is empty.

I have no explanation for this!

The patch was bitrotted by today, so I fixed it up and pushed it to try just to be safe:

https://tbpl.mozilla.org/?tree=Try&rev=47292aac9786
The last patch had a conflict between the 'test_name' property and a 'test_name' method in one of the tests.  Fixed and pushed to try again:

https://tbpl.mozilla.org/?tree=Try&rev=e31ae96471a0
Attachment #677851 - Attachment is obsolete: true
Comment on attachment 678796 [details] [diff] [review]
Include test names in failure messages v0.3,

Carry r+ forward.
Attachment #678796 - Flags: review+
try was green, pushed as https://hg.mozilla.org/integration/mozilla-inbound/rev/c94731604343

(I checked this time!)
Try run for 47292aac9786 is complete.
Detailed breakdown of the results available here:
    https://tbpl.mozilla.org/?tree=Try&rev=47292aac9786
Results (out of 6 total builds):
    success: 2
    warnings: 4
Builds (or logs if builds failed) available at:
http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/jgriffin@mozilla.com-47292aac9786
Try run for 47292aac9786 is complete.
Detailed breakdown of the results available here:
    https://tbpl.mozilla.org/?tree=Try&rev=47292aac9786
Results (out of 7 total builds):
    success: 2
    warnings: 4
    failure: 1
Builds (or logs if builds failed) available at:
http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/jgriffin@mozilla.com-47292aac9786
Try run for e31ae96471a0 is complete.
Detailed breakdown of the results available here:
    https://tbpl.mozilla.org/?tree=Try&rev=e31ae96471a0
Results (out of 7 total builds):
    success: 6
    failure: 1
Builds (or logs if builds failed) available at:
http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/jgriffin@mozilla.com-e31ae96471a0
https://hg.mozilla.org/mozilla-central/rev/c94731604343
Status: REOPENED → RESOLVED
Closed: 7 years ago → 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla19
You need to log in before you can comment on or make changes to this bug.