1136395 - accessibility/mochitest/test/common.js could use some additional output to help debug issues

Status: RESOLVED FIXED

(Testing :: Mochitest, defect)

Description

[Joel Maher ( :jmaher ) (UTC -8)]

in bug 1131720 and bug 1131291 we have issues while running each directory standalone in automation as seen here:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=98fd5e44a30e&filter-searchStr=osx

I looked into printing out some additional information, specifically related to:
08:20:00 INFO - 1373 INFO TEST-UNEXPECTED-FAIL | chrome://mochitests/content/a11y/accessible/tests/mochitest/treeupdate/test_whitespace.html | Different amount of expected children of ['div@id="container1" node', address: [object HTMLDivElement], role: section, address: [xpconnect wrapped nsIAccessible]]. - got 6, expected 5

This doesn't seem easy, but I did print additional information out locally, then pushed to try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=050a4b973e8f

the problem is I couldn't get any a11y tests to fail.  With this one push (and dozens of retriggers) I have no more problems and it is leaning towards a timing issue.

Either way, we should get some useful output printed when we have a failure.  If this happens to fix the 2 a11y issues we see, that becomes an added bonus.

Comment 1

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: adjust the print output testAccessibleTree (0.9)

Comment 2

[alexander :surkov (:asurkov)]

Comment on attachment 8568808 [details] [diff] [review]
adjust the print output testAccessibleTree (0.9)

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

::: accessible/tests/mochitest/common.js
@@ +349,5 @@
>   *                          states   - an object having states and extraStates
>   *                                      fields
>   * @param aFlags          [in, optional] flags, see constants above
>   */
> +function testAccessibleTree(aAccOrElmOrID, aAccTree, aFlags, bChildCountEqual=false, index=-1)

I would prefer to not introduce these arguments, I would rather run though children and reported if unexpected child is encountered.

@@ +372,5 @@
>    for (var prop in accTree) {
>      var msg = "Wrong value of property '" + prop + "' for " + prettyName(acc) + ".";
>  
> +    if (!bChildCountEqual) {
> +      is(true, true, "Warning property from accTree: " + prop + " is defined but child counts are not equal on: " + prettyName(acc) + ", index=" + index);

this should fail

Comment 3

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: print out the difference in children if we find it (0.91)

this patch takes a different approach.  I am not sure if it solves my bugs, but it would print out what differences we have.  I suspect I could do a better job of printing out the unique values, maybe you have a technique I could use for doing that.

Comment 4

[alexander :surkov (:asurkov)]

Comment on attachment 8569811 [details] [diff] [review]
print out the difference in children if we find it (0.91)

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

::: accessible/tests/mochitest/common.js
@@ +453,5 @@
>  
>      is(childCount, accTree.children.length,
>         "Different amount of expected children of " + prettyName(acc) + ".");
>  
> +    if (aFlags & kSkipTreeFullCheck) {

you should report errors not depending on the given flag

@@ +459,3 @@
>          for (var i = 0; i < childCount; i++) {
>            var child = children.queryElementAt(i, nsIAccessible);
>            testAccessibleTree(child, accTree.children[i], aFlags);

it's not necessary to go into grandchildren if children don't match

I think I would do is something like this
if (childCount != accTree.children.length) {
  var idx = 0;
  for (idx < accTree.children.length; idx++) {
    var actualChild = children.queryElementAt(idx, nsIAccessible);
    if (actualChild) {
      var expectedChild = accTree.children[idx];
      isRole(actualChild, expectedChild.role, " at index=bla");
    else {
      ok(false, "No expected child with role=bla at index=bla");
    }
  }
  for (idx < childCount; idx++) {
    var actualChild = children.queryElementAt(idx, nsIAccessible);
    ok(false, "Unexpected child at index=bla" + prettyName(actualChild);
  }

  return;
}

@@ +475,3 @@
>  
>        // nsIAccessible::firstChild
>        var expectedFirstChild = childCount > 0 ?

nit: indentation wasn't fixed here, you may change 'if' statement above to avoid this

Comment 5

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: print out the difference in children if we find it (0.95)

this patch is a lot cleaner and should address the issue without causing too much confusion.

Comment 6

[alexander :surkov (:asurkov)]

Comment on attachment 8571954 [details] [diff] [review]
print out the difference in children if we find it (0.95)

redirecting request to Yura per our chat

Comment 7

[Yura Zenevich [:yzen] (please use "needinfo")]

Comment on attachment 8571954 [details] [diff] [review]
print out the difference in children if we find it (0.95)

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

Some suggestions inline. Please flip the review back to me take a look. Thanks!

::: accessible/tests/mochitest/common.js
@@ +450,5 @@
>    if ("children" in accTree && accTree["children"] instanceof Array) {
>      var children = acc.children;
>      var childCount = children.length;
>  
> +    if (childCount != accTree.children.length) {

Since we do not know the position of the extra child, I would suggest the following;

for (var i = 0; i < Math.max(accTree.children.length, childCount); i++) {
  var accChild;
  try {
    accChild = children.queryElementAt(i, nsIAccessible));
    if (!accTree.children[i]) {
      ok(false, 'acc has an extra child at index ' + i + ' : ' + 
        prettyName(accChild));
    }
    if (accChild.role !== accTree.children[i].role) {
      ok(false, 'accTree and acc have different children at index ' + 
        i + ' : ' + JSON.stringify(accTree.children[i]) + ', ' + 
        prettyName(accChild));
    }
    info('Matching accTree and acc child: ' + prettyName(accChild));
  } catch (e) {
    ok(false, 'accTree has an extra child at index ' + i + ' : ' + 
      JSON.stringify(accTree.children[i]));
  }
}

@@ +453,5 @@
>  
> +    if (childCount != accTree.children.length) {
> +      if (childCount < accTree.children.length) {
> +        for (var i=childCount; i < accTree.children.length; i++) {
> +          is(false, "accTree has an extra child: " + accTree.children[i]);

ok(false, ...

@@ +457,5 @@
> +          is(false, "accTree has an extra child: " + accTree.children[i]);
> +        }
> +      } else {
> +        for (var i=accTree.children.length; i < childCount; i++) {
> +          is(false, "acc has an extra child: " + children.queryElementAt(i, nsIAccessible));

ok(false, ...

Comment 8

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: print out the difference in children if we find it (1.0)

this is what it will look like in production:
https://treeherder.mozilla.org/logviewer.html#?job_id=5438181&repo=try

Comment 9

[Yura Zenevich [:yzen] (please use "needinfo")]

Comment on attachment 8573971 [details] [diff] [review]
print out the difference in children if we find it (1.0)

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

Looks good to me, thanks! Just double checking with Alex that he likes the formatting.

Comment 10

[Yura Zenevich [:yzen] (please use "needinfo")]

(In reply to Joel Maher (:jmaher) from comment #8)
> Created attachment 8573971 [details] [diff] [review]
> print out the difference in children if we find it (1.0)
> 
> this is what it will look like in production:
> https://treeherder.mozilla.org/logviewer.html#?job_id=5438181&repo=try

It looks pretty good. Does it work for you, Alex?

Comment 11

[alexander :surkov (:asurkov)]

it's not clear what "accTree and acc" is and it'd be nice to print was we got and what was expected (to not make me looking at the test sources)

Comment 12

[Yura Zenevich [:yzen] (please use "needinfo")]

Hi Joel, would it be possible to slightly change the logged string to include what Alex asked for? Thanks!

Comment 13

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: print out the difference in children if we find it (1.1)

updated with prettyName for acc and accTree instances

Comment 14

[alexander :surkov (:asurkov)]

Comment on attachment 8575932 [details] [diff] [review]
print out the difference in children if we find it (1.1)

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

I'm good as long as my comment about logging format is addressed, redirecting review request to Yura

Comment 15

[Yura Zenevich [:yzen] (please use "needinfo")]

Comment on attachment 8575932 [details] [diff] [review]
print out the difference in children if we find it (1.1)

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

r=me with comments addressed, thanks!

::: accessible/tests/mochitest/common.js
@@ +457,5 @@
> +        var accChild;
> +        try {
> +          accChild = children.queryElementAt(i, nsIAccessible);
> +          if (!accTree.children[i]) {
> +            ok(false, prettyName(acc) + ' has an extra child at index ' + i + ' : ' +

Nit: lets stay within 80 lines and also the file seems to use double quotes, lets keep it that way in this patch too.

@@ +463,5 @@
> +          }
> +          if (accChild.role !== accTree.children[i].role) {
> +            ok(false, prettyName(accTree) + ' and ' + prettyName(acc) +
> +              ' have different children at index ' + i + ' : ' +
> +              JSON.stringify(accTree.children[i]) + ', ' + prettyName(accChild));

With the below comment we would then be able to write prettyName(accTree.children[i])

@@ +466,5 @@
> +              ' have different children at index ' + i + ' : ' +
> +              JSON.stringify(accTree.children[i]) + ', ' + prettyName(accChild));
> +          }
> +          info('Matching ' + prettyName(accTree) + ' and ' + prettyName(acc) +
> +               ' child: ' + prettyName(accChild));

Nit: "child: " -> "child at index " + i + " : "

@@ +468,5 @@
> +          }
> +          info('Matching ' + prettyName(accTree) + ' and ' + prettyName(acc) +
> +               ' child: ' + prettyName(accChild));
> +        } catch (e) {
> +          ok(false, prettyName(accTree) + ' has an extra child at index ' + i + ' : ' +

prettyName(accTree) will just return " '" + accTree + "' ";

I suggest adding a case in prettyName before the final return where we check:

if (aIdentifier && typeof aIdentifier === "object" ) {
  return JSON.stringify(aIdentifier);
}

Nit: lets stay within 80 lines

@@ +469,5 @@
> +          info('Matching ' + prettyName(accTree) + ' and ' + prettyName(acc) +
> +               ' child: ' + prettyName(accChild));
> +        } catch (e) {
> +          ok(false, prettyName(accTree) + ' has an extra child at index ' + i + ' : ' +
> +            JSON.stringify(accTree.children[i]));

With the above comment we would then be able to write prettyName(accTree.children[i])

Comment 16

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: print out the difference in children if we find it (1.2)

updated with nits, thanks for all the review comments!

Comment 17

[Joel Maher ( :jmaher ) (UTC -8)]

inbound:
https://hg.mozilla.org/integration/mozilla-inbound/rev/1e920b44f68e

Comment 18

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/1e920b44f68e