Bug 162177 – Web Inspector: Improve output of TestHarness.expect* failures

• Status: RESOLVED
• Resolution: FIXED
• Component: Web Inspector

[Matt Baker]

Summary:
Improve output of TestHarness.expect* failures. With the exception of expectThat, expectation failures should log details about the failing test and the value of actual and expected parameters.

Example output, loosely based on assertion messages in XCTest:

InspectorTest.expectFalse("abc");
InspectorTest.expectNull({});
InspectorTest.expectEqual(1.23, 4.56, "Should be equal."); // optional message appended after template failure message

FAIL: ("abc" is false) failed
FAIL: ({} is null) failed
FAIL: (1.23 equal to 4.56) failed: Should be equal.

[Radar WebKit Bug Importer]

<rdar://problem/28367186>

[Matt Baker]

Created attachment 289243 [details]
Patch

[Joseph Pecoraro]

Comment on attachment 289243 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=289243&action=review

> LayoutTests/inspector/unit-tests/test-harness-expect-functions-expected.txt:33
> +FAIL: (true is false) failed: expectFalse(true)
> +FAIL: (1 is false) failed: expectFalse(1)
> +FAIL: ("abc" is false) failed: expectFalse("abc")
> +FAIL: ({} is false) failed: expectFalse({})
> +FAIL: ([] is false) failed: expectFalse([])

This output doesn't read clearly to me. (true is null)? (null not null)? These don't make sense!

I would like output that makes it very clear what is expected and what the actual value is:

    FAIL: message
        Expected: <description of expectation> || JSON.stringify(expected) || expected.toString()
        Actual: JSON.stringify(actual) || actual.toString() || best description

So in these cases, we'd get something like:

    FAIL: expectFalse(true)
        Expected: false
        Actual: true

    FAIL: expectFalse({})
        Expected: false
        Actual: {}

Or in realistic cases:

    // InspectorTest.expectEqual(expectedKeysOrderedByName[i], key.value, `Key should be ordered by name.`);
    FAIL: Key should be ordered by name.
        Expected: "Jamming Peacock"
        Actual: "Thirsty Hampster"

    // InspectorTest.expectEqual(0, names.length, "No IndexedDB databases should exist initially.")
    FAIL: No IndexedDB databases should exist initially.
        Expected: 0
        Actual: 1

Things will get much harder when one of the values cannot be JSON.stringified, and toString() mostly just produces [object Object]. We could find the constructor name since many of our tests deal with WebInspector.Object instances.

Examples where we would run into problems:

    // InspectorTest.expectFalse(nodeStyles.inlineStyle, "No Inline Styles");
    FAIL: No Inline Styles
        Expected: falsey
        Actual: WebInspector.CSSStyleDeclaration instance

    // InspectorTest.expectEquals(insertedOrRemovedDOMNode.parentNode, testDOMNode, "New DOMNode is a child of #x");
    FAIL: New DOMNode is a child of #x
        Expected: DOMNode instance
        Actual: DOMNode instance

Note that right now expect(foo, bar) does not have the concept of which argument is the expected or the actual. We would need to make a decision and start applying it.

Another note, I also had high hopes that for simple cases we would print the expected value. Throwing out some ideas:

    // InspectorTest.expectEqual("Jamming Peacock", key.value, "Name is $$")
    PASS: Name is "Jamming Peacock"

    // InspectorTest.expectEqual("Jamming Peacock", key2.value, "Name is $$")
    FAIL: Name is "Jamming Peacock"
        Expected "Jamming Peacock"
        Actual: "Thirsty Hampster"

The advantage here being that even the passing test shows the nice expected values instead of just "PASS PASS PASS" with no idea of what values it got, it has "PASS: Foo PASS: Bar PASS: Zzz". All without the expectation having to double type the expected value.

Does this match your expectations too?

[Matt Baker]

(In reply to comment #3)
> Comment on attachment 289243 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=289243&action=review
> 
> > LayoutTests/inspector/unit-tests/test-harness-expect-functions-expected.txt:33
> > +FAIL: (true is false) failed: expectFalse(true)
> > +FAIL: (1 is false) failed: expectFalse(1)
> > +FAIL: ("abc" is false) failed: expectFalse("abc")
> > +FAIL: ({} is false) failed: expectFalse({})
> > +FAIL: ([] is false) failed: expectFalse([])
> 
> This output doesn't read clearly to me. (true is null)? (null not null)?
> These don't make sense!

This is the way XCTest assertions are formatted, but I agree they're convoluted. We can do better!

> I would like output that makes it very clear what is expected and what the
> actual value is:
> 
>     FAIL: message
>         Expected: <description of expectation> || JSON.stringify(expected)
> || expected.toString()
>         Actual: JSON.stringify(actual) || actual.toString() || best
> description

I like the idea of using value.toString(). How about using String(value) instead, as it handles null/undefined and calls toString internally anyway? So now when creating an argument description we have:

- If value is "string", output quoted string
- If typeof value is "object", output JSON.stringify
- If JSON.stringify throws, output "[object Object]"
- Otherwise output String(value)

> So in these cases, we'd get something like:
> 
>     FAIL: expectFalse(true)
>         Expected: false
>         Actual: true
> 
>     FAIL: expectFalse({})
>         Expected: false
>         Actual: {}
> 
> Or in realistic cases:
> 
>     // InspectorTest.expectEqual(expectedKeysOrderedByName[i], key.value,
> `Key should be ordered by name.`);
>     FAIL: Key should be ordered by name.
>         Expected: "Jamming Peacock"
>         Actual: "Thirsty Hampster"
> 
>     // InspectorTest.expectEqual(0, names.length, "No IndexedDB databases
> should exist initially.")
>     FAIL: No IndexedDB databases should exist initially.
>         Expected: 0
>         Actual: 1
> 
> Things will get much harder when one of the values cannot be
> JSON.stringified, and toString() mostly just produces [object Object]. We
> could find the constructor name since many of our tests deal with
> WebInspector.Object instances.
> 
> Examples where we would run into problems:
> 
>     // InspectorTest.expectFalse(nodeStyles.inlineStyle, "No Inline Styles");
>     FAIL: No Inline Styles
>         Expected: falsey

I'll change the output to "falsey" since the actual value isn't strictly false.

>         Actual: WebInspector.CSSStyleDeclaration instance
> 
>     // InspectorTest.expectEquals(insertedOrRemovedDOMNode.parentNode,
> testDOMNode, "New DOMNode is a child of #x");
>     FAIL: New DOMNode is a child of #x
>         Expected: DOMNode instance
>         Actual: DOMNode instance
> 
> Note that right now expect(foo, bar) does not have the concept of which
> argument is the expected or the actual. We would need to make a decision and
> start applying it.

That's fine. It's common for test frameworks to name assert/expect arguments.

> Another note, I also had high hopes that for simple cases we would print the
> expected value. Throwing out some ideas:
> 
>     // InspectorTest.expectEqual("Jamming Peacock", key.value, "Name is $$")
>     PASS: Name is "Jamming Peacock"
> 
>     // InspectorTest.expectEqual("Jamming Peacock", key2.value, "Name is $$")
>     FAIL: Name is "Jamming Peacock"
>         Expected "Jamming Peacock"
>         Actual: "Thirsty Hampster"
> 
> The advantage here being that even the passing test shows the nice expected
> values instead of just "PASS PASS PASS" with no idea of what values it got,
> it has "PASS: Foo PASS: Bar PASS: Zzz". All without the expectation having
> to double type the expected value.
> 
> Does this match your expectations too?

Great feedback! I'm not sure about adding extra output in the passing case, but we could revisit that later.

[Matt Baker]

Some expectation functions can't be clearly represented as a failure/expected/actual message:

// InspectorTest.expectNotNull(curl[0].match("https?://.*?/resources/url\\?query=true"), "Command should contain URL.");
FAIL: Command should contain URL.
    Expected: ? 
    Actual: null

// InspectorTest.expectNotEqual(event.data.styleSheet, addedStyleSheet, "Added StyleSheet should be different from the last added stylesheet.");
FAIL: Added StyleSheet should be different from the last added stylesheet.
    Expected: ?
    Actual: ?

These cases could be formatted as:

// InspectorTest.expectNotNull(curl[0].match("https?://.*?/resources/url\\?query=true"), "Command should contain URL.");
FAIL: Expected not null failed. Command should contain URL.

// InspectorTest.expectNotEqual(event.data.styleSheet, addedStyleSheet, "Added StyleSheet should be different from the last added stylesheet.");
FAIL: Expected not equal failed. Added StyleSheet should be different from the last added stylesheet.

[Joseph Pecoraro]

(In reply to comment #5)
> Some expectation functions can't be clearly represented as a
> failure/expected/actual message:
> 
> //
> InspectorTest.expectNotNull(curl[0].match("https?://.*?/resources/
> url\\?query=true"), "Command should contain URL.");
> FAIL: Command should contain URL.
>     Expected: ? 
>     Actual: null
> 
> // InspectorTest.expectNotEqual(event.data.styleSheet, addedStyleSheet,
> "Added StyleSheet should be different from the last added stylesheet.");
> FAIL: Added StyleSheet should be different from the last added stylesheet.
>     Expected: ?
>     Actual: ?

In some cases I expected "Expected: <description>", where description is hard coded for a few of the tests that are loose (expectFalse, expectNotNull)

    Expected: falsey
    Actual: ...

    Expected: not null
    Actual: null

The expectNotEqual() could prefix with "not" and print both instances as best as it can:

    Expected: not Foo instance
    Actual: Foo instance

And we can even assign our own (id) to any instance we log in this way.

    let failureObjects = new Map;
    let failureObjectIdentifier = 1;
    ...
    let id = failureObjects.get(o);
    if (!id) {
        id = failureObjectIdentifier++;
        failureObjects.set(o, id);
    }
    return "#" + id
    ...

To get:

    Expected: not Foo instance #1
    Actual: Foo instance #1


> These cases could be formatted as:
> 
> //
> InspectorTest.expectNotNull(curl[0].match("https?://.*?/resources/
> url\\?query=true"), "Command should contain URL.");
> FAIL: Expected not null failed. Command should contain URL.
> 
> // InspectorTest.expectNotEqual(event.data.styleSheet, addedStyleSheet,
> "Added StyleSheet should be different from the last added stylesheet.");
> FAIL: Expected not equal failed. Added StyleSheet should be different from
> the last added stylesheet.

These are fine but still require a little more work on the eyes to parse the sentence instead of just looking at Expected / Actual values. That said I'm less concerned about this, and probably more concerned with the most common case (expectEquals).

[Joseph Pecoraro]

> >     FAIL: message
> >         Expected: <description of expectation> || JSON.stringify(expected)
> > || expected.toString()
> >         Actual: JSON.stringify(actual) || actual.toString() || best
> > description
> 
> I like the idea of using value.toString(). How about using String(value)
> instead, as it handles null/undefined and calls toString internally anyway?
> So now when creating an argument description we have:
> 
> - If value is "string", output quoted string
> - If typeof value is "object", output JSON.stringify
> - If JSON.stringify throws, output "[object Object]"
> - Otherwise output String(value)

- JSON.stringify handles the top 2 cases, no need to special case "string".
- How do we reach the 4th case in the above?

I suggest something like:

    function dumpValue(value) {
        try {
            return JSON.stringify(value);
        } catch (e) { }

        try {
            let s = String(value);
            if (s === "[object Object]" && s.constructor && s.constructor.name !== "Object")
                return s.constructor.name + " Instance" + instanceIdentifier(value);
            return s;
        } catch (e) { }

        // FIXME: I don't know how we would get here. But if we do... handle it.
        return "?";
    }

instanceIdentifier is optional. And we may want to refine this later (if JSON.stringify() is super large, we should truncate). But this gets us a good start.

[Blaze Burg]

Comment on attachment 289243 [details]
Patch

Agree with Joe's comments. Can you post a revised patch?

[Matt Baker]

(In reply to comment #7)
> > >     FAIL: message
> > >         Expected: <description of expectation> || JSON.stringify(expected)
> > > || expected.toString()
> > >         Actual: JSON.stringify(actual) || actual.toString() || best
> > > description
> > 
> > I like the idea of using value.toString(). How about using String(value)
> > instead, as it handles null/undefined and calls toString internally anyway?
> > So now when creating an argument description we have:
> > 
> > - If value is "string", output quoted string
> > - If typeof value is "object", output JSON.stringify
> > - If JSON.stringify throws, output "[object Object]"
> > - Otherwise output String(value)
> 
> - JSON.stringify handles the top 2 cases, no need to special case "string".

Adding quotes makes it more obvious the inputs are strings. If the opinion is that this doesn't add value it can be dropped.

Shouldn't toString() have higher priority than JSON.stringify?

let point = new WebInspector.Point(1, 2);
String(point)
  => WebInspector.Point[1,2]

JSON.stringify(point)
  => {"x":1,"y":2}

> - How do we reach the 4th case in the above?
> 
> I suggest something like:
> 
>     function dumpValue(value) {
>         try {
>             return JSON.stringify(value);
>         } catch (e) { }
> 
>         try {
>             let s = String(value);
>             if (s === "[object Object]" && s.constructor &&
> s.constructor.name !== "Object")
>                 return s.constructor.name + " Instance" +
> instanceIdentifier(value);
>             return s;
>         } catch (e) { }
> 
>         // FIXME: I don't know how we would get here. But if we do... handle
> it.
>         return "?";
>     }
> 
> instanceIdentifier is optional. And we may want to refine this later (if
> JSON.stringify() is super large, we should truncate). But this gets us a
> good start.

[Joseph Pecoraro]

> > - JSON.stringify handles the top 2 cases, no need to special case "string".
> 
> Adding quotes makes it more obvious the inputs are strings. If the opinion
> is that this doesn't add value it can be dropped.

JSON.stringify includes the quotes, and that is precisely why I'm suggesting it:

    js> JSON.stringify("str")
    "\"str\""

> Shouldn't toString() have higher priority than JSON.stringify?
> 
> let point = new WebInspector.Point(1, 2);
> String(point)
>   => WebInspector.Point[1,2]

I think JSON.stringify handles the majority of cases. When it fails we should do something else. I could be convinced if there is a general case where toString would be better. Even in the Point example above, I think the JSON output is pretty clear. There may be other WebInspector Objects that stringify poorly and would be better suited by a toString. Very few of our classes even implement toString.

[Matt Baker]

(In reply to comment #10)
> > Shouldn't toString() have higher priority than JSON.stringify?
> > 
> > let point = new WebInspector.Point(1, 2);
> > String(point)
> >   => WebInspector.Point[1,2]
> 
> I think JSON.stringify handles the majority of cases. When it fails we
> should do something else. I could be convinced if there is a general case
> where toString would be better. Even in the Point example above, I think the
> JSON output is pretty clear. There may be other WebInspector Objects that
> stringify poorly and would be better suited by a toString. Very few of our
> classes even implement toString.

All good points. Revised patch with recommended improvements incoming.

[Matt Baker]

Some new output:

// InspectorTest.expectNotShallowEqual({a: 1, b: 2}, {a: 1, b: 2})
FAIL: expectNotShallowEqual({"a":1,"b":2}, {"a":1,"b":2})
    Expected: not {"a":1,"b":2}
    Actual: {"a":1,"b":2}

// InspectorTest.expectEqualWithAccuracy(0, 2, 1)
FAIL: expectEqualWithAccuracy(0, 2, 1)
    Expected: 0 +/- 1
    Actual: 2

// InspectorTest.expectLessThan(0, 1)
FAIL: expectLessThan(0, 1)
    Expected: less than 0
    Actual: 1

// InspectorTest.expectLessThanOrEqual(0, 1)
FAIL: expectLessThanOrEqual(0, 1)
    Expected: less than or equal to 0
    Actual: 1

[Matt Baker]

We should establish the convention that the actual value precedes the expected value. There are some good reasons to adopt this order:

1. It matches the way inequality functions are read
2. Some functions don't take an expected value (expectThat, expectFalse, etc)
3. XCTest uses it

[Matt Baker]

(In reply to comment #12)
> // InspectorTest.expectLessThan(0, 1)
> FAIL: expectLessThan(0, 1)
>     Expected: less than 0
>     Actual: 1
> 
> // InspectorTest.expectLessThanOrEqual(0, 1)
> FAIL: expectLessThanOrEqual(0, 1)
>     Expected: less than or equal to 0
>     Actual: 1

This output was created when the argument order was: expected, actual.

[Matt Baker]

Created attachment 289412 [details]
Patch

[Joseph Pecoraro]

Comment on attachment 289412 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=289412&action=review

r=me! Be sure to fix the typo

> Source/WebInspectorUI/UserInterface/Test/TestHarness.js:219
> +        const maximumValueStringLength = 100;

We might want to bump this up to 200. I prefer JSON much more then "instance" even if there are ~ 10 properties and it goes over 100 characters.

> Source/WebInspectorUI/UserInterface/Test/TestHarness.js:224
> +        // Special case for numbers, since JSON.stringify converts Infinity and NaN to null.
> +        if (typeof value === "number")
> +            return value;

Nice. We could even special case -0 (see InjectedScriptSource), but that seems pretty rare.

> Source/WebInspectorUI/UserInterface/Test/TestHarness.js:226
> +        let valueString;

Would be cleaner to just put the `let` inside each of the try blocks.

> Source/WebInspectorUI/UserInterface/Test/TestHarness.js:249
> +    _expectationMessageFormat(type)
> +    {
> +        switch (type) {
> +        case TestHarness.ExpectationType.True:
> +            return "expectThat(%s)";
> +        case TestHarness.ExpectationType.False:
> +            return "expectFalse(%s)";

This auto-message strikes me as kind of useless. Because normally a test would have an expression that gets lost. For example:

    expectEquals(key.name, "JoePeck")

It looks like this would produce:

    // expectEquals(<resolvedValue>, expectedValue)
    FAIL: expectEquals("Johnny Appleseed", "JoePeck")
        Expected: "JoePeck"
        Actual: "Johnny Appleseed"

When we would really want (the somewhat impossible):

    // expectEquals(<originalExpression>, expectedValue)
    FAIL: expectEquals(key.name, "JoePeck")
        Expected: "JoePeck"
        Actual: "Johnny Appleseed"

The way that LayoutTests do this right now via "shouldBe*" functions is that they take strings to eval. So it has the string "key.name" and can eval it to get the result. The eval approach makes test writing ugly, but produces nice output. I think what you have now is fine. Especially since it is the default message, and we will most likely be providing messages.

> Source/WebInspectorUI/UserInterface/Test/TestHarness.js:255
> +            return "expetEqual(%s, %s)";

Typo: "expet" => "expect"

[Build Bot]

Comment on attachment 289412 [details]
Patch

Attachment 289412 [details] did not pass mac-wk2-ews (mac-wk2):
Output: http://webkit-queues.webkit.org/results/2115313

New failing tests:
inspector/unit-tests/number-utilities.html
inspector/indexeddb/requestData.html

[Build Bot]

Created attachment 289415 [details]
Archive of layout-test-results from ews105 for mac-yosemite-wk2

The attached test failures were seen while running run-webkit-tests on the mac-wk2-ews.
Bot: ews105  Port: mac-yosemite-wk2  Platform: Mac OS X 10.10.5

[Build Bot]

Comment on attachment 289412 [details]
Patch

Attachment 289412 [details] did not pass mac-ews (mac):
Output: http://webkit-queues.webkit.org/results/2115328

New failing tests:
inspector/indexeddb/requestData.html
inspector/unit-tests/number-utilities.html

[Build Bot]

Created attachment 289416 [details]
Archive of layout-test-results from ews101 for mac-yosemite

The attached test failures were seen while running run-webkit-tests on the mac-ews.
Bot: ews101  Port: mac-yosemite  Platform: Mac OS X 10.10.5

[Build Bot]

Comment on attachment 289412 [details]
Patch

Attachment 289412 [details] did not pass mac-debug-ews (mac):
Output: http://webkit-queues.webkit.org/results/2115352

New failing tests:
inspector/unit-tests/number-utilities.html
inspector/indexeddb/requestData.html

[Build Bot]

Created attachment 289418 [details]
Archive of layout-test-results from ews117 for mac-yosemite

The attached test failures were seen while running run-webkit-tests on the mac-debug-ews.
Bot: ews117  Port: mac-yosemite  Platform: Mac OS X 10.10.5

[Matt Baker]

Test failures are being caused by changes to expectation output for FAIL cases. Will include updated expectations.

[Matt Baker]

Created attachment 289477 [details]
Patch

[WebKit Commit Bot]

Comment on attachment 289477 [details]
Patch

Clearing flags on attachment: 289477

Committed r206237: <http://trac.webkit.org/changeset/206237>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.