Closed Bug 1523494 Opened 5 years ago Closed 5 years ago

Intermittent devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Service worker target still has an inspect button -

Categories

(DevTools :: about:debugging, defect, P5)

Product:
DevTools
Component:
about:debugging
Type:
defect

Tracking

(firefox68 fixed)

Status:
RESOLVED FIXED
Milestone:
Firefox 68
Tracking Flags:
Tracking Status
firefox68 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: jdescottes)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Attachments

(1 file)

Bug 1523494 - Increase sw timeout in serviceworker_timeout.js mochitest
47 bytes, text/x-phabricator-request
Details | Review

#[markdown(off)]
Filed by: rmaries [at] mozilla.com

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

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

00:58:38 INFO - TEST-START | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js
00:58:38 INFO - GECKO(4804) | [Parent 7008, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
00:58:38 INFO - GECKO(4804) | [Child 7720, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332

00:59:01 INFO - TEST-PASS | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Service worker target has an inspect button -
00:59:01 INFO - Click on inspect and wait for the toolbox to open
00:59:01 INFO - Buffered messages logged at 00:58:51
00:59:01 INFO - Waiting 10 seconds.
00:59:01 INFO - Buffered messages finished
00:59:01 INFO - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Service worker target still has an inspect button -
00:59:01 INFO - Stack trace:
00:59:01 INFO - chrome://mochikit/content/browser-test.js:test_ok:1307
00:59:01 INFO - chrome://mochitests/content/browser/devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js:null:67
00:59:01 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1108
00:59:01 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1099
00:59:01 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:997
00:59:01 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
00:59:01 INFO - Destroy the toolbox
00:59:01 INFO - Not taking screenshot here: see the one that was previously logged
00:59:01 INFO - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Uncaught exception - at resource://devtools/client/framework/attach-thread.js:94 - TypeError: threadClient is undefined
00:59:01 INFO - Stack trace:
00:59:01 INFO - detachThread@resource://devtools/client/framework/attach-thread.js:94:3
00:59:01 INFO - _destroyToolbox@resource://devtools/client/framework/toolbox.js:2919:5
00:59:01 INFO - async*destroy@resource://devtools/client/framework/toolbox.js:2843:23
00:59:01 INFO - @chrome://mochitests/content/browser/devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js:70:9
00:59:01 INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1108:34
00:59:01 INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1099:16
00:59:01 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:997:9
00:59:01 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
00:59:01 INFO - Leaving test bound
00:59:01 INFO - GECKO(4804) | console.warn: "Error while detaching the worker target front: undefined"
00:59:01 INFO - Removing tab.
00:59:01 INFO - Waiting for event: 'TabClose' on [object XULElement].
00:59:01 INFO - Got event: 'TabClose' on [object XULElement].
00:59:01 INFO - Tab removed and finished closing
00:59:01 INFO - GECKO(4804) | [Parent 7008, Main Thread] WARNING: Content used context-fill-opacity when not in a context element: file z:/build/build/src/layout/svg/nsSVGUtils.cpp, line 1497
00:59:01 INFO - Removing tab.
00:59:01 INFO - Waiting for event: 'TabClose' on [object XULElement].
00:59:01 INFO - Got event: 'TabClose' on [object XULElement].
00:59:01 INFO - Tab removed and finished closing

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE

Recent log failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=238168601&repo=autoland&lineNumber=1902

[task 2019-04-04T15:05:21.343Z] 15:05:21 INFO - TEST-START | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js
[task 2019-04-04T15:05:23.470Z] 15:05:23 INFO - GECKO(1075) | Empty service worker registered
[task 2019-04-04T15:05:25.698Z] 15:05:25 INFO - GECKO(1075) | console.error: "Exception while opening the toolbox" "closed" "closed"
[task 2019-04-04T15:05:25.701Z] 15:05:25 INFO - GECKO(1075) | undefined
[task 2019-04-04T15:05:35.700Z] 15:05:35 INFO - TEST-INFO | started process screentopng
[task 2019-04-04T15:05:36.388Z] 15:05:36 INFO - TEST-INFO | screentopng: exit 0
[task 2019-04-04T15:05:36.389Z] 15:05:36 INFO - Buffered messages logged at 15:05:21
[task 2019-04-04T15:05:36.389Z] 15:05:36 INFO - Entering test bound
[task 2019-04-04T15:05:36.389Z] 15:05:36 INFO - Set a low service worker idle timeout
[task 2019-04-04T15:05:36.389Z] 15:05:36 INFO - opening about:debugging
[task 2019-04-04T15:05:36.389Z] 15:05:36 INFO - Adding a new tab with URL: about:debugging
[task 2019-04-04T15:05:36.390Z] 15:05:36 INFO - Buffered messages logged at 15:05:22
[task 2019-04-04T15:05:36.391Z] 15:05:36 INFO - Tab added and finished loading
[task 2019-04-04T15:05:36.391Z] 15:05:36 INFO - Wait until Connect page is displayed
[task 2019-04-04T15:05:36.395Z] 15:05:36 INFO - Select This Firefox page
[task 2019-04-04T15:05:36.395Z] 15:05:36 INFO - Wait for requests to be complete
[task 2019-04-04T15:05:36.398Z] 15:05:36 INFO - Buffered messages logged at 15:05:23
[task 2019-04-04T15:05:36.398Z] 15:05:36 INFO - Wait for runtime page to be rendered
[task 2019-04-04T15:05:36.399Z] 15:05:36 INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/aboutdebugging-new/test/browser/resources/service-workers/empty-sw.html
[task 2019-04-04T15:05:36.400Z] 15:05:36 INFO - Tab added and finished loading
[task 2019-04-04T15:05:36.402Z] 15:05:36 INFO - Wait until the registration appears on the window
[task 2019-04-04T15:05:36.403Z] 15:05:36 INFO - Wait until the service worker stops
[task 2019-04-04T15:05:36.405Z] 15:05:36 INFO - Console message: [JavaScript Warning: "Sending message that cannot be cloned. Are you trying to send an XPCOM object?" {file: "resource://testing-common/content-task.js" line: 62}]
[task 2019-04-04T15:05:36.406Z] 15:05:36 INFO - Buffered messages logged at 15:05:24
[task 2019-04-04T15:05:36.408Z] 15:05:36 INFO - Click on the start button and wait for the service worker to be running
[task 2019-04-04T15:05:36.410Z] 15:05:36 INFO - TEST-PASS | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Service worker target has an inspect button -
[task 2019-04-04T15:05:36.413Z] 15:05:36 INFO - Click on inspect and wait for the toolbox to open
[task 2019-04-04T15:05:36.415Z] 15:05:36 INFO - Buffered messages logged at 15:05:25
[task 2019-04-04T15:05:36.417Z] 15:05:36 INFO - Waiting 10 seconds.
[task 2019-04-04T15:05:36.422Z] 15:05:36 INFO - Buffered messages finished
[task 2019-04-04T15:05:36.424Z] 15:05:36 INFO - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Service worker target still has an inspect button -
[task 2019-04-04T15:05:36.425Z] 15:05:36 INFO - Stack trace:
[task 2019-04-04T15:05:36.427Z] 15:05:36 INFO - chrome://mochikit/content/browser-test.js:test_ok:1314
[task 2019-04-04T15:05:36.434Z] 15:05:36 INFO - chrome://mochitests/content/browser/devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js:null:69
[task 2019-04-04T15:05:36.436Z] 15:05:36 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1116
[task 2019-04-04T15:05:36.438Z] 15:05:36 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1144
[task 2019-04-04T15:05:36.440Z] 15:05:36 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1005
[task 2019-04-04T15:05:36.441Z] 15:05:36 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
[task 2019-04-04T15:05:36.448Z] 15:05:36 INFO - Destroy the toolbox
[task 2019-04-04T15:05:36.450Z] 15:05:36 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-04-04T15:05:36.451Z] 15:05:36 INFO - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Uncaught exception - at resource://devtools/client/framework/attach-thread.js:75 - TypeError: threadClient is undefined
[task 2019-04-04T15:05:36.451Z] 15:05:36 INFO - Stack trace:
[task 2019-04-04T15:05:36.452Z] 15:05:36 INFO - detachThread@resource://devtools/client/framework/attach-thread.js:75:3
[task 2019-04-04T15:05:36.453Z] 15:05:36 INFO - _destroyToolbox@resource://devtools/client/framework/toolbox.js:2994:5
[task 2019-04-04T15:05:36.454Z] 15:05:36 INFO - destroy@resource://devtools/client/framework/toolbox.js:2918:28
[task 2019-04-04T15:05:36.455Z] 15:05:36 INFO - @chrome://mochitests/content/browser/devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js:72:17
[task 2019-04-04T15:05:36.455Z] 15:05:36 INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1116:34
[task 2019-04-04T15:05:36.455Z] 15:05:36 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1144:12
[task 2019-04-04T15:05:36.455Z] 15:05:36 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1005:14

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

There are 28 total failures in the last 7 days on windows and osx: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-04-17&endday=2019-04-24&tree=trunk&bug=1523494

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=242195508&repo=autoland&lineNumber=2363

00:31:53 INFO - TEST-START | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js
00:31:53 INFO - GECKO(1592) | [Parent 2876, Gecko_IOThread] WARNING: pipe error: 109: file z:/task_1556054345/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
00:31:53 INFO - GECKO(1592) | [Child 5240, Chrome_ChildThread] WARNING: pipe error: 109: file z:/task_1556054345/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
00:31:53 INFO - GECKO(1592) | [Child 5240, Chrome_ChildThread] WARNING: pipe error: 109: file z:/task_1556054345/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
00:31:54 INFO - GECKO(1592) | Empty service worker registered
00:31:55 INFO - GECKO(1592) | [Parent 2876, Gecko_IOThread] WARNING: pipe error: 109: file z:/task_1556054345/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
00:31:57 INFO - GECKO(1592) | [Parent 2876, Gecko_IOThread] WARNING: pipe error: 109: file z:/task_1556054345/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
00:31:57 INFO - GECKO(1592) | [Parent 2876, Gecko_IOThread] WARNING: pipe error: 109: file z:/task_1556054345/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
00:31:57 INFO - GECKO(1592) | console.error: "Exception while opening the toolbox" "closed" "closed"
00:31:57 INFO - GECKO(1592) | undefined
00:32:07 INFO - TEST-INFO | started process screenshot
00:32:07 INFO - TEST-INFO | screenshot: exit 0
00:32:07 INFO - Buffered messages logged at 00:31:53
00:32:07 INFO - Entering test bound
00:32:07 INFO - Set a low service worker idle timeout
00:32:07 INFO - opening about:debugging
00:32:07 INFO - Adding a new tab with URL: about:debugging
00:32:07 INFO - Buffered messages logged at 00:31:54
00:32:07 INFO - Tab added and finished loading
00:32:07 INFO - Wait until Connect page is displayed
00:32:07 INFO - Select This Firefox page
00:32:07 INFO - Wait for requests to be complete
00:32:07 INFO - Wait for runtime page to be rendered
00:32:07 INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/aboutdebugging-new/test/browser/resources/service-workers/empty-sw.html
00:32:07 INFO - Tab added and finished loading
00:32:07 INFO - Wait until the registration appears on the window
00:32:07 INFO - Wait until the service worker stops
00:32:07 INFO - Console message: [JavaScript Warning: "Sending message that cannot be cloned. Are you trying to send an XPCOM object?" {file: "resource://testing-common/content-task.js" line: 62}]
00:32:07 INFO - Buffered messages logged at 00:31:55
00:32:07 INFO - Click on the start button and wait for the service worker to be running
00:32:07 INFO - Buffered messages logged at 00:31:56
00:32:07 INFO - TEST-PASS | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Service worker target has an inspect button -
00:32:07 INFO - Click on inspect and wait for the toolbox to open
00:32:07 INFO - Buffered messages logged at 00:31:57
00:32:07 INFO - Waiting 10 seconds.
00:32:07 INFO - Buffered messages finished
00:32:07 INFO - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Service worker target still has an inspect button -
00:32:07 INFO - Stack trace:
00:32:07 INFO - chrome://mochikit/content/browser-test.js:test_ok:1314
00:32:07 INFO - chrome://mochitests/content/browser/devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js:null:69
00:32:07 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1116
00:32:07 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1144
00:32:07 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1005
00:32:07 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
00:32:07 INFO - Destroy the toolbox
00:32:07 INFO - Not taking screenshot here: see the one that was previously logged
00:32:07 INFO - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | Uncaught exception - at resource://devtools/client/framework/attach-thread.js:75 - TypeError: threadClient is undefined
00:32:07 INFO - Stack trace:
00:32:07 INFO - detachThread@resource://devtools/client/framework/attach-thread.js:75:3
00:32:07 INFO - _destroyToolbox@resource://devtools/client/framework/toolbox.js:3038:5
00:32:07 INFO - destroy@resource://devtools/client/framework/toolbox.js:2962:28
00:32:07 INFO - @chrome://mochitests/content/browser/devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js:72:17
00:32:07 INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1116:34
00:32:07 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1144:12
00:32:07 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1005:14
00:32:07 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
00:32:07 INFO - Leaving test bound
00:32:07 INFO - Removing tab.
00:32:07 INFO - Waiting for event: 'TabClose' on [object XULElement].
00:32:07 INFO - Got event: 'TabClose' on [object XULElement].
00:32:07 INFO - Tab removed and finished closing
00:32:07 INFO - Removing tab.
00:32:07 INFO - Waiting for event: 'TabClose' on [object XULElement].
00:32:07 INFO - Got event: 'TabClose' on [object XULElement].
00:32:07 INFO - Tab removed and finished closing
00:32:07 INFO - Removing tab.
00:32:07 INFO - Waiting for event: 'TabClose' on [object XULElement].
00:32:07 INFO - Got event: 'TabClose' on [object XULElement].
00:32:07 INFO - Tab removed and finished closing
00:32:07 INFO - GECKO(1592) | MEMORY STAT | vsize 1304MB | vsizeMaxContiguous 151MB | residentFast 611MB | heapAllocated 231MB
00:32:07 INFO - TEST-OK | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_timeout.js | took 13278ms
00:32:07 INFO - checking window state

Julian, could you please assign this to someone?

Flags: needinfo?(jdescottes)
Whiteboard: [stockwell needswork:owner]

I think I have a fix for this one by adjusting the timeout delay:

Assignee: nobody → jdescottes
Status: REOPENED → ASSIGNED
Flags: needinfo?(jdescottes)

This mochitest had a very short SW timeout of 1 second, sometimes the worker would already be terminated before we could finish to attach a toolbox.
Increase the timeout to 4 seconds.

Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/eae018d5c364
Increase sw timeout in serviceworker_timeout.js mochitest r=daisuke

https://hg.mozilla.org/mozilla-central/rev/eae018d5c364

Status: ASSIGNED → RESOLVED
Closed: 5 years ago → 5 years ago
status-firefox68: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 68
See Also: → 1619456
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: