Closed Bug 624686 Opened 11 years ago Closed 11 years ago

Failed for 'subject.enteredTitle == subject.underlinedTitle' in testCheckItemHighlight.js

Categories

(Mozilla QA Graveyard :: Mozmill Tests, defect)

defect
Not set
normal

Tracking

(Not tracked)

VERIFIED FIXED

People

(Reporter: whimboo, Assigned: u279076)

References

()

Details

(Keywords: regression, Whiteboard: [mozmill-test-failure])

Attachments

(3 files, 4 obsolete files)

Module:    /testAwesomeBar/testCheckItemHighlight.js
Test:      testCheckItemHighlight
Failure:   controller.assertJS: Failed for 'subject.enteredTitle == subject.underlinedTitle' 
Branches:  4.0
Platforms: Windows (Vista/Win7)

This regressed recently. First failure appeared on 110107
Tested with nightly Minefield builds on Vista/Win7

What seems to be happening is that we're fetching for autocomplete results and underlined entries before the last character is typed in the test's query because of an inefficient sleep timer value [1]. This is particular to slower machines. In the test, we are searching for 'community', but our entry in the autoCompleteResults contains 'communit' -- race condition. Changing the test to use 'mozilla_grants.html' and searching for 'grants', our entry contains 'grant'
  
[1] http://hg.mozilla.org/qa/mozmill-tests/file/6f9e3affa2dc/firefox/testAwesomeBar/testCheckItemHighlight.js#l86

Currently, I've only seen it pass when raising the sleep timer to 500ms
All is probably happen because of:
http://groups.google.com/group/mozilla.dev.planning/browse_frm/thread/a754afdccebdec54

We should replace the assert calls with waitFor calls to make sure to not fail.
Changed all assertJS to waitFor's and it continues to fail, same as comment #1. However, I attached a patch to produce better output. The error will contain

"Underlined title should match the entered title - got communit, expected community"
Assignee: nobody → aaron.train
Status: NEW → ASSIGNED
Attachment #503159 - Flags: review?(hskupin)
Attachment #503159 - Flags: review?(hskupin)
Attachment #503159 - Attachment is obsolete: true
Need to swap the expected/gots
Attachment #503162 - Flags: review?(hskupin)
Comment on attachment 503162 [details] [diff] [review]
Patch v1.1 - (default) [error messages]

>+  // Wait for the location bar to contain the entire test string
>+  controller.waitFor(function () {
>+    return locationBar.value === testString;
>+  }, "Location bar should contain the entire test string - got " +
>+    locationBar.value + ", expected " + testString);

I like that and yes, it should be the reason why we are failing here and in probably other tests. Sounds like that Dave was right and that it could be a bug on Linux too. Also please reword the message to "Location bar contains entered string".

>+  // Check the autocomplete list is open
>+  controller.waitFor(function () {
>+    return locationBar.autoCompleteResults.isOpened === true;

You can remove the '=== true' part. isOpened already returns a boolean value.

>+  }, "Autocomplete results list should be open - got " +
>+    locationBar.autoCompleteResults.isOpened + ", expected " + true);

"Autocomplete popup has been opened"

>-  controller.assertJS("subject.underliedTextCount == 1", {
>-    underliedTextCount: titleEntries.length
>-  });
>+  controller.waitFor(function () {
>+    return titleEntries.length === 1;
>+  }, "There should only be 1 underlined entry - got " + titleEntries.length +
>+    ", expected " + 1);

The underlined text should be already set when the popup gets opened. So we should not switch to waitFor here. It would make our test to miss possible regressions. Also can we try to completely remove the "should" from our messages? The positive message has to explicitly tell us what the target state is, i.e. "Only one underlined entry visible" 

>   // Check that the underlined title matches the entered title
>   for each (var entry in titleEntries) {
>-    controller.assertJS("subject.enteredTitle == subject.underlinedTitle", {
>-      enteredTitle: testString, 
>-      underlinedTitle: entry.toLowerCase()
>-    });
>+    controller.waitFor(function () {
>+      return testString === entry.toLowerCase();
>+    }, "Underlined title should match the entered title - got " + 
>+      entry.toLowerCase() + ", expected " + testString);

Same as above.

Please also apply it to the tests for the underlines URLs. Would be great if we could get this in before the todays testrun.
Attachment #503162 - Flags: review?(hskupin) → review-
Attachment #503162 - Attachment is obsolete: true
Attachment #503478 - Flags: review?(hskupin)
Comment on attachment 503478 [details] [diff] [review]
Patch v2 - (default) [error messages]

>-  controller.assertJS("subject.underliedTextCount == 1", {
>-    underliedTextCount: titleEntries.length
>+  controller.assertJS("subject.underlinedTextCount == 1", {
>+    underlinedTextCount: titleEntries.length

Why have you reverted the call to assertJS? We should never use this method again. Simply change the waitFor calls from your last patch to assert.
Attachment #503478 - Flags: review?(hskupin) → review-
> Why have you reverted the call to assertJS? We should never use this method
> again. Simply change the waitFor calls from your last patch to assert.

See your comment in comment #6

"The underlined text should be already set when the popup gets opened. So we
should not switch to waitFor here"
I haven't said you should use assertJS. So please convert the assertJS instances to assert. Otherwise we do not get the wanted information.
AssertJS calls are now assert with callbacks and messages.
Attachment #503478 - Attachment is obsolete: true
Attachment #503490 - Flags: review?(hskupin)
Comment on attachment 503490 [details] [diff] [review]
Patch v3 - (default) [error messages]

>+    controller.assert(function () {
>+      return testString === entry.toLowerCase();
>+    }, "Underlined title matches the entered title - got " + entry.toLowerCase() +
>+      ", expected " + testString);

Flip the operands for the comparison inside the callback so the order matches the one in the message. Right now it's confusing.

>+    controller.assert(function () { 
>+      return testString === entry.toLowerCase();
>+    }, "Underlined URL matches entered URL - got " + entry.toLowerCase() + 
>+    ", expected " + testString);

Same here.

With both changes it will get my r+. Please attach the updated version of the patch to this bug as reference before checking it in.
Attachment #503490 - Flags: review?(hskupin) → review+
Landed on default - 
http://hg.mozilla.org/qa/mozmill-tests/rev/26ade9664231

Now let's check for error messages
Attachment #503500 - Flags: review+
Attachment #503500 - Attachment description: Patch v3.1 - (default) [error messages] → Patch v3.1 - (default) [error messages] [checked-in]
http://mozmill-release.brasstacks.mozilla.com/#/general/report/a57c8e0b757874f4760206c74b1640b2

Information:
'Underlined title matches the entered title - got communit, expected community'
One little nit I have for this error message. If we are expecting the value to be a string, we should surround it with single quotes:

"Underlined title matches the entered title - got '" + x + "', expected '" + y + '"
This test failure is still a occurring and is still a mystery in investigation. The checks are in place to wait for the entirety of the typed string but for some reason the last character is ignored. The underlined entries omit the last character. 

Recent reports from the 21st of February 

http://mozmill-release.brasstacks.mozilla.com/#/general/failure?branch=4.0&from=2011-02-01&to=2011-02-23&test=firefox%2FtestAwesomeBar%2FtestCheckItemHighlight.js&func=testCheckItemHighlight

I'm going to try additional waits and see what happens
I tend to say we should wait until the whole string is visible in the location bar. Sounds like that we are too fast here.
Any progress here, Aaron? If not, we should probably take it off your plate so someone else can focus on it.
By the way, the new failure messages seem to support the "too fast" theory:
http://mozmill-release.brasstacks.mozilla.com/#/functional/failure?branch=All&platform=All&from=2011-06-01&to=2011-06-03&test=%2FtestAwesomeBar%2FtestCheckItemHighlight.js&func=testCheckItemHighlight

2011-06-03 got commu, expected community
2011-06-02 got commun, expected community

We might just have to increase the timeout.
When I was investigating this, I couldn't nail down the race that's going on. Agreed with comment #19.
Assignee: aaron.train → nobody
Status: ASSIGNED → NEW
Assignee: nobody → anthony.s.hughes
Status: NEW → ASSIGNED
This patch does some refactoring. I've tested this locally and can't reproduce the error. However, based on the rarity of this failure on brasstacks (once every few days), we may have to blindly check in a potential fix and wait to see what happens.
Attachment #503490 - Attachment is obsolete: true
Attachment #537252 - Flags: review?(aaron.train)
Comment on attachment 537252 [details] [diff] [review]
Patch v4.0 [checked-in]

Thanks for the cleanup, overall looks good, r+

>   // Wait for 4 seconds to work around Firefox LAZY ADD of items to the DB
>-  controller.sleep(4000);
>+  controller.sleep(PLACES_DB_TIMEOUT);

I'm curious if this is still a requirement with recent Firefox builds (4.0+)

>-  for each (var letter in testString) {
>-    locationBar.type(letter);
>-    controller.sleep(100);
>-  }

I take it 'type' in it's implementation already handles a sleep between characters (haven't looked), that's why you removed it?
Attachment #537252 - Flags: review?(aaron.train) → review+
(In reply to comment #23)
> Comment on attachment 537252 [details] [diff] [review] [review]
> Patch v4.0
> 
> >-  controller.sleep(4000);
> >+  controller.sleep(PLACES_DB_TIMEOUT);
> 
> I'm curious if this is still a requirement with recent Firefox builds (4.0+)

I suspect it's still needed since this patch will need check-in across all branches (it continues to fail on 3.6 and onward).

> >-  for each (var letter in testString) {
> >-    locationBar.type(letter);
> >-    controller.sleep(100);
> >-  }
> 
> I take it 'type' in it's implementation already handles a sleep between
> characters (haven't looked), that's why you removed it?

Not exactly. I tested this without this for loop and sleep() and it works fine. This code does not appear to be necessary, at least locally.
Given comment 24, do you stand behind your r+ ?
(In reply to comment #25)
> Given comment 24, do you stand behind your r+ ?

Yes.
Comment on attachment 537252 [details] [diff] [review]
Patch v4.0 [checked-in]

Over to Geo for pre-commit review.
Attachment #537252 - Flags: review?(gmealer)
Comment on attachment 537252 [details] [diff] [review]
Patch v4.0 [checked-in]

Looks fine. r+

If you're willing to land, that'd be awesome. Otherwise let me know and I'll land.
Attachment #537252 - Flags: review?(gmealer) → review+
Thanks Geo. I'll check this in after lunch and we'll see what kind of information we get from this week's test runs.
Comment on attachment 537252 [details] [diff] [review]
Patch v4.0 [checked-in]

Landed:
http://hg.mozilla.org/qa/mozmill-tests/rev/e260c600a7c3 [default]
http://hg.mozilla.org/qa/mozmill-tests/rev/ca37244027b5 [mozilla-aurora]
http://hg.mozilla.org/qa/mozmill-tests/rev/badfe5cc2a5b [mozilla-beta]
http://hg.mozilla.org/qa/mozmill-tests/rev/df082fa6eb6d [mozilla-2.0]

Patch does not apply cleanly to mozilla-1.9.2 and mozilla-1.9.1. Revised patch coming up shortly.
Attachment #537252 - Attachment description: Patch v4.0 → Patch v4.0 [checked-in]
Backport patch for mozilla-1.9.2 and mozilla-1.9.1
Attachment #537687 - Flags: review?(gmealer)
Comment on attachment 537687 [details] [diff] [review]
Patch v4.0b [checked-in]

Looks fine, r+.

Quick style suggestion (though I wouldn't apply it here, now, since we've already checked in and I forgot to call it before). 

When we have a forEach w/ an assert in it like that, i.e. a test function containing a forEach function containing an assert function, moving at least the assert function out into a named helper might make the code clearer.

const LOCAL_TEST_PAGES = ...

function assertElementMatches(element) {
  controller.assert(function () {
    return element.toLowerCase()...
  }
}

function testFoo() {
  ...
  underlined.forEach(function (element) {
    assertElementMatches(element)
  }
}

Deep nesting is complex to read. Deep nesting wrapped in functions is even more so. :/ 

If the assert function needed variables in scope of testFoo, you could declare it inside testFoo instead. Just getting it out of the nested bit would make it clearer.
Attachment #537687 - Flags: review?(gmealer) → review+
(In reply to comment #32)
> If the assert function needed variables in scope of testFoo, you could
> declare it inside testFoo instead. Just getting it out of the nested bit
> would make it clearer.

That's a good point. Let's keep that in mind for future patches.
Comment on attachment 537687 [details] [diff] [review]
Patch v4.0b [checked-in]

Landed:
http://hg.mozilla.org/qa/mozmill-tests/rev/6b59acbf284b [mozilla-1.9.2]
http://hg.mozilla.org/qa/mozmill-tests/rev/638ee4871c35 [mozilla-1.9.1]
Attachment #537687 - Attachment description: Patch v4.0b → Patch v4.0b [checked-in]
Patch landed across all branches. Marking resolved fixed but will keep a close eye on this for the next week or so since this is an orange failure.
Status: ASSIGNED → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
This hasn't failed since the check-in. Marking VERIFIED FIXED.
Status: RESOLVED → VERIFIED
Product: Mozilla QA → Mozilla QA Graveyard
You need to log in before you can comment on or make changes to this bug.