Open Bug 1463443 Opened 2 years ago Updated 6 months ago

Intermittent browser/components/places/tests/browser/browser_toolbar_overflow.js | The bookmark node should be visible - "" == "visible" - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js

Categories

(Firefox :: Bookmarks & History, defect, P3)

defect

Tracking

()

Tracking Status
firefox62 --- disabled
firefox63 --- disabled

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, leave-open, Whiteboard: [fxsearch][test disabled on linux32 debug])

Attachments

(1 file)

Filed by: csabou [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=179615970&repo=mozilla-central

https://queue.taskcluster.net/v1/task/Srl7a2wcQYWOVpSdtlMH-A/runs/0/artifacts/public/logs/live_backing.log

[task 2018-05-22T10:49:23.303Z] 10:49:23     INFO - TEST-START | browser/components/places/tests/browser/browser_toolbar_overflow.js
[task 2018-05-22T10:49:24.355Z] 10:49:24     INFO - GECKO(2847) | --DOMWINDOW == 54 (0xc40f9400) [pid = 2847] [serial = 289] [outer = (nil)] [url = about:blank]
[task 2018-05-22T10:49:24.355Z] 10:49:24     INFO - GECKO(2847) | --DOMWINDOW == 53 (0xc892a800) [pid = 2847] [serial = 316] [outer = (nil)] [url = about:blank]
[task 2018-05-22T10:49:24.357Z] 10:49:24     INFO - GECKO(2847) | --DOMWINDOW == 52 (0xc4661e00) [pid = 2847] [serial = 318] [outer = (nil)] [url = about:blank]
[task 2018-05-22T10:49:24.357Z] 10:49:24     INFO - GECKO(2847) | --DOMWINDOW == 51 (0xc465ba00) [pid = 2847] [serial = 216] [outer = (nil)] [url = about:blank]
[task 2018-05-22T10:49:24.358Z] 10:49:24     INFO - GECKO(2847) | --DOMWINDOW == 50 (0xc465de00) [pid = 2847] [serial = 314] [outer = (nil)] [url = about:blank]
[task 2018-05-22T10:49:24.359Z] 10:49:24     INFO - GECKO(2847) | --DOMWINDOW == 49 (0xc465ac00) [pid = 2847] [serial = 295] [outer = (nil)] [url = about:blank]
[task 2018-05-22T10:49:24.360Z] 10:49:24     INFO - GECKO(2847) | --DOMWINDOW == 48 (0xc40f9e00) [pid = 2847] [serial = 304] [outer = (nil)] [url = about:blank]
[task 2018-05-22T10:49:24.361Z] 10:49:24     INFO - GECKO(2847) | --DOMWINDOW == 47 (0xc8929800) [pid = 2847] [serial = 312] [outer = (nil)] [url = about:blank]
[task 2018-05-22T10:49:30.814Z] 10:49:30     INFO - GECKO(2847) | --DOMWINDOW == 46 (0xc44311b0) [pid = 2847] [serial = 321] [outer = (nil)] [url = chrome://browser/content/places/places.xul]
[task 2018-05-22T10:49:30.814Z] 10:49:30     INFO - GECKO(2847) | --DOMWINDOW == 45 (0xc461dc70) [pid = 2847] [serial = 282] [outer = (nil)] [url = chrome://browser/content/places/places.xul]
[task 2018-05-22T10:49:30.816Z] 10:49:30     INFO - GECKO(2847) | --DOMWINDOW == 44 (0xc461c840) [pid = 2847] [serial = 280] [outer = (nil)] [url = chrome://browser/content/places/places.xul]
[task 2018-05-22T10:49:30.817Z] 10:49:30     INFO - GECKO(2847) | --DOMWINDOW == 43 (0xc36a9aa0) [pid = 2847] [serial = 308] [outer = (nil)] [url = about:mozilla]
[task 2018-05-22T10:49:30.818Z] 10:49:30     INFO - GECKO(2847) | --DOMWINDOW == 42 (0xc36a94b0) [pid = 2847] [serial = 297] [outer = (nil)] [url = about:buildconfig]
[task 2018-05-22T10:49:30.819Z] 10:49:30     INFO - GECKO(2847) | --DOMWINDOW == 41 (0xc36a95e0) [pid = 2847] [serial = 301] [outer = (nil)] [url = about:mozilla]
[task 2018-05-22T10:49:30.820Z] 10:49:30     INFO - GECKO(2847) | --DOMWINDOW == 40 (0xc36a9970) [pid = 2847] [serial = 306] [outer = (nil)] [url = about:buildconfig]
[task 2018-05-22T10:49:30.821Z] 10:49:30     INFO - GECKO(2847) | --DOMWINDOW == 39 (0xc36a8670) [pid = 2847] [serial = 291] [outer = (nil)] [url = about:mozilla]
[task 2018-05-22T10:49:30.823Z] 10:49:30     INFO - GECKO(2847) | --DOMWINDOW == 38 (0xc36a82e0) [pid = 2847] [serial = 285] [outer = (nil)] [url = about:buildconfig]
[task 2018-05-22T10:49:30.982Z] 10:49:30     INFO - TEST-INFO | started process screentopng
[task 2018-05-22T10:49:31.689Z] 10:49:31     INFO - TEST-INFO | screentopng: exit 0
[task 2018-05-22T10:49:31.690Z] 10:49:31     INFO - Buffered messages logged at 10:49:23
[task 2018-05-22T10:49:31.690Z] 10:49:31     INFO - Entering test bound setup
[task 2018-05-22T10:49:31.691Z] 10:49:31     INFO - Buffered messages logged at 10:49:27
[task 2018-05-22T10:49:31.694Z] 10:49:31     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | The toolbar is collapsed by default - true == true - 
[task 2018-05-22T10:49:31.694Z] 10:49:31     INFO - Buffered messages logged at 10:49:29
[task 2018-05-22T10:49:31.694Z] 10:49:31     INFO - Leaving test bound setup
[task 2018-05-22T10:49:31.694Z] 10:49:31     INFO - Entering test bound test_overflow
[task 2018-05-22T10:49:31.694Z] 10:49:31     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | The overflow chevron should be visible - true == true - 
[task 2018-05-22T10:49:31.694Z] 10:49:31     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | Not all the nodes should be built by default - true == true - 
[task 2018-05-22T10:49:31.694Z] 10:49:31     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | The number of visible nodes (45) should be smaller than the number of built nodes (126) - true == true - 
[task 2018-05-22T10:49:31.695Z] 10:49:31     INFO - Node at the last visible index
[task 2018-05-22T10:49:31.698Z] 10:49:31     INFO - Buffered messages logged at 10:49:30
[task 2018-05-22T10:49:31.700Z] 10:49:31     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | Sanity check the bookmark index - 44 == 44 - 
[task 2018-05-22T10:49:31.702Z] 10:49:31     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | Found the added bookmark at the expected position - "3H7bJr4YsYaZ" == "3H7bJr4YsYaZ" - 
[task 2018-05-22T10:49:31.703Z] 10:49:31     INFO - Buffered messages finished
[task 2018-05-22T10:49:31.709Z] 10:49:31     INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/browser_toolbar_overflow.js | The bookmark node should be visible - "" == "visible" - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js :: test_index :: line 149
[task 2018-05-22T10:49:31.711Z] 10:49:31     INFO - Stack trace:
[task 2018-05-22T10:49:31.712Z] 10:49:31     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js:test_index:149
[task 2018-05-22T10:49:31.714Z] 10:49:31     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js:test_overflow:55
[task 2018-05-22T10:49:31.718Z] 10:49:31     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1083
[task 2018-05-22T10:49:31.719Z] 10:49:31     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1074
[task 2018-05-22T10:49:31.720Z] 10:49:31     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:976
[task 2018-05-22T10:49:31.721Z] 10:49:31     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
[task 2018-05-22T10:49:31.722Z] 10:49:31     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | Number of built nodes should stay the same - 126 == 126 - 
[task 2018-05-22T10:49:31.723Z] 10:49:31     INFO - Remove the node
[task 2018-05-22T10:49:31.725Z] 10:49:31     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | Found the previous bookmark at the expected position - "http://test.places.44/" == "http://test.places.44/" - 
[task 2018-05-22T10:49:31.726Z] 10:49:31     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-05-22T10:49:31.727Z] 10:49:31     INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/browser_toolbar_overflow.js | The bookmark node should be visible - "hidden" == "visible" - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js :: test_index :: line 166
[task 2018-05-22T10:49:31.728Z] 10:49:31     INFO - Stack trace:
[task 2018-05-22T10:49:31.729Z] 10:49:31     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js:test_index:166
[task 2018-05-22T10:49:31.730Z] 10:49:31     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js:test_overflow:55
[task 2018-05-22T10:49:31.731Z] 10:49:31     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1083
[task 2018-05-22T10:49:31.732Z] 10:49:31     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1074
[task 2018-05-22T10:49:31.733Z] 10:49:31     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:976
[task 2018-05-22T10:49:31.734Z] 10:49:31     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
Over the last 7 days there are 30 failures on this bug. These happen only on linux32.

Here is the most recent log example: https://treeherder.mozilla.org/logviewer.html#?job_id=186822177&repo=autoland&lineNumber=10042

[task 2018-07-06T11:43:46.160Z] 11:43:46     INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/browser_toolbar_overflow.js | The bookmark node should be visible - "" == "visible" - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js :: test_index :: line 149
[task 2018-07-06T11:43:46.161Z] 11:43:46     INFO - Stack trace:
[task 2018-07-06T11:43:46.162Z] 11:43:46     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js:test_index:149
[task 2018-07-06T11:43:46.163Z] 11:43:46     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js:test_overflow:55
[task 2018-07-06T11:43:46.164Z] 11:43:46     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1098
[task 2018-07-06T11:43:46.165Z] 11:43:46     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1089
[task 2018-07-06T11:43:46.166Z] 11:43:46     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:991
[task 2018-07-06T11:43:46.167Z] 11:43:46     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
[task 2018-07-06T11:43:46.168Z] 11:43:46     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | Number of built nodes should stay the same - 126 == 126 - 
[task 2018-07-06T11:43:46.169Z] 11:43:46     INFO - Remove the node
[task 2018-07-06T11:43:46.170Z] 11:43:46     INFO - TEST-PASS | browser/components/places/tests/browser/browser_toolbar_overflow.js | Found the previous bookmark at the expected position - "http://test.places.44/" == "http://test.places.44/" - 
[task 2018-07-06T11:43:46.171Z] 11:43:46     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-07-06T11:43:46.172Z] 11:43:46     INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/browser_toolbar_overflow.js | The bookmark node should be visible - "hidden" == "visible" - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/browser_toolbar_overflow.js :: test_index :: line 166
Flags: needinfo?(mak77)
Priority: P5 → P1
Whiteboard: [fxsearch]
The screenshot looks good afaict. Considered it's linux32 debug, my only suspect is that something is slower than expected, probably the wait for "BookmarksToolbarVisibilityUpdated" happens too early, or we handle the wrong one.

That's likely the place to investigate.
Disabling the test on linux32 debug is also a possibility in the meanwhile.
Flags: needinfo?(mak77)
Keywords: leave-open
Comment on attachment 8992326 [details]
Bug 1463443 - Disable browser_toolbar_overflow.js on debug linux 32bit.

https://reviewboard.mozilla.org/r/257200/#review264146
Attachment #8992326 - Flags: review?(adw) → review+
Pushed by mak77@bonardo.net:
https://hg.mozilla.org/integration/autoland/rev/371ee7ac7773
Disable browser_toolbar_overflow.js on debug linux 32bit. r=adw
Whiteboard: [fxsearch] → [fxsearch][test disabled on linux32 debug]
Priority: P1 → P3
We are trying to build a tool to automatically classify intermittent failures, which would provide a starting point for fixing the bug, reducing the manual work for the developers.
We are collecting some feedback on the results, to see if they’re good enough and where we need to improve.
    
For this bug, the tool says that the intermittent failure is most likely a:
Concurrency Issue: This includes tests in which failures occur due to thread management issues (different threads or their outcomes depending on an implicit ordering), race conditions and/or deadlocks, and issues related to an asynchronous waits (e.g. a process trying to access an external resource or continuing before the external resource is available).


Once you’re done investigating and/or fixing the bug, could you tell me:
- Did the tool correctly recognize the type of intermittent failure?
- Did the information from the tool help your analysis, the bug fixing process, or anything in the process? (please also let us know how the tool was useful and/or what would improve the tool's usefulness for you)
You need to log in before you can comment on or make changes to this bug.