Closed Bug 1525743 Opened 6 years ago Closed 6 years ago

windows/aarch64 - netwerk/test/browser/browser_child_resource.js | application terminated with exit code 3221226505

Categories

(Testing :: Mochitest, defect, P5)

Product:
Testing
Component:
Mochitest
Type:
defect

Tracking

(firefox67 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla67
Tracking Flags:
Tracking Status
firefox67 --- fixed

People

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

References

Details

Attachments

(1 file)

Bug 1525743 - extend timeout for mochitest on aarch64
(deleted), text/x-phabricator-request
Details

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

https://treeherder.mozilla.org/logviewer.html#?job_id=226341277&repo=try

https://queue.taskcluster.net/v1/task/QBp9fXklQ-2PHf1y75Arkw/runs/0/artifacts/public/logs/live_backing.log

13:53:35 ERROR - TEST-UNEXPECTED-FAIL | netwerk/test/browser/browser_child_resource.js | application terminated with exit code 3221226505

more context from the log:
13:44:22 INFO - TEST-START | browser/base/content/test/performance/browser_appmenu.js
13:45:46 INFO - TEST-INFO | started process screenshot
13:45:46 INFO - TEST-INFO | screenshot: exit 0
13:45:46 INFO - Buffered messages logged at 13:44:22
13:45:46 INFO - Entering test bound
13:45:46 INFO - TEST-PASS | browser/base/content/test/performance/browser_appmenu.js | The panel is closed to begin with. - "closed" == "closed" -
13:45:46 INFO - Buffered messages logged at 13:44:23
13:45:46 INFO - TEST-FAIL | browser/base/content/test/performance/browser_appmenu.js | known reflow at openPopup/this._openPopupPromise<@resource:///modules/PanelMultiView.jsm was encountered 1 times -
13:45:46 INFO - Full stack:
13:45:46 INFO - openPopup/this._openPopupPromise<@resource:///modules/PanelMultiView.jsm:520:9
13:45:46 INFO -
13:45:46 INFO - TEST-FAIL | browser/base/content/test/performance/browser_appmenu.js | known reflow at adjustArrowPosition@chrome://global/content/bindings/popup.xml was encountered 1 times -
13:45:46 INFO - Full stack:
13:45:46 INFO - adjustArrowPosition@chrome://global/content/bindings/popup.xml:290:13
13:45:46 INFO - onxblpopuppositioned@chrome://global/content/bindings/popup.xml:389:9
13:45:46 INFO -
.
.
.
13:45:46 INFO - Click appMenu-help-button
13:45:46 INFO - Buffered messages logged at 13:45:43
13:45:46 INFO - Shown PanelUI-helpView
13:45:46 INFO - Buffered messages logged at 13:45:46
13:45:46 INFO - TEST-PASS | browser/base/content/test/performance/browser_appmenu.js | The panel is open to begin with. - true == true -
13:45:46 INFO - TEST-PASS | browser/base/content/test/performance/browser_appmenu.js | 0 unexpected reflows - true == true -
13:45:46 INFO - comparing 1 frames
13:45:46 INFO - TEST-PASS | browser/base/content/test/performance/browser_appmenu.js | should have 0 unknown flickering areas -
13:45:46 INFO - Leaving test bound
13:45:46 INFO - Buffered messages finished
13:45:46 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/performance/browser_appmenu.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -
13:45:46 INFO - GECKO(6012) | MEMORY STAT | vsize 6662MB | vsizeMaxContiguous 67545246MB | residentFast 1027MB | heapAllocated 892MB
13:45:46 INFO - TEST-OK | browser/base/content/test/performance/browser_appmenu.js | took 83449ms

I am not sure what is wrong here, I assume the reflows are the real problem, but maybe other issues are at stake (OOM?)

:bgrins, I see you edited this test in the recent past, do you have any more insight or could help find someone to help out

Flags: needinfo?(bgrinstead)
Keywords: intermittent-failure, regression
Summary: Intermittent netwerk/test/browser/browser_child_resource.js | application terminated with exit code 3221226505 → windows/aarch64 - netwerk/test/browser/browser_child_resource.js | application terminated with exit code 3221226505

this is another test where the manifest requires crashreporter

Blocks: aarch64-crash-reporting

(In reply to Joel Maher ( :jmaher ) (UTC-4) from comment #1)

more context from the log:
13:44:22 INFO - TEST-START | browser/base/content/test/performance/browser_appmenu.js
13:45:46 INFO - TEST-INFO | started process screenshot
13:45:46 INFO - TEST-INFO | screenshot: exit 0
13:45:46 INFO - Buffered messages logged at 13:44:22
13:45:46 INFO - Entering test bound
13:45:46 INFO - TEST-PASS | browser/base/content/test/performance/browser_appmenu.js | The panel is closed to begin with. - "closed" == "closed" -
13:45:46 INFO - Buffered messages logged at 13:44:23
13:45:46 INFO - TEST-FAIL | browser/base/content/test/performance/browser_appmenu.js | known reflow at openPopup/this._openPopupPromise<@resource:///modules/PanelMultiView.jsm was encountered 1 times -
13:45:46 INFO - Full stack:
13:45:46 INFO - openPopup/this._openPopupPromise<@resource:///modules/PanelMultiView.jsm:520:9
13:45:46 INFO -
13:45:46 INFO - TEST-FAIL | browser/base/content/test/performance/browser_appmenu.js | known reflow at adjustArrowPosition@chrome://global/content/bindings/popup.xml was encountered 1 times -
13:45:46 INFO - Full stack:
13:45:46 INFO - adjustArrowPosition@chrome://global/content/bindings/popup.xml:290:13
13:45:46 INFO - onxblpopuppositioned@chrome://global/content/bindings/popup.xml:389:9
13:45:46 INFO -
.
.
.
13:45:46 INFO - Click appMenu-help-button
13:45:46 INFO - Buffered messages logged at 13:45:43
13:45:46 INFO - Shown PanelUI-helpView
13:45:46 INFO - Buffered messages logged at 13:45:46
13:45:46 INFO - TEST-PASS | browser/base/content/test/performance/browser_appmenu.js | The panel is open to begin with. - true == true -
13:45:46 INFO - TEST-PASS | browser/base/content/test/performance/browser_appmenu.js | 0 unexpected reflows - true == true -
13:45:46 INFO - comparing 1 frames
13:45:46 INFO - TEST-PASS | browser/base/content/test/performance/browser_appmenu.js | should have 0 unknown flickering areas -
13:45:46 INFO - Leaving test bound
13:45:46 INFO - Buffered messages finished
13:45:46 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/performance/browser_appmenu.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -
13:45:46 INFO - GECKO(6012) | MEMORY STAT | vsize 6662MB | vsizeMaxContiguous 67545246MB | residentFast 1027MB | heapAllocated 892MB
13:45:46 INFO - TEST-OK | browser/base/content/test/performance/browser_appmenu.js | took 83449ms

I am not sure what is wrong here, I assume the reflows are the real problem, but maybe other issues are at stake (OOM?)

:bgrins, I see you edited this test in the recent past, do you have any more insight or could help find someone to help out

I don't really know this test, my last change to it was just tweaking a selector for Bug 1470910. I think Florian would know who to ask.

Flags: needinfo?(bgrinstead) → needinfo?(florian)

Mike knows this test. But in the piece of log that has been quoted, the test passed ("TEST-FAIL" in an expected failure, ie todo()) but just took a bit too long to complete.

Flags: needinfo?(florian) → needinfo?(mconley)

Yeah, the test is running too long on this hardware, and we're timing out.

I'll go out on a limb and assume this is not the only test that we're finding runs too long on the arm64 hardware, right? Assuming that's the case, what have we been doing with them? Adding the requestLongerTimeout, or something else?

Flags: needinfo?(mconley) → needinfo?(jmaher)

good point :mconley, tests take roughly 2x longer on this laptop than our racked machines that win10 runs on normally.

:egao, for some of these bugs (this one specifically, maybe test_jsctypes.js as well) could we try extending the timeout inside the test, for this case and other xpcshell, something similar to:
https://searchfox.org/mozilla-central/source/dom/push/test/xpcshell/test_reconnect_retry.js#11 <- timeout in ms

and for mochitest/browser-chrome, something like this:
https://searchfox.org/mozilla-central/source/browser/base/content/test/about/browser_aboutCertError_telemetry.js#6 <- timeout as a multiplier of default

Flags: needinfo?(jmaher) → needinfo?(egao)

(In reply to Joel Maher ( :jmaher ) (UTC-4) from comment #6)

good point :mconley, tests take roughly 2x longer on this laptop than our racked machines that win10 runs on normally.

Isn't there a way to specify a longer default timeout for the whole platform, rather than adjusting individual tests? I think we do that for debug and asan builds.

we do this for browser-chrome tests:
https://searchfox.org/mozilla-central/source/testing/mochitest/runtests.py#1894
if (mozinfo.info["asan"] or mozinfo.info["debug"]) and
options.flavor == 'browser' and options.timeout is None:
self.log.info("Increasing default timeout to 90 seconds")
prefs["testing.browserTestHarness.timeout"] = 90

but not for xpcshell, we often solve timeouts by running fewer tests (more chunks) and setting individual tests to request a longer timeout.

I do think the platform level solution is better for a final solution than hacking dozens of tests. lets first see if a longer timeout solves this, and if it does we can assess the scope, etc.

Job is done, test timing related errors are not observed.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=25ce57f929324285b0861c6eb5a0e81a7218a2d5
https://taskcluster-artifacts.net/EMdjyEPYQXqJa3WtgSxaOw/0/public/logs/live_backing.log

application terminated with exit code 3221226505 is observed in several files, but the issue in the summary is no longer present.

Failures currently present:

22:57:40     INFO - TEST-UNEXPECTED-FAIL | browser/components/contextualidentity/test/browser/browser_eme.js | Uncaught exception - [Exception... "NS_ERROR_FAILURE (0x80004005) - GMPService::operator() failed since GetContentParent rejects the promise with reason NS_ERROR_FAILURE (0x80004005) - GeckoMediaPluginServiceChild::GetContentParent SendLaunchGMPForNodeId failed with description (Process has not loaded.)."  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "<unknown>"  data: no]
22:57:40     INFO - Leaving test bound test
22:57:40     INFO - Console message: MediaKeys::Init() promise rejected 0x80004005 'NS_ERROR_FAILURE (0x80004005) - GMPService::operator() failed since GetContentParent rejects the promise with reason NS_ERROR_FAILURE (0x80004005) - GeckoMediaPluginServiceChild::GetContentParent SendLaunchGMPForNodeId failed with description (Process has not loaded.).'
22:57:40     INFO - GECKO(9664) | MEMORY STAT | vsize 5984MB | vsizeMaxContiguous 67224818MB | residentFast 267MB | heapAllocated 81MB
22:57:40     INFO - TEST-OK | browser/components/contextualidentity/test/browser/browser_eme.js | took 30183ms
22:57:40     INFO - Not taking screenshot here: see the one that was previously logged
22:57:40     INFO - TEST-UNEXPECTED-FAIL | browser/components/contextualidentity/test/browser/browser_eme.js | Found an unexpected tab at the end of test run: http://example.com/browser/browser/components/contextualidentity/test/browser/empty_file.html - 
22:57:40     INFO - checking window state

22:58:12     INFO - TEST-UNEXPECTED-FAIL | browser/components/contextualidentity/test/browser/browser_forgetAPI_EME_forgetThisSite.js | Uncaught exception - [Exception... "NS_ERROR_FAILURE (0x80004005) - GMPService::operator() failed since GetContentParent rejects the promise with reason NS_ERROR_FAILURE (0x80004005) - GeckoMediaPluginServiceChild::GetContentParent SendLaunchGMPForNodeId failed with description (Process has not loaded.)."  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "<unknown>"  data: no]
22:58:12     INFO - Leaving test bound test_EME_forgetThisSite
22:58:12     INFO - Console message: MediaKeys::Init() promise rejected 0x80004005 'NS_ERROR_FAILURE (0x80004005) - GMPService::operator() failed since GetContentParent rejects the promise with reason NS_ERROR_FAILURE (0x80004005) - GeckoMediaPluginServiceChild::GetContentParent SendLaunchGMPForNodeId failed with description (Process has not loaded.).'
22:58:12     INFO - GECKO(9664) | MEMORY STAT | vsize 5984MB | vsizeMaxContiguous 67224818MB | residentFast 268MB | heapAllocated 82MB
22:58:12     INFO - TEST-OK | browser/components/contextualidentity/test/browser/browser_forgetAPI_EME_forgetThisSite.js | took 30173ms
22:58:12     INFO - Not taking screenshot here: see the one that was previously logged
22:58:12     INFO - TEST-UNEXPECTED-FAIL | browser/components/contextualidentity/test/browser/browser_forgetAPI_EME_forgetThisSite.js | Found an unexpected tab at the end of test run: http://example.com/browser/browser/components/contextualidentity/test/browser/empty_file.html - 
22:58:12     INFO - checking window state

23:03:09    ERROR - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_port_disconnect_on_crash.js | application terminated with exit code 3221226505
23:03:09     INFO - runtests.py | Application ran for: 0:04:21.560000
23:03:09     INFO - zombiecheck | Reading PID log: c:\users\testdr~1\appdata\local\temp\tmpadf0abpidlog
23:03:09     INFO - ==> process 4536 launched child process 1196 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.0.784455537\1995042068" -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 2344 gpu)
23:03:09     INFO - ==> process 4536 launched child process 1552 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.6.1798885136\1337282263" -childID 1 -isForBrowser -prefsHandle 2884 -prefMapHandle 2724 -prefsLen 1 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 2916 tab)
23:03:09     INFO - ==> process 4536 launched child process 6712 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.13.1757832718\1863649064" -childID 2 -isForBrowser -prefsHandle 3164 -prefMapHandle 3108 -prefsLen 132 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 2828 tab)
23:03:09     INFO - ==> process 4536 launched child process 9308 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.20.1255734411\1585888145" -childID 3 -isForBrowser -prefsHandle 3128 -prefMapHandle 3132 -prefsLen 132 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 3100 tab)
23:03:09     INFO - ==> process 4536 launched child process 11148 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.27.1100438750\1951701051" -childID 4 -isForBrowser -prefsHandle 3092 -prefMapHandle 4100 -prefsLen 8070 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 4112 tab)
23:03:09     INFO - ==> process 4536 launched child process 2124 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.34.1162565452\2064517484" -childID 5 -isForBrowser -prefsHandle 4388 -prefMapHandle 4392 -prefsLen 8117 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 4468 tab)
23:03:09     INFO - ==> process 4536 launched child process 11256 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.41.638871613\1994596242" -childID 6 -isForBrowser -prefsHandle 4704 -prefMapHandle 4708 -prefsLen 8316 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 4716 tab)
23:03:09     INFO - ==> process 3652 launched child process 8944 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="3652.0.1635197124\234645555" -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 3652 "\\.\pipe\gecko-crash-server-pipe.3652" 2656 gpu)
23:03:09     INFO - ==> process 3652 launched child process 7992 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="3652.6.876689486\1336321733" -childID 1 -isForBrowser -prefsHandle 2040 -prefMapHandle 2036 -prefsLen 1 -prefMapSize 195993 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 3652 "\\.\pipe\gecko-crash-server-pipe.3652" 2176 tab)
23:03:09     INFO - ==> process 3652 launched child process 3596 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="3652.13.368616499\1904397907" -childID 2 -isForBrowser -prefsHandle 3468 -prefMapHandle 3472 -prefsLen 389 -prefMapSize 195993 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 3652 "\\.\pipe\gecko-crash-server-pipe.3652" 3484 tab)
23:03:09     INFO - ==> process 4536 launched child process 5488 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.48.1273104173\1256452814" -childID 7 -isForBrowser -prefsHandle 4664 -prefMapHandle 5092 -prefsLen 8306 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 5108 tab)
23:03:09     INFO - ==> process 4536 launched child process 11040 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.55.924308864\1385162370" -childID 8 -isForBrowser -prefsHandle 5332 -prefMapHandle 5352 -prefsLen 8716 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 5368 tab)
23:03:09     INFO - ==> process 4536 launched child process 10452 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.62.1599357542\508430954" -childID 9 -isForBrowser -prefsHandle 5588 -prefMapHandle 5592 -prefsLen 9546 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 5604 tab)
23:03:09     INFO - ==> process 4536 launched child process 7300 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="4536.69.1630074871\892685924" -childID 10 -isForBrowser -prefsHandle 5828 -prefMapHandle 5832 -prefsLen 9658 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 5844 tab)
23:03:09     INFO - ==> process 4536 launched child process 8808 ("C:\tasks\task_1549924918\build\application\firefox\plugin-container.exe" --channel="4536.76.1619578648\1391150202" "C:\Users\testdroid\AppData\Local\Temp\tmpfavno3.mozrunner\plugins\nptest.dll" "C:\Users\testdroid\AppData\LocalLow\Mozilla\Temp-{bf38b25c-2c10-487f-bc2c-6969c8b51ce4}" "C:\Users\testdroid\AppData\Roaming\Adobe\\" -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 7480 plugin)
23:03:09     INFO - ==> process 4536 launched child process 10900 ("C:\tasks\task_1549924918\build\application\firefox\plugin-container.exe" --channel="4536.80.1658097912\1434015992" "C:\Users\testdroid\AppData\Local\Temp\tmpfavno3.mozrunner\plugins\npswftest.dll" "C:\Users\testdroid\AppData\LocalLow\Mozilla\Temp-{bf38b25c-2c10-487f-bc2c-6969c8b51ce4}" "C:\Users\testdroid\AppData\Roaming\Adobe\\" -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 4536 "\\.\pipe\gecko-crash-server-pipe.4536" 6704 plugin)
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 11040
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 8944
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 7300
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 8808
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 1196
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 11148
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 2124
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 7992
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 1552
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 11256
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 10452
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 6712
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 10900
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 5488
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 9308
23:03:09     INFO - zombiecheck | Checking for orphan process with PID: 3596
23:03:09     INFO - Stopping web server
23:03:09     INFO - Stopping web socket server
23:03:09     INFO - Stopping ssltunnel
23:03:09  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!

23:07:33     INFO - runtests.py | Application ran for: 0:00:42.928000
23:07:33     INFO - zombiecheck | Reading PID log: c:\users\testdr~1\appdata\local\temp\tmpcqv2oopidlog
23:07:33     INFO - ==> process 2900 launched child process 6132 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.0.471634662\1221674216" -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 2244 gpu)
23:07:33     INFO - ==> process 2900 launched child process 7068 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.6.1417473693\1586370556" -childID 1 -isForBrowser -prefsHandle 1780 -prefMapHandle 2916 -prefsLen 1 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 1324 tab)
23:07:33     INFO - ==> process 2900 launched child process 2308 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.13.487241880\253486955" -childID 2 -isForBrowser -prefsHandle 2888 -prefMapHandle 2996 -prefsLen 132 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 1428 tab)
23:07:33     INFO - ==> process 2900 launched child process 4536 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.20.1943589431\1661869421" -childID 3 -isForBrowser -prefsHandle 3332 -prefMapHandle 3320 -prefsLen 132 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 3376 tab)
23:07:33     INFO - ==> process 2900 launched child process 6976 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.27.314884930\1261690634" -childID 4 -isForBrowser -prefsHandle 4020 -prefMapHandle 3704 -prefsLen 8070 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 4104 tab)
23:07:33     INFO - ==> process 2900 launched child process 7720 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.34.310751778\2138064512" -childID 5 -isForBrowser -prefsHandle 4116 -prefMapHandle 4152 -prefsLen 8121 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 4308 tab)
23:07:33     INFO - ==> process 2900 launched child process 5884 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.41.1203755066\605764081" -childID 6 -isForBrowser -prefsHandle 4524 -prefMapHandle 4528 -prefsLen 8121 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 4544 tab)
23:07:33     INFO - ==> process 2900 launched child process 4092 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.48.1601155391\150076285" -childID 7 -isForBrowser -prefsHandle 3740 -prefMapHandle 3744 -prefsLen 8595 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 3668 tab)
23:07:33     INFO - ==> process 2900 launched child process 6780 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.55.1292257226\1801920472" -childID 8 -isForBrowser -prefsHandle 3528 -prefMapHandle 5184 -prefsLen 8595 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 5176 tab)
23:07:33     INFO - ==> process 2900 launched child process 6356 ("C:\tasks\task_1549924918\build\application\firefox\firefox.exe" -contentproc --channel="2900.62.226447145\1901062074" -childID 9 -isForBrowser -prefsHandle 5256 -prefMapHandle 5240 -prefsLen 8595 -prefMapSize 194128 -parentBuildID 20190211212242 -greomni "C:\tasks\task_1549924918\build\application\firefox\omni.ja" -appomni "C:\tasks\task_1549924918\build\application\firefox\browser\omni.ja" -appdir "C:\tasks\task_1549924918\build\application\firefox\browser" - 2900 "\\.\pipe\gecko-crash-server-pipe.2900" 5420 tab)
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 6976
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 6780
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 2308
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 7720
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 5884
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 4092
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 6132
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 4536
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 6356
23:07:33     INFO - zombiecheck | Checking for orphan process with PID: 7068
23:07:33     INFO - Stopping web server
23:07:33     INFO - Stopping web socket server

Florian, can you please think of a better component for this? According your comment it seems to be an infra problem. Thanks.

Flags: needinfo?(florian)

Tentatively moving to Testing::Mochitest, but there may be another component better suited for platform specific configuration issues.

Component: Networking → Mochitest
Flags: needinfo?(florian)
Product: Core → Testing

this works for now; running on different hardware has different timing issues- I think some of these issues will be timing related- for this test case it is. Thanks for chiming in everyone.

:egao, if you want to extend the timing in the test, or figure out a way to extend it conditionally (maybe we add it to manifestparser?) and then add a line like |extend_timeout = 4|. Possibly we can query in the test to determine if we are on a slower config.

Flags: needinfo?(gbrown)
Flags: needinfo?(egao)

Recall that we adjust timeouts for debug/asan:

https://searchfox.org/mozilla-central/rev/38035ee92463c9e9fbca729ac7e66476ac7eb27a/testing/mochitest/runtests.py#1890-1897

Something like that might be appropriate (I'm not sure).

Flags: needinfo?(gbrown)

Used quicker method:

  • if windows and aarch64, extend timeout to 4x self.DEFAULT_TIMEOUT (default: 60.0)

(In reply to Joel Maher ( :jmaher ) (UTC-4) from comment #14)

this works for now; running on different hardware has different timing issues- I think some of these issues will be timing related- for this test case it is. Thanks for chiming in everyone.

:egao, if you want to extend the timing in the test, or figure out a way to extend it conditionally (maybe we add it to manifestparser?) and then add a line like |extend_timeout = 4|. Possibly we can query in the test to determine if we are on a slower config.

(In reply to Geoff Brown [:gbrown] (away Feb 18, 19) from comment #15)

Recall that we adjust timeouts for debug/asan:

https://searchfox.org/mozilla-central/rev/38035ee92463c9e9fbca729ac7e66476ac7eb27a/testing/mochitest/runtests.py#1890-1897

Something like that might be appropriate (I'm not sure).

I spent a good chunk of my day trying to figure out a system for manifests that permits:

  • specifying of extend_timeout
  • conditions for extend_timeout
  • extend_timeout value

I did not get very far. In the meantime, I cooked up a quick patch in the form of https://phabricator.services.mozilla.com/D19882. Will test this on the local hardware instead of Try, but I think this will resolve timing related issues for aarch64 for the time being. This should be be generalizable to mochitests, and I will run tests on a local machine using build with this change to verify.

No longer depends on: 1526276
Depends on: 1526276
Flags: needinfo?(egao)
Pushed by egao@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/dcd4928cb172
extend timeout for mochitest on aarch64 r=gbrown

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

Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox67: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla67
Assignee: nobody → egao
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: