Open Bug 1422928 Opened 2 years ago Updated Last year

Intermittent browser/base/content/test/alerts/browser_notification_replace.js | Test timed out -

Categories

(Toolkit :: Notifications and Alerts, defect, P1)

defect

Tracking

()

REOPENED
mozilla59
Tracking Status
firefox58 --- fixed
firefox59 --- fixed

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, leave-open, Whiteboard: [stockwell disabled])

Filed by: apavel [at] mozilla.com

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

https://queue.taskcluster.net/v1/task/XHlKn2l7RL-SZ-UVNTAJLw/runs/0/artifacts/public/logs/live_backing.log

15:05:50     INFO -  86 INFO TEST-START | browser/base/content/test/alerts/browser_notification_replace.js
15:05:50     INFO -  GECKO(5580) | ++DOMWINDOW == 6 (0B847C00) [pid = 5072] [serial = 6] [outer = 05D8B4C0]
15:05:50     INFO -  GECKO(5580) | ++DOMWINDOW == 5 (08D25000) [pid = 5148] [serial = 5] [outer = 061904C0]
15:05:50     INFO -  GECKO(5580) | ++DOMWINDOW == 7 (0BAE7400) [pid = 5072] [serial = 7] [outer = 05D8B4C0]
15:05:50     INFO -  GECKO(5580) | [Child 5072, Main Thread] WARNING: attempt to modify an immutable nsStandardURL: file z:/build/build/src/netwerk/base/nsStandardURL.cpp, line 1698
15:05:50     INFO -  GECKO(5580) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\genericworker\appdata\local\temp\tmpjp5xau.mozrunner\runtests_leaks_tab_pid4284.log
15:05:50     INFO -  GECKO(5580) | [Child 4284, Main Thread] WARNING: No CID found when attempting to map contract ID: file z:/build/build/src/xpcom/components/nsComponentManager.cpp, line 508
15:05:51     INFO -  GECKO(5580) | ++DOCSHELL 05975400 == 1 [pid = 4284] [id = {8ac7dba8-fe87-4628-be66-38a3881f7bfa}]
15:05:51     INFO -  GECKO(5580) | [Child 4284, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/widget/windows/nsLookAndFeel.cpp, line 846
15:05:51     INFO -  GECKO(5580) | ++DOMWINDOW == 1 (058823A0) [pid = 4284] [serial = 1] [outer = 00000000]
15:05:51     INFO -  GECKO(5580) | ++DOMWINDOW == 2 (0AF91400) [pid = 4284] [serial = 2] [outer = 058823A0]
15:05:51     INFO -  GECKO(5580) | [Child 4284, Main Thread] WARNING: site security information will not be persisted: file z:/build/build/src/security/manager/ssl/nsSiteSecurityService.cpp, line 553
15:05:51     INFO -  GECKO(5580) | [Child 4284, Main Thread] WARNING: 'NS_FAILED(GetAccentColor(unused))', file z:/build/build/src/widget/windows/nsLookAndFeel.cpp, line 472
15:05:51     INFO -  GECKO(5580) | [Parent 5580, Main Thread] WARNING: Could not get disk status from nsIDiskSpaceWatcher: file z:/build/build/src/uriloader/prefetch/nsOfflineCacheUpdateService.cpp, line 286
15:05:51     INFO -  GECKO(5580) | [Parent 5580, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file z:/build/build/src/netwerk/base/nsChannelClassifier.cpp, line 344
15:05:51     INFO -  GECKO(5580) | ++DOMWINDOW == 3 (0AF9BC00) [pid = 4284] [serial = 3] [outer = 058823A0]
15:05:51     INFO -  GECKO(5580) | [Parent 5580, Main Thread] WARNING: NS_ENSURE_TRUE(aSecondURI) failed: file z:/build/build/src/dom/base/ThirdPartyUtil.cpp, line 98
15:05:51     INFO -  GECKO(5580) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\genericworker\appdata\local\temp\tmpjp5xau.mozrunner\runtests_leaks_tab_pid2364.log
15:05:51     INFO -  GECKO(5580) | [Child 2364, Main Thread] WARNING: No CID found when attempting to map contract ID: file z:/build/build/src/xpcom/components/nsComponentManager.cpp, line 508
15:05:55     INFO -  GECKO(5580) | --DOCSHELL 0FE31C00 == 5 [pid = 5580] [id = {1021195f-8d73-453a-8e9b-62af2cc23b9f}]
15:05:55     INFO -  GECKO(5580) | --DOCSHELL 13FDA000 == 4 [pid = 5580] [id = {1b17c392-b06c-4622-b53f-528bc5297271}]
15:05:56     INFO -  GECKO(5580) | --DOCSHELL 05E5A800 == 1 [pid = 5072] [id = {ca782fd7-09ed-46fb-9702-a8d16f933d5a}]
15:05:57     INFO -  GECKO(5580) | --DOCSHELL 06151800 == 1 [pid = 5148] [id = {3233ff46-3616-48c6-89bc-07a786ec8ff7}]
15:06:00     INFO -  GECKO(5580) | --DOMWINDOW == 12 (0FE38800) [pid = 5580] [serial = 4] [outer = 00000000] [url = about:blank]
15:06:00     INFO -  GECKO(5580) | --DOMWINDOW == 6 (05E5C000) [pid = 5072] [serial = 2] [outer = 00000000] [url = about:blank]
15:06:00     INFO -  GECKO(5580) | --DOMWINDOW == 5 (0B847C00) [pid = 5072] [serial = 6] [outer = 00000000] [url = about:blank]
15:06:03     INFO -  GECKO(5580) | --DOMWINDOW == 11 (148EB700) [pid = 5580] [serial = 9] [outer = 00000000] [url = about:blank]
15:06:03     INFO -  GECKO(5580) | --DOMWINDOW == 2 (0AF91400) [pid = 4284] [serial = 2] [outer = 00000000] [url = about:blank]
15:06:04     INFO -  GECKO(5580) | --DOMWINDOW == 4 (05D8B3A0) [pid = 5072] [serial = 1] [outer = 00000000] [url = about:blank]
15:06:05     INFO -  GECKO(5580) | --DOMWINDOW == 4 (06153000) [pid = 5148] [serial = 2] [outer = 00000000] [url = about:blank]
15:06:05     INFO -  GECKO(5580) | --DOMWINDOW == 3 (061903A0) [pid = 5148] [serial = 1] [outer = 00000000] [url = chrome://gfxsanity/content/sanitytest.html]
15:06:06     INFO -  GECKO(5580) | [Parent 5580, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/dom/fetch/FetchDriver.cpp, line 418
15:06:07     INFO -  GECKO(5580) | --DOMWINDOW == 10 (13FDB400) [pid = 5580] [serial = 10] [outer = 00000000] [url = about:blank]
15:06:07     INFO -  GECKO(5580) | --DOMWINDOW == 2 (0BD34400) [pid = 5148] [serial = 3] [outer = 00000000] [url = chrome://gfxsanity/content/sanitytest.html]
15:06:08     INFO -  GECKO(5580) | --DOMWINDOW == 3 (0B846400) [pid = 5072] [serial = 4] [outer = 00000000] [url = about:blank]
15:06:08     INFO -  GECKO(5580) | --DOMWINDOW == 2 (05E51C00) [pid = 5072] [serial = 3] [outer = 00000000] [url = about:blank]
15:07:20     INFO -  TEST-INFO | started process screenshot
15:07:20     INFO -  TEST-INFO | screenshot: exit 0
15:07:20     INFO -  Buffered messages logged at 15:05:50
15:07:20     INFO -  87 INFO Entering test bound test_notificationReplace
15:07:20     INFO -  88 INFO Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/FileUtils.jsm" line: 174}]
15:07:20     INFO -  Buffered messages logged at 15:05:51
15:07:20     INFO -  89 INFO Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/FileUtils.jsm" line: 174}]
15:07:20     INFO -  Buffered messages finished
15:07:20    ERROR -  90 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/alerts/browser_notification_replace.js | Test timed out -
15:07:20     INFO -  GECKO(5580) | MEMORY STAT | vsize 718MB | vsizeMaxContiguous 446MB | residentFast 196MB | heapAllocated 74MB
15:07:20     INFO -  91 INFO TEST-OK | browser/base/content/test/alerts/browser_notification_replace.js | took 90072ms
15:07:20     INFO -  Not taking screenshot here: see the one that was previously logged
15:07:20    ERROR -  92 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/alerts/browser_notification_replace.js | Found a tab after previous test timed out: http://example.org/browser/browser/base/content/test/alerts/file_dom_notifications.html -
15:07:20     INFO -  GECKO(5580) | ++DOCSHELL 0625CC00 == 1 [pid = 2364] [id = {938e06e2-afec-42bb-9bda-b8aa940010fb}]
15:07:20     INFO -  GECKO(5580) | [Child 2364, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/widget/windows/nsLookAndFeel.cpp, line 846
15:07:20     INFO -  GECKO(5580) | ++DOMWINDOW == 1 (0618C3A0) [pid = 2364] [serial = 1] [outer = 00000000]
15:07:20     INFO -  93 INFO checking window state
15:07:20     INFO -  94 INFO TEST-START | browser/base/content/test/alerts/browser_notification_tab_switching.js
15:07:20     INFO -  GECKO(5580) | ++DOCSHELL 0614DC00 == 2 [pid = 5148] [id = {7c33c70d-46a5-468c-9d73-47b7f40a583e}]
15:07:20     INFO -  GECKO(5580) | ++DOMWINDOW == 3 (061903A0) [pid = 5148] [serial = 6] [outer = 00000000]
15:07:20     INFO -  GECKO(5580) | ++DOMWINDOW == 2 (0BDA9800) [pid = 2364] [serial = 2] [outer = 0618C3A0]
15:07:20     INFO -  GECKO(5580) | ++DOMWINDOW == 4 (06151800) [pid = 5148] [serial = 7] [outer = 061903A0]
15:07:21     INFO -  GECKO(5580) | [Child 5148, Main Thread] WARNING: site security information will not be persisted: file z:/build/build/src/security/manager/ssl/nsSiteSecurityService.cpp, line 553
15:07:21     INFO -  GECKO(5580) | [Parent 5580, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file z:/build/build/src/netwerk/base/nsChannelClassifier.cpp, line 344
15:07:21     INFO -  GECKO(5580) | [Child 2364, Main Thread] WARNING: 'NS_FAILED(GetAccentColor(unused))', file z:/build/build/src/widget/windows/nsLookAndFeel.cpp, line 472
15:07:21     INFO -  GECKO(5580) | ++DOMWINDOW == 5 (08D24C00) [pid = 5148] [serial = 8] [outer = 061903A0]
15:07:28     INFO -  GECKO(5580) | --DOCSHELL 05975400 == 0 [pid = 4284] [id = {8ac7dba8-fe87-4628-be66-38a3881f7bfa}]
15:07:28     INFO -  GECKO(5580) | --DOCSHELL 08D22400 == 1 [pid = 5148] [id = {eebda9c9-3e05-4ced-831c-364afe8d2673}]
15:07:29     INFO -  GECKO(5580) | --DOMWINDOW == 4 (061904C0) [pid = 5148] [serial = 4] [outer = 00000000] [url = about:blank]
15:07:29     INFO -  GECKO(5580) | --DOMWINDOW == 1 (058823A0) [pid = 4284] [serial = 1] [outer = 00000000] [url = http://example.org/browser/browser/base/content/test/alerts/file_dom_notifications.html]
15:07:33     INFO -  GECKO(5580) | --DOMWINDOW == 3 (06151800) [pid = 5148] [serial = 7] [outer = 00000000] [url = about:blank]
15:07:33     INFO -  GECKO(5580) | --DOMWINDOW == 2 (08D25000) [pid = 5148] [serial = 5] [outer = 00000000] [url = about:blank]
15:07:33     INFO -  GECKO(5580) | --DOMWINDOW == 0 (0AF9BC00) [pid = 4284] [serial = 3] [outer = 00000000] [url = http://example.org/browser/browser/base/content/test/alerts/file_dom_notifications.html]
15:07:49     INFO -  GECKO(5580) | [Parent 5580, Lazy Idle] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/widget/windows/WinUtils.cpp, line 1483
15:08:50     INFO -  Not taking screenshot here: see the one that was previously logged
15:08:50     INFO -  Buffered messages logged at 15:07:20
15:08:50     INFO -  95 INFO Entering test bound test_notificationPreventDefaultAndSwitchTabs
15:08:50     INFO -  Buffered messages logged at 15:07:21
15:08:50     INFO -  96 INFO Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/FileUtils.jsm" line: 174}]
15:08:50     INFO -  97 INFO TEST-PASS | browser/base/content/test/alerts/browser_notification_tab_switching.js | Notification page loaded as a background tab -
15:08:50     INFO -  98 INFO openNotification: showNotification1
15:08:50     INFO -  Buffered messages finished
15:08:50    ERROR -  99 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/alerts/browser_notification_tab_switching.js | Test timed out -
15:08:50     INFO -  GECKO(5580) | MEMORY STAT | vsize 756MB | vsizeMaxContiguous 446MB | residentFast 198MB | heapAllocated 76MB
15:08:50     INFO -  100 INFO TEST-OK | browser/base/content/test/alerts/browser_notification_tab_switching.js | took 90061ms
15:08:50     INFO -  Not taking screenshot here: see the one that was previously logged
15:08:50    ERROR -  101 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/alerts/browser_notification_tab_switching.js | Found a tab after previous test timed out: http://example.org/browser/browser/base/content/test/alerts/file_dom_notifications.html -
15:08:50     INFO -  GECKO(5580) | ++DOCSHELL 0596D400 == 1 [pid = 4284] [id = {a5807097-25ac-4b7b-9c34-93f33aff026c}]
15:08:50     INFO -  GECKO(5580) | ++DOMWINDOW == 1 (058823A0) [pid = 4284] [serial = 4] [outer = 00000000]
15:08:50     INFO -  102 INFO checking window state
15:08:50     INFO -  GECKO(5580) | ++DOMWINDOW == 2 (0AF91000) [pid = 4284] [serial = 5] [outer = 058823A0]
15:08:51     INFO -  GECKO(5580) | ++DOMWINDOW == 11 (0F384000) [pid = 5580] [serial = 14] [outer = 0E624940]
15:08:51     INFO -  GECKO(5580) | ++DOMWINDOW == 12 (0F386400) [pid = 5580] [serial = 15] [outer = 0E624940]
15:08:51     INFO -  GECKO(5580) | --DOCSHELL 0625CC00 == 0 [pid = 2364] [id = {938e06e2-afec-42bb-9bda-b8aa940010fb}]
15:08:51     INFO -  GECKO(5580) | --DOCSHELL 0614DC00 == 0 [pid = 5148] [id = {7c33c70d-46a5-468c-9d73-47b7f40a583e}]
15:08:51     INFO -  GECKO(5580) | --DOMWINDOW == 1 (0618C3A0) [pid = 2364] [serial = 1] [outer = 00000000] [url = about:blank]
15:08:51     INFO -  GECKO(5580) | --DOMWINDOW == 0 (0BDA9800) [pid = 2364] [serial = 2] [outer = 00000000] [url = about:blank]
15:08:51     INFO -  GECKO(5580) | --DOMWINDOW == 1 (061903A0) [pid = 5148] [serial = 6] [outer = 00000000] [url = http://example.org/browser/browser/base/content/test/alerts/file_dom_notifications.html]
15:08:51     INFO -  GECKO(5580) | --DOMWINDOW == 0 (08D24C00) [pid = 5148] [serial = 8] [outer = 00000000] [url = http://example.org/browser/browser/base/content/test/alerts/file_dom_notifications.html]
15:08:51     INFO -  GECKO(5580) | --DOCSHELL 0B843000 == 0 [pid = 5072] [id = {f20ada12-e5d2-48c9-a78c-5d3a8f308d2c}]
15:08:51     INFO -  GECKO(5580) | --DOMWINDOW == 1 (05D8B4C0) [pid = 5072] [serial = 5] [outer = 00000000] [url = about:newtab]
15:08:51     INFO -  GECKO(5580) | --DOMWINDOW == 0 (0BAE7400) [pid = 5072] [serial = 7] [outer = 00000000] [url = about:newtab]
15:08:52     INFO -  GECKO(5580) | --DOMWINDOW == 11 (14993000) [pid = 5580] [serial = 11] [outer = 00000000] [url = about:blank]
15:08:52     INFO -  GECKO(5580) | --DOMWINDOW == 10 (0F384000) [pid = 5580] [serial = 14] [outer = 00000000] [url = about:blank]
15:08:53     INFO -  GECKO(5580) | Completed ShutdownLeaks collections in process 2364
15:08:53     INFO -  GECKO(5580) | Completed ShutdownLeaks collections in process 5148
15:08:53     INFO -  GECKO(5580) | Completed ShutdownLeaks collections in process 4284
15:08:53     INFO -  GECKO(5580) | Completed ShutdownLeaks collections in process 5072
15:08:55     INFO -  GECKO(5580) | Completed ShutdownLeaks collections in process 5580
15:08:55     INFO -  103 INFO TEST-START | Shutdown
15:08:55     INFO -  104 INFO Browser Chrome Test Summary
15:08:55     INFO -  105 INFO Passed:  1
15:08:55  WARNING -  106 INFO Failed:  4
15:08:55  WARNING -  One or more unittests failed.
15:08:55     INFO -  107 INFO Todo:    0
15:08:55     INFO -  108 INFO Mode:    e10s
15:08:55     INFO -  109 INFO *** End BrowserChrome Test Results ***
In the last 4 days, there have been 53 failures.

Most of the failures are on Win 10 x64, but a few of them on Windows 7.
Affected build types: debug, opt, pgo.

An example of a recent log file:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=150449896&lineNumber=1938 

And the relevant part of the log:

10:50:29     INFO -  17 INFO TEST-START | browser/base/content/test/alerts/browser_notification_replace.js
10:50:46     INFO -  GECKO(7716) | [DEBUG SHUTDOWN] Shutdown: decoder=000001EB091A9C00 state machine=000001EB08FE1000
10:50:46     INFO -  GECKO(7716) | [DEBUG SHUTDOWN] Enter: state machine=000001EB05CF1610 reader=000001EB08FDED30
10:50:46     INFO -  GECKO(7716) | [DEBUG SHUTDOWN] Shutdown: reader=000001EB05CFA000 shutdown demuxer=000001EB05CF1260
10:50:46     INFO -  GECKO(7716) | [DEBUG SHUTDOWN] Shutdown: pool=000001EB005D87C0 count=1
10:50:46     INFO -  GECKO(7716) | [DEBUG SHUTDOWN] operator (): pool=000001EB005D87C0 shutdown=true count=0
10:50:46     INFO -  GECKO(7716) | [DEBUG SHUTDOWN] TearDownDecoders: reader=000001EB05CFA000 shut down audio task queue
10:50:46     INFO -  GECKO(7716) | [DEBUG SHUTDOWN] TearDownDecoders: reader=000001EB05CFA000 shut down video task queue
10:50:46     INFO -  GECKO(7716) | [DEBUG SHUTDOWN] FinishShutdown: state machine=000001EB08FE1000
10:50:46     INFO -  GECKO(7716) | [DEBUG SHUTDOWN] Unregister: decoder=000001EB091A9C00, count=0
10:51:14     INFO -  TEST-INFO | started process screenshot
10:51:14     INFO -  TEST-INFO | screenshot: exit 0
10:51:14     INFO -  Buffered messages logged at 10:50:29
10:51:14     INFO -  18 INFO Entering test bound test_notificationReplace
10:51:14     INFO -  19 INFO Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/FileUtils.jsm" line: 174}]
10:51:14     INFO -  Buffered messages logged at 10:50:30
10:51:14     INFO -  20 INFO Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/FileUtils.jsm" line: 174}]
10:51:14     INFO -  Buffered messages finished
10:51:14    ERROR -  21 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/alerts/browser_notification_replace.js | Test timed out -
10:51:14     INFO -  GECKO(7716) | MEMORY STAT | vsize 1760MB | vsizeMaxContiguous 132464115MB | residentFast 223MB | heapAllocated 81MB
10:51:14     INFO -  22 INFO TEST-OK | browser/base/content/test/alerts/browser_notification_replace.js | took 45032ms
10:51:14     INFO -  Not taking screenshot here: see the one that was previously logged
10:51:14    ERROR -  23 INFO TEST-UNEXPECTED-FAIL | browser/base/content/test/alerts/browser_notification_replace.js | Found a tab after previous test timed out: http://example.org/browser/browser/base/content/test/alerts/file_dom_notifications.html -
10:51:14     INFO -  24 INFO checking window state 

:MattN As you are the triage owner of this component, could you please take a look at this?
Thank you!
Flags: needinfo?(MattN+bmo)
Whiteboard: [stockwell needswork]
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/b0f53f576dad
Disable browser/base/content/test/alerts/browser_notification_replace.js on windows for frequent failures. r=me, a=testonly
:mattn, please remember this is disabled when working on a fix for this.  As a note, there is only 1 test remaining on windows in the alerts/ directory, I suspect that will be disabled soon as well
https://hg.mozilla.org/mozilla-central/rev/b0f53f576dad
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla59
I've informed my manager that all of the alert service b-c tests have been disabled due to intermittent failures but there are currently higher priorities projects.
Status: RESOLVED → REOPENED
Flags: needinfo?(MattN+bmo)
Keywords: leave-open
Priority: P5 → P1
Resolution: FIXED → ---
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Moving to p3 because no activity for at least 24 weeks.
Priority: P1 → P3
You need to log in before you can comment on or make changes to this bug.