Closed Bug 1512741 Opened 9 months ago Closed 6 months ago

Intermittent TEST-UNEXPECTED-TIMEOUT | toolkit/components/extensions/test/xpcshell/test_ext_userScripts.js | Test timed out

Categories

(WebExtensions :: General, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED FIXED

People

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

Details

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

Attachments

(2 files)

Filed by: dluca [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=215936245&repo=autoland

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

[task 2018-12-07T16:29:43.325Z] 16:29:43     INFO - Killing every process called emulator64-arm
[task 2018-12-07T16:29:43.336Z] 16:29:43     INFO - Killing pid 471.
[task 2018-12-07T16:29:43.337Z] 16:29:43     INFO - [mozharness: 2018-12-07 16:29:43.336948Z] Finished run-tests step (success)
[task 2018-12-07T16:29:43.337Z] 16:29:43     INFO - Running post-run listener: _resource_record_post_run
[task 2018-12-07T16:29:43.534Z] 16:29:43     INFO - Total resource usage - Wall time: 3518s; CPU: 25.0%; Read bytes: 110592; Write bytes: 1210191872; Read time: 24; Write time: 211328
[task 2018-12-07T16:29:43.534Z] 16:29:43     INFO - TinderboxPrint: CPU usage<br/>24.8%
[task 2018-12-07T16:29:43.534Z] 16:29:43     INFO - TinderboxPrint: I/O read bytes / time<br/>110,592 / 24
[task 2018-12-07T16:29:43.534Z] 16:29:43     INFO - TinderboxPrint: I/O write bytes / time<br/>1,210,191,872 / 211,328
[task 2018-12-07T16:29:43.535Z] 16:29:43     INFO - TinderboxPrint: CPU idle<br/>10,506.7 (75.1%)
[task 2018-12-07T16:29:43.536Z] 16:29:43     INFO - TinderboxPrint: CPU user<br/>3,457.1 (24.7%)
[task 2018-12-07T16:29:43.536Z] 16:29:43     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2018-12-07T16:29:43.539Z] 16:29:43     INFO - verify-device - Wall time: 5s; CPU: 5.0%; Read bytes: 0; Write bytes: 21512192; Read time: 0; Write time: 10084
[task 2018-12-07T16:29:43.543Z] 16:29:43     INFO - install - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2018-12-07T16:29:43.584Z] 16:29:43     INFO - run-tests - Wall time: 3513s; CPU: 25.0%; Read bytes: 110592; Write bytes: 1188679680; Read time: 24; Write time: 201244
[task 2018-12-07T16:29:44.700Z] 16:29:44  WARNING - returning nonzero exit status 1
[task 2018-12-07T16:29:44.735Z] cleanup
[task 2018-12-07T16:29:44.735Z] + cleanup
[task 2018-12-07T16:29:44.735Z] + local rv=1
[task 2018-12-07T16:29:44.735Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2018-12-07T16:29:44.735Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2018-12-07T16:29:44.736Z] + true
[task 2018-12-07T16:29:44.736Z] + cleanup_xvfb
[task 2018-12-07T16:29:44.737Z] pidof Xvfb
[task 2018-12-07T16:29:44.737Z] ++ pidof Xvfb
[task 2018-12-07T16:29:44.741Z] + local xvfb_pid=25
[task 2018-12-07T16:29:44.741Z] + local vnc=false
[task 2018-12-07T16:29:44.741Z] + local interactive=false
[task 2018-12-07T16:29:44.741Z] + '[' -n 25 ']'
[task 2018-12-07T16:29:44.741Z] + [[ false == false ]]
[task 2018-12-07T16:29:44.741Z] + [[ false == false ]]
[task 2018-12-07T16:29:44.741Z] + kill 25
[task 2018-12-07T16:29:44.741Z] + screen -XS xvfb quit
[task 2018-12-07T16:29:44.746Z] XIO:  fatal IO error 11 (Resource temporarily unavailable) on X server ":0"
[task 2018-12-07T16:29:44.752Z]       after 1066 requests (1066 known processed) with 0 events remaining.
[task 2018-12-07T16:29:44.753Z] compizconfig - Info: Backend     : ini
[task 2018-12-07T16:29:44.753Z] compizconfig - Info: Integration : true
[task 2018-12-07T16:29:44.753Z] compizconfig - Info: Profile     : default
[task 2018-12-07T16:29:44.917Z] No screen session found.
[task 2018-12-07T16:29:44.917Z] + true
[task 2018-12-07T16:29:44.917Z] + exit 1
[taskcluster 2018-12-07 16:29:45.280Z] === Task Finished ===
[taskcluster 2018-12-07 16:29:53.930Z] Unsuccessful task run with exit code: 1 completed in 3628.628 seconds
[task 2018-12-07T16:24:32.814Z] 16:24:32     INFO -  TEST-START | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_userScripts.js
[task 2018-12-07T16:29:32.816Z] 16:29:32  WARNING -  TEST-UNEXPECTED-TIMEOUT | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_userScripts.js | Test timed out
[task 2018-12-07T16:29:32.816Z] 16:29:32     INFO -  TEST-INFO took 300000ms
[task 2018-12-07T16:29:33.223Z] 16:29:33     INFO -  xpcshell return code: -1
[task 2018-12-07T16:29:43.287Z] 16:29:43  WARNING -  TEST-UNEXPECTED-FAIL | Received SIGINT (control-C), so stopped run. (Use --keep-going to keep running tests after killing one with SIGINT)

This bug has failed 37 times in the last 7 days. Occurs on android-em-4-3-armv7-api16 on debug build types.

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

ddurst:

Can you please take a look at this bug?

Flags: needinfo?(ddurst)
Whiteboard: [stockwell needswork]

(In reply to Narcis Beleuzu [:NarcisB] from comment #10)

There are 78 failures in the last 7 days.
Jolin, the fail started from Bug 1495053 - https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=android%2C4.3%2Capi16%2B%2Cdebug%2Cxpcshell%2Ctests%2Ctest-android-em-4.3-arm7-api-16%2Fdebug-xpcshell-11%2Cx%28x11%29&tochange=8442297c6818db346c8252914f7d69fd68094f10&fromchange=ffb2ef47c53699f188ab5f316f3285f8a012e743

Could you please take a look?

I don't see how changes for CDM support would ever affect the WebExtensions test results. The code in those patches won't be executed unless a specific EME API [1] is used. Could it be other changes before that?

[1] https://w3c.github.io/encrypted-media/#dom-mediakeys-setservercertificate

Flags: needinfo?(jolin)
Attachment #9037288 - Flags: review?(jmaher) → review+
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]

Pushed by ccoroiu@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/de8ba06db792
disable test_ext_userScripts.js on Android debug for frequent failures. r=jmaher

Keywords: checkin-needed

This patch move the part of test_ext_userScripts.js that is testing the userScripts' export API helpers
(script.defineGlobals and script.export) into a separate test_ext_userScripts_exports.js test file.

Based on the logs from the intermittent failures of the test_ext_userScripts.js test file
on android debug builds, it seems that this xpcshell test was just timing out while exiting after all
the test tasks were actually completed.

The results got from pushing to try this patch seems to confirm that once the test tasks are splitted
over two test files, the intermittent failures are not being triggered anymore on the android debug
builds.

Push to try of the attached patch (running test-android-em-4.3-arm7-api-16/debug-xpcshell-11 for 5 times, to double check that the intermittent failures tracked by this issue is not being triggered with the changes described in comment 20):

Pushed by luca.greco@alcacoop.it:
https://hg.mozilla.org/integration/autoland/rev/4f629b83e01b
Split userScripts xpcshell test and re-enable it on android debug build. r=robwu

Marked as fixed, as this test has been splitted into two test files and re-enabled (comment 23).

Assignee: shindli → lgreco
Status: NEW → RESOLVED
Closed: 6 months ago
Flags: needinfo?(ddurst)
Keywords: leave-open
Resolution: --- → FIXED
Whiteboard: [stockwell disabled] → [stockwell fixed]
You need to log in before you can comment on or make changes to this bug.