Closed Bug 1562117 Opened 5 years ago Closed 5 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | browser/components/extensions/test/ | xpcshell/test_ext_normandyAddonStudy.jsTest timed out

Categories

(Firefox :: Normandy Client, defect, P5)

Product:
Firefox
Component:
Normandy Client
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
Firefox 70
Tracking Flags:
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- unaffected
firefox68 --- unaffected
firefox69 --- wontfix
firefox70 --- fixed

People

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

References

(Regression)

Details

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

Attachments

(1 file)

Bug 1562117 - Fix race in test_ext_normandyAddonStudy test cases. r?mixedpuppy!
47 bytes, text/x-phabricator-request
Details | Review

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=253847301&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/fKr52KEMT--G5d6Y6HhH3A/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/fKr52KEMT--G5d6Y6HhH3A/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2019-06-28T03:05:02.433Z] 03:05:02 INFO - TEST-START | xpcshell-remote.ini:browser/components/extensions/test/xpcshell/test_ext_normandyAddonStudy.js
[task 2019-06-28T03:10:02.434Z] 03:10:02 WARNING - TEST-UNEXPECTED-TIMEOUT | xpcshell-remote.ini:browser/components/extensions/test/xpcshell/test_ext_normandyAddonStudy.js | Test timed out
[task 2019-06-28T03:10:02.436Z] 03:10:02 INFO - TEST-INFO took 300000ms
[task 2019-06-28T03:10:02.437Z] 03:10:02 INFO - >>>>>>>
[task 2019-06-28T03:10:02.437Z] 03:10:02 INFO - PID 18177 | *** You are running in chaos test mode. See ChaosMode.h. ***
[task 2019-06-28T03:10:02.438Z] 03:10:02 INFO - PID 18177 | WARN 2019-06-28T03:05:02Z: audio_thread_priority::rt_linux: Could not make thread real-time.
[task 2019-06-28T03:10:02.438Z] 03:10:02 INFO - PID 18177 | [18177, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file /builds/worker/workspace/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2555
[task 2019-06-28T03:10:02.439Z] 03:10:02 INFO - PID 18177 | [18177, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002: file /builds/worker/workspace/build/src/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 662
[task 2019-06-28T03:10:02.440Z] 03:10:02 INFO - PID 18177 | [18177, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /builds/worker/workspace/build/src/extensions/permissions/nsPermissionManager.cpp, line 2903
[task 2019-06-28T03:10:02.441Z] 03:10:02 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2019-06-28T03:10:02.443Z] 03:10:02 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2019-06-28T03:10:02.445Z] 03:10:02 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2019-06-28T03:10:02.448Z] 03:10:02 INFO - running event loop
[task 2019-06-28T03:10:02.455Z] 03:10:02 INFO - xpcshell-remote.ini:browser/components/extensions/test/xpcshell/test_ext_normandyAddonStudy.js | Starting setup
[task 2019-06-28T03:10:02.457Z] 03:10:02 INFO - (xpcshell/head.js) | test setup pending (2)
[task 2019-06-28T03:10:02.459Z] 03:10:02 INFO - PID 18177 | 1561691102853 addons.manager DEBUG Application has been upgraded

Component: Add-ons Manager → Normandy Client
Product: Toolkit → Firefox
Regressed by: 1536658

Issue appears to be with test_endStudy_works when run in chaos mode.

Type: -- → defect

The changes applied in Bug 1542035 shouldn't be able to affect test_ext_normandyAddonStudy.js intermittency.

Also, looking at the graph linked to this intermittent:

The test failed only once when Bug 1542035 patch has been landed (but given that this was already an open intermittent, it is likely just a coincidence), but then it stays basically inactive until it raised in intermittency between Aug 24-Aug 26.

I did try to run test_ext_normandyAddonStudy.js locally and for me (on a linux64 artifact build) it is basically a permafail and so I did an hg bisect to see if hg could identify a particular commit as the one that triggered the increase in intermittency.

hg bisect pointed to this commit (which landed on Aug 26):

I'm not sure how Bug 1513705 has triggered an increase in intermittency of the test_ext_normandyAddonStudy.js, but I noticed that there are 2 races in its test cases (in particular in test_endStudy_works, which seems to have never been able to pass the --verify when running in chaosmode, see Bug 1562117 comment 1).

I'm attaching to this bug a patch to fix the races in test_ext_normandyAddonStudy.js, which (at least locally) seems to be enough to get the test file to pass --verify consistently (including when running in chaosmode).

Flags: needinfo?(bdanforth)
Assignee: nobody → lgreco
Status: NEW → ASSIGNED
Pushed by luca.greco@alcacoop.it:
https://hg.mozilla.org/integration/autoland/rev/ab9a80002a62
Fix race in test_ext_normandyAddonStudy test cases. r=mixedpuppy

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

Status: ASSIGNED → RESOLVED
Closed: 5 years ago
status-firefox70: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 70

Thanks for working on this Luca!

Marking as [stockwell fixed], as the orangefactor graph shows this test didn't failed anymore after we landed the fix.

Whiteboard: [stockwell disable-recommended] → [stockwell fixed]
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: