Closed Bug 983672 Opened 6 years ago Closed 6 years ago

Put custom messages into wait_for_condition

Categories

(Firefox OS Graveyard :: Gaia::UI Tests, defect)

x86_64
Linux
defect
Not set

Tracking

(Not tracked)

RESOLVED WONTFIX

People

(Reporter: zcampbell, Unassigned)

Details

Attachments

(1 file)

To save time re-running tests to debug, put custom messages everywhere we can.

On Travis pull requests where there are no screenshots or report it is difficult to debug.

We can just be smarter about our waits.

For example
wait_for_condition(lambda: element.location['x'] == 0) does not fail very nicely.

If we used:
wait_for_condition(lambda: element.location['x'] == 0, message="Actual location was %s" %element.location)
then the failure message provides information to resolve the problem.
(In reply to Zac C (:zac) from comment #0)
> If we used:
> wait_for_condition(lambda: element.location['x'] == 0, message="Actual
> location was %s" %element.location)
> then the failure message provides information to resolve the problem.

Note that in this example, element.location in the message could differ from the final value causing the timeout.
Dave has a point, I will begin working on this and see what changes I can add.
I just wanted you guys to have a look on what modification I've made.
These are not all the "wait_for_condition".
I wanted your opinion on this on how should I continue, before changing them all.
Attachment #8393482 - Flags: feedback?(zcampbell)
Attachment #8393482 - Flags: feedback?(florin.strugariu)
Attachment #8393482 - Flags: feedback?(dave.hunt)
Comment on attachment 8393482 [details] [review]
PR https://github.com/mozilla-b2g/gaia/pull/17327

I think we can definitely over-do this. We don't need to put a custom message into every single place we use wait_for_condition.

We really only need to do it when it's a bit vague, or when the condition we're waiting for is not a boolean.

For example:
self.wait_for_condition(lambda m: m.execute_script("return window.wrappedJSObject.Browser.hasLoaded;")
that can really only be true or false so the stack trace is quite easy to understand.

self.wait_for_condition(lambda m: main_screen.location['x'] == 0)
This one does need a custom message because the location could be 10, 320, 1000+.. 
An example of this one was when a dev was changing the height of the status bar. Our wait failed because the element was not at ['x'] == 20 because after his patch it was at ['x'] == 24. with the custom message he'd immediately know how to change the test and what to, because he already knew that he was increasing the statusbar height by 4px.
Attachment #8393482 - Flags: feedback?(zcampbell) → feedback-
Comment on attachment 8393482 [details] [review]
PR https://github.com/mozilla-b2g/gaia/pull/17327

Totally agree with Zac here. I would like to see that most tracebacks are readable as they are. I'm also still concerned that we may be giving false information in that the message will report the value at the time the message is created and not necessarily represent the value that cause the timeout.

It feels like we could solve this by having a wait that took the two values to compare and included the values that mismatched at the time the timeout is thrown.

It could look something like:
Wait(marionette).until(expected.equal('foo', 'bar'))

With a trace of:
TimeoutException: Timed out after 30.0 seconds with message: expected 'foo' but found 'bar'

I'm not sure how easy this would be. Andreas, do you think this would be worth looking into?
Attachment #8393482 - Flags: feedback?(dave.hunt) → feedback-
Flags: needinfo?(ato)
Comment on attachment 8393482 [details] [review]
PR https://github.com/mozilla-b2g/gaia/pull/17327

the boys are right :D
Attachment #8393482 - Flags: feedback?(florin.strugariu) → feedback-
(In reply to Dave Hunt (:davehunt) from comment #5)
> It feels like we could solve this by having a wait that took the two
> values to compare and included the values that mismatched at the
> time the timeout is thrown.
>
> It could look something like:
> Wait(marionette).until(expected.equal('foo', 'bar'))
>
> With a trace of:
> TimeoutException: Timed out after 30.0 seconds with message: expected 'foo'
> but found 'bar'
>
> I'm not sure how easy this would be. Andreas, do you think this
> would be worth looking into?

This is an interesting idea, but not something I'm convinced can be
easily implemented.  The obstacle consists of how to get the message
parameter populated by the condition's return value.

Simplified, we're looking at something like:

    def equal(a, b):
        def inner():
            return a == b

        return inner, "expected '%s' but got '%s'" % (a, b)

    def until(cond, message=""):
        rv = cond()
        if not rv:
            raise Exception(message)
        return rv

    are_equal = until(*equal(1, 2))
    assert are_equal

I'm unsure if there's a way to do this without needing to unwrap
equal's return value using an astrisk.
Flags: needinfo?(ato)
I had another think about this problem and tried to come up with some real-life use cases involving some typical Marionette use and the prototype code I wrote above.  The short version is that it wasn't pretty.

Because the Wait class passes along the Marionette instance object when the function passed into until is called, you'd need yet another anonymous function inside the equal to make use of it since equal is already a closure.  An alternative would be to have a more specialized version of equal that would behave more like a delegator to some specific functionality, but that seems very unintuitive.

Another possible approach could be to introspect the function passed into until(func) and the values used in the return statement, much like what pytest does [1].

This _might_ allow us to get something like this:

Wait(marionette).until(lambda: element.location["x"] == 0)
TimeoutException: Timed out after 30.0 seconds on:
    lambda marionette: 42 = 0

But the fundamental request here is very hard to achieve.  To introspect an anonymous function and specifically the return statement, which in Python could be left implicit, and then the values used in that line is a difficult problem.  I'm not sure how feasible this is, or even if it's possible. 

1. See https://gist.github.com/andreastt/9781575 for an example.
We all agree that this is a good practice but it's hard to change the suite and/or framework in one big go.

We'll make it a good practice of ours to use custom messages where we can.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.