Closed Bug 1607907 Opened 6 years ago Closed 6 years ago

Intermittent [tier2] linux1804 TEST-UNEXPECTED-TIMEOUT | toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | Test timed out

Categories

(WebExtensions :: General, defect, P5)

Product:
WebExtensions
Component:
General
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=284063794&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/NCnYIdX1Rn6UuCw-XKjC2A/runs/0/artifacts/public/logs/live_backing.log

[task 2020-01-08T19:57:10.251Z] 19:57:10 INFO - TEST-START | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js
[task 2020-01-08T20:02:10.250Z] 20:02:10 WARNING - TEST-UNEXPECTED-TIMEOUT | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | Test timed out
[task 2020-01-08T20:02:10.250Z] 20:02:10 INFO - TEST-INFO took 300001ms
[task 2020-01-08T20:02:10.250Z] 20:02:10 INFO - >>>>>>>
[task 2020-01-08T20:02:10.251Z] 20:02:10 INFO - PID 28456 | [CodeCoverage] Setting handlers for process 28456.
[task 2020-01-08T20:02:10.251Z] 20:02:10 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2020-01-08T20:02:10.251Z] 20:02:10 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2020-01-08T20:02:10.251Z] 20:02:10 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2020-01-08T20:02:10.252Z] 20:02:10 INFO - running event loop
[task 2020-01-08T20:02:10.252Z] 20:02:10 INFO - xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | Starting check_remote
[task 2020-01-08T20:02:10.252Z] 20:02:10 INFO - (xpcshell/head.js) | test check_remote pending (2)
[task 2020-01-08T20:02:10.253Z] 20:02:10 INFO - TEST-PASS | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | check_remote - [check_remote : 1] useRemoteWebExtensions matches - true == true
[task 2020-01-08T20:02:10.254Z] 20:02:10 INFO - TEST-PASS | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | check_remote - [check_remote : 1] testing from extension process - false == false
[task 2020-01-08T20:02:10.257Z] 20:02:10 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2020-01-08T20:02:10.258Z] 20:02:10 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2020-01-08T20:02:10.258Z] 20:02:10 INFO - (xpcshell/head.js) | test check_remote finished (2)
[task 2020-01-08T20:02:10.258Z] 20:02:10 INFO - xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | Starting test_speculative_connect
[task 2020-01-08T20:02:10.259Z] 20:02:10 INFO - (xpcshell/head.js) | test test_speculative_connect pending (2)
[task 2020-01-08T20:02:10.260Z] 20:02:10 INFO - "Extension attached"
[task 2020-01-08T20:02:10.260Z] 20:02:10 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2020-01-08T20:02:10.260Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/dom/plugins/ipc/PluginInstanceChild.gcda:Merge mismatch for function 44
[task 2020-01-08T20:02:10.261Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/dom/media/Unified_cpp_dom_media6.gcda:Merge mismatch for function 3000
[task 2020-01-08T20:02:10.261Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/dom/plugins/ipc/PluginInstanceChild.gcda:Merge mismatch for function 44
[task 2020-01-08T20:02:10.261Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/dom/media/Unified_cpp_dom_media6.gcda:Merge mismatch for function 3000
[task 2020-01-08T20:02:10.261Z] 20:02:10 INFO - PID 28456 | [CodeCoverage] Setting handlers for process 28491.
[task 2020-01-08T20:02:10.262Z] 20:02:10 INFO - "onRequest {"requestId":"2","url":"http://localhost:38841/","method":"GET","type":"speculative","fromCache":false,"incognito":false,"thirdParty":true,"frameId":0,"parentFrameId":-1,"timeStamp":1578513433441,"tabId":-1}"
[task 2020-01-08T20:02:10.262Z] 20:02:10 INFO - TEST-PASS | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | test_speculative_connect - [test_speculative_connect : 405] Should have seen a speculative proxy request. - Expected: speculative, Actual: speculative - true == true
[task 2020-01-08T20:02:10.262Z] 20:02:10 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "[Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIControllers.removeController]" nsresult: "0x80004005 (NS_ERROR_FAILURE)" location: "JS frame :: chrome://global/content/elements/browser-custom-element.js :: destroy :: line 1374" data: no]"]
[task 2020-01-08T20:02:10.263Z] 20:02:10 INFO - destroy@chrome://global/content/elements/browser-custom-element.js:1374:28
[task 2020-01-08T20:02:10.263Z] 20:02:10 INFO - disconnectedCallback@chrome://global/content/elements/browser-custom-element.js:408:12
[task 2020-01-08T20:02:10.263Z] 20:02:10 INFO - _releaseBrowser@resource://gre/modules/ExtensionParent.jsm:1427:18
[task 2020-01-08T20:02:10.263Z] 20:02:10 INFO - shutdown@resource://gre/modules/ExtensionParent.jsm:1422:12
[task 2020-01-08T20:02:10.263Z] 20:02:10 INFO - shutdown@chrome://extensions/content/parent/ext-backgroundPage.js:99:11
[task 2020-01-08T20:02:10.263Z] 20:02:10 INFO - onShutdown@chrome://extensions/content/parent/ext-backgroundPage.js:165:19
[task 2020-01-08T20:02:10.264Z] 20:02:10 INFO - ExtensionAPI/<@resource://gre/modules/ExtensionCommon.jsm:356:14
[task 2020-01-08T20:02:10.264Z] 20:02:10 INFO - wrapper@resource://gre/modules/ExtensionCommon.jsm:300:14
[task 2020-01-08T20:02:10.264Z] 20:02:10 INFO - emit@resource://gre/modules/ExtensionCommon.jsm:327:32
[task 2020-01-08T20:02:10.264Z] 20:02:10 INFO - emit@resource://gre/modules/Extension.jsm:1815:25
[task 2020-01-08T20:02:10.265Z] 20:02:10 INFO - shutdown@resource://gre/modules/Extension.jsm:2462:10
[task 2020-01-08T20:02:10.265Z] 20:02:10 INFO - unload@resource://testing-common/ExtensionXPCShellUtils.jsm:480:28
[task 2020-01-08T20:02:10.265Z] 20:02:10 INFO - test_speculative_connect@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js:51:21
[task 2020-01-08T20:02:10.265Z] 20:02:10 INFO - async*run_next_test/_run_next_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:1567:22
[task 2020-01-08T20:02:10.265Z] 20:02:10 INFO - _run_next_test@/builds/worker/workspace/build/tests/xpcshell/head.js:1567:38
[task 2020-01-08T20:02:10.265Z] 20:02:10 INFO - run@/builds/worker/workspace/build/tests/xpcshell/head.js:735:9
[task 2020-01-08T20:02:10.265Z] 20:02:10 INFO - _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:246:6
[task 2020-01-08T20:02:10.266Z] 20:02:10 INFO - _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:573:5
[task 2020-01-08T20:02:10.266Z] 20:02:10 INFO - @-e:1:1
[task 2020-01-08T20:02:10.266Z] 20:02:10 INFO - "
[task 2020-01-08T20:02:10.267Z] 20:02:10 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2020-01-08T20:02:10.267Z] 20:02:10 INFO - (xpcshell/head.js) | test test_speculative_connect finished (2)
[task 2020-01-08T20:02:10.268Z] 20:02:10 INFO - (xpcshell/head.js) | test run_next_test 2 finished (1)
[task 2020-01-08T20:02:10.268Z] 20:02:10 INFO - exiting test
[task 2020-01-08T20:02:10.268Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/dom/plugins/ipc/PluginInstanceChild.gcda:Merge mismatch for function 44
[task 2020-01-08T20:02:10.269Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/dom/media/Unified_cpp_dom_media6.gcda:Merge mismatch for function 3000
[task 2020-01-08T20:02:10.269Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/gfx/thebes/Unified_cpp_gfx_thebes1.gcda:Merge mismatch for function 479
[task 2020-01-08T20:02:10.269Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/security/nss/lib/ckfw/ckfw_nssckfw/wrap.gcda:Merge mismatch for function 32
[task 2020-01-08T20:02:10.270Z] 20:02:10 INFO - PID 28456 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-08T20:02:10.270Z] 20:02:10 INFO - PID 28456 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-08T20:02:10.270Z] 20:02:10 INFO - PID 28456 | SharedThreadPool in xpcom-shutdown-threads. Waiting for pools "IPC Launch"
[task 2020-01-08T20:02:10.270Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/dom/plugins/ipc/PluginInstanceChild.gcda:Merge mismatch for function 44
[task 2020-01-08T20:02:10.270Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/dom/media/Unified_cpp_dom_media6.gcda:Merge mismatch for function 3000
[task 2020-01-08T20:02:10.270Z] 20:02:10 INFO - PID 28456 | profiling:/tmp/tmpvLRnsJ/gfx/thebes/Unified_cpp_gfx_thebes0.gcda:Merge mismatch for function 9
[task 2020-01-08T20:02:10.270Z] 20:02:10 INFO - <<<<<<<
[task 2020-01-08T20:02:10.271Z] 20:02:10 INFO - xpcshell return code: None
[task 2020-01-08T20:02:10.271Z] 20:02:10 INFO - xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | Process still running after test!
[task 2020-01-08T20:02:10.286Z] 20:02:10 INFO - TEST-START | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_startup.js
[task 2020-01-08T20:07:10.284Z] 20:07:10 WARNING - TEST-UNEXPECTED-TIMEOUT | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_proxy_startup.js | Test timed out
[task 2020-01-08T20:07:10.284Z] 20:07:10 INFO - TEST-INFO took 300000ms

Summary: Intermittent TEST-UNEXPECTED-TIMEOUT | toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | Test timed out → Intermittent [tier2] linux1804 TEST-UNEXPECTED-TIMEOUT | toolkit/components/extensions/test/xpcshell/test_ext_proxy_speculative.js | Test timed out
See Also: → 1607887

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.