Closed Bug 1469904 Opened Last year Closed 10 months ago

Perma-failing tier2 TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Test timed out

Categories

(Toolkit :: Add-ons Manager, defect)

defect
Not set

Tracking

()

RESOLVED FIXED
mozilla66
Tracking Status
firefox66 --- fixed

People

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

References

Details

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

Attachments

(2 files)

Filed by: apavel [at] mozilla.com

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

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

14:06:10     INFO -  TEST-START | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_temporary.js
14:11:10  WARNING -  TEST-UNEXPECTED-TIMEOUT | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Test timed out
14:11:10     INFO -  TEST-INFO took 300000ms
14:11:10     INFO -  >>>>>>>
14:11:10     INFO -  PID 7268 | [7268, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file z:/build/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2682
14:11:10     INFO -  PID 7268 | JavaScript strict warning: resource://testing-common/AddonTestUtils.jsm, line 310: ReferenceError: reference to undefined property "testScope"
14:11:10     INFO -  "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "testScope"" {file: "resource://testing-common/AddonTestUtils.jsm" line: 310}]"
14:11:10     INFO -  PID 7268 | [7268, LoadRoots] WARNING: This method is lossy. Use GetCanonicalPath !: file z:/build/build/src/xpcom/io/nsLocalFileWin.cpp, line 3464
14:11:10     INFO -  PID 7268 | [7268, LoadRoots] WARNING: This method is lossy. Use GetCanonicalPath !: file z:/build/build/src/xpcom/io/nsLocalFileWin.cpp, line 3464
14:11:10     INFO -  PID 7268 | [7268, LoadRoots] WARNING: This method is lossy. Use GetCanonicalPath !: file z:/build/build/src/xpcom/io/nsLocalFileWin.cpp, line 3464
14:11:10     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
14:11:10     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
14:11:10     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
14:11:10     INFO -  running event loop
14:11:10     INFO -  xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Starting test_new_temporary
14:11:10     INFO -  (xpcshell/head.js) | test test_new_temporary pending (2)
14:11:10     INFO -  PID 7268 | 1529503571931	addons.manager	DEBUG	Application has been upgraded
14:11:10     INFO -  PID 7268 | 1529503572010	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider", "XPIInternal"]
14:11:10     INFO -  PID 7268 | 1529503572037	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/LightweightThemeManager.jsm: ["LightweightThemeManager"]
14:11:10     INFO -  PID 7268 | 1529503572071	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm
14:11:10     INFO -  PID 7268 | 1529503572084	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm
14:11:10     INFO -  PID 7268 | 1529503572088	addons.manager	DEBUG	Starting provider: XPIProvider
14:11:10     INFO -  PID 7268 | 1529503572091	addons.xpi	DEBUG	startup
14:11:10     INFO -  PID 7268 | 1529503572092	addons.xpi	WARN	List of valid built-in add-ons could not be parsed.: [Exception... "Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsIXPCComponents_Utils.readUTF8URI]"  nsresult: "0xc1f30001 (NS_ERROR_NOT_INITIALIZED)"  location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: startup :: line 2093"  data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2093
14:11:10     INFO -  PID 7268 | callProvider()@resource://gre/modules/AddonManager.jsm:206
14:11:10     INFO -  PID 7268 | _startProvider()@resource://gre/modules/AddonManager.jsm:654
14:11:10     INFO -  PID 7268 | startup()@resource://gre/modules/AddonManager.jsm:813
14:11:10     INFO -  PID 7268 | startup()@resource://gre/modules/AddonManager.jsm:2808
14:11:10     INFO -  PID 7268 | observe()@jar:file:///Z:/task_1529500723/build/application/firefox/omni.ja!/components/addonManager.js:66
14:11:10     INFO -  PID 7268 | promiseStartupManager()@resource://testing-common/AddonTestUtils.jsm:768
14:11:10     INFO -  PID 7268 | 1529503572109	addons.xpi	INFO	SystemAddonLocation directory is missing
14:11:10     INFO -  PID 7268 | 1529503572205	addons.xpi	INFO	Removing all system add-on upgrades.
14:11:10     INFO -  PID 7268 | 1529503572212	addons.xpi	DEBUG	checkForChanges
14:11:10     INFO -  PID 7268 | 1529503572215	addons.xpi	DEBUG	Loaded add-on state: ${}
14:11:10     INFO -  PID 7268 | 1529503572219	addons.xpi	DEBUG	scanForChanges changed: false, state: {}
14:11:10     INFO -  PID 7268 | 1529503572222	addons.xpi	DEBUG	Empty XPI database, setting schema version preference to 27
14:11:10     INFO -  PID 7268 | 1529503572223	addons.xpi	DEBUG	No changes found
14:11:10     INFO -  PID 7268 | 1529503572285	addons.manager	DEBUG	Registering shutdown blocker for XPIProvider
14:11:10     INFO -  PID 7268 | 1529503572287	addons.manager	DEBUG	Provider finished startup: XPIProvider
14:11:10     INFO -  PID 7268 | 1529503572288	addons.manager	DEBUG	Starting provider: LightweightThemeManager
14:11:10     INFO -  PID 7268 | 1529503572288	addons.manager	DEBUG	Registering shutdown blocker for LightweightThemeManager
14:11:10     INFO -  PID 7268 | 1529503572290	addons.manager	DEBUG	Provider finished startup: LightweightThemeManager
14:11:10     INFO -  PID 7268 | 1529503572294	addons.manager	DEBUG	Starting provider: GMPProvider
14:11:10     INFO -  PID 7268 | 1529503572307	addons.manager	DEBUG	Registering shutdown blocker for GMPProvider
14:11:10     INFO -  PID 7268 | 1529503572308	addons.manager	DEBUG	Provider finished startup: GMPProvider
14:11:10     INFO -  PID 7268 | 1529503572309	addons.manager	DEBUG	Starting provider: PluginProvider
14:11:10     INFO -  PID 7268 | 1529503572310	addons.manager	DEBUG	Registering shutdown blocker for PluginProvider
14:11:10     INFO -  PID 7268 | 1529503572311	addons.manager	DEBUG	Provider finished startup: PluginProvider
14:11:10     INFO -  PID 7268 | JavaScript strict warning: resource://gre/modules/LightweightThemeManager.jsm, line 694: ReferenceError: reference to undefined property "version"
14:11:10     INFO -  PID 7268 | 1529503572343	addons.manager	DEBUG	Completed startup sequence
14:11:10     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
14:11:10     INFO -  "CONSOLE_MESSAGE: (info) 1529503571931	addons.manager	DEBUG	Application has been upgraded"
14:11:10     INFO -  "CONSOLE_MESSAGE: (info) 1529503572010	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider", "XPIInternal"]"
14:11:10     INFO -  "CONSOLE_MESSAGE: (info) 1529503572037	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/LightweightThemeManager.jsm: ["LightweightThemeManager"]"
14:11:10     INFO -  "CONSOLE_MESSAGE: (info) 1529503572071	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm"
14:11:10     INFO -  "CONSOLE_MESSAGE: (info) 1529503572084	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm"
14:11:10     INFO -  "CONSOLE_MESSAGE: (info) 1529503572088	addons.manager	DEBUG	Starting provider: XPIProvider"
14:11:10     INFO -  "CONSOLE_MESSAGE: (info) 1529503572091	addons.xpi	DEBUG	startup"
14:11:10     INFO -  "CONSOLE_MESSAGE: (info) 1529503572092	addons.xpi	WARN	List of valid built-in add-ons could not be parsed.: [Exception... "Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsIXPCComponents_Utils.readUTF8URI]"  nsresult: "0xc1f30001 (NS_ERROR_NOT_INITIALIZED)"  location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: startup :: line 2093"  data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2093
14:11:10     INFO -  callProvider()@resource://gre/modules/AddonManager.jsm:206
14:11:10     INFO -  _startProvider()@resource://gre/modules/AddonManager.jsm:654
14:11:10     INFO -  startup()@resource://gre/modules/AddonManager.jsm:813
14:11:10     INFO -  startup()@resource://gre/modules/AddonManager.jsm:2808
14:11:10     INFO -  observe()@jar:file:///Z:/task_1529500723/build/application/firefox/omni.ja!/components/addonManager.js:66
14:11:10     INFO -  promiseStartupManager()@resource://testing-common/AddonTestUtils.jsm:768"
See Also: → 1469915
Summary: Intermittent TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Test timed out → Perma-failing tier2 ccov TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Test timed out
Duplicate of this bug: 1469915
This failures became perma on tier 2 after this merge: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&revision=681eb7dfa324dd50403c382888929ea8b8b11b00

Looked into the merge, presumably the cause is https://bugzilla.mozilla.org/show_bug.cgi?id=1463635

:marco is this something you can look into?
Flags: needinfo?(mcastelluccio)
Redirecting needinfo to :kmag, author of bug 1463635. Perhaps it's just a matter of increasing the timeout?
Blocks: 1463635
Flags: needinfo?(mcastelluccio) → needinfo?(kmaglione+bmo)
Hm. No, it looks like this always fails in the same place. It's probably a race.
Assignee: nobody → kmaglione+bmo
Flags: needinfo?(kmaglione+bmo)
(In reply to Kris Maglione [:kmag] from comment #7)
> Hm. No, it looks like this always fails in the same place. It's probably a
> race.

Okay, so is disabling the test a solution in this case or can you fix it?
Flags: needinfo?(kmaglione+bmo)
There are 33 failures for the past 7 days, all on windows10-64-ccov platform debug.

Recent log failure: https://treeherder.mozilla.org/logviewer.html#?job_id=188671566&repo=mozilla-central&lineNumber=3460

Relevant part of the log: 
00:54:23     INFO -  TEST-START | toolkit/modules/tests/xpcshell/test_DeferredTask.js
00:54:32     INFO -  TEST-PASS | toolkit/modules/tests/xpcshell/test_DeferredTask.js | took 9174ms
00:54:32     INFO -  TEST-START | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_temporary.js
00:59:32  WARNING -  TEST-UNEXPECTED-TIMEOUT | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Test timed out
00:59:32     INFO -  TEST-INFO took 300001ms
00:59:32     INFO -  >>>>>>>
00:59:32     INFO -  PID 3168 | [3168, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file z:/build/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2707
00:59:32     INFO -  PID 3168 | JavaScript strict warning: resource://testing-common/AddonTestUtils.jsm, line 310: ReferenceError: reference to undefined property "testScope"
00:59:32     INFO -  "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "testScope"" {file: "resource://testing-common/AddonTestUtils.jsm" line: 310}]"
00:59:32     INFO -  PID 3168 | [3168, LoadRoots] WARNING: This method is lossy. Use GetCanonicalPath !: file z:/build/build/src/xpcom/io/nsLocalFileWin.cpp, line 3459
00:59:32     INFO -  PID 3168 | [3168, LoadRoots] WARNING: This method is lossy. Use GetCanonicalPath !: file z:/build/build/src/xpcom/io/nsLocalFileWin.cpp, line 3459
00:59:32     INFO -  PID 3168 | [3168, LoadRoots] WARNING: This method is lossy. Use GetCanonicalPath !: file z:/build/build/src/xpcom/io/nsLocalFileWin.cpp, line 3459
00:59:32     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
00:59:32     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
00:59:32     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
00:59:32     INFO -  running event loop
00:59:32     INFO -  xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Starting test_new_temporary
00:59:32     INFO -  (xpcshell/head.js) | test test_new_temporary pending (2)

:kmag could you please take a look at this?
Update: there were 43 failures in the last 7 days:
- 1 failure on linux64-jsdcov opt
- 33 failures on windows10-64-ccov debug
- 9 failures on windows7-32-msvc debug
There have been 41 failures in the last 7 days.
All occurrences are on the debug build type.

windows10-64-ccov: 39 failures
windows10-64: 1 failure
windows7-32-msvc: 1 failure

Recent log file and snippet with the failure:
https://treeherder.mozilla.org/logviewer.html#?job_id=191502063&repo=mozilla-central&lineNumber=3708

01:51:02     INFO -  TEST-START | toolkit/components/url-classifier/tests/unit/test_listmanager.js
01:51:09     INFO -  TEST-PASS | toolkit/components/url-classifier/tests/unit/test_listmanager.js | took 7058ms
01:51:09     INFO -  TEST-START | toolkit/modules/tests/xpcshell/test_DeferredTask.js
01:51:19     INFO -  TEST-PASS | toolkit/modules/tests/xpcshell/test_DeferredTask.js | took 9601ms
01:51:19     INFO -  TEST-START | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_system_update_fail.js
01:52:15     INFO -  TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_system_update_fail.js | took 56371ms
01:52:15     INFO -  TEST-START | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_temporary.js
01:57:15  WARNING -  TEST-UNEXPECTED-TIMEOUT | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Test timed out
01:57:15     INFO -  TEST-INFO took 300000ms
Comment on attachment 9001831 [details] [diff] [review]
disablewin10ccov_bug1469904

Review of attachment 9001831 [details] [diff] [review]:
-----------------------------------------------------------------

thanks!
Attachment #9001831 - Flags: review?(jmaher) → review+
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Pushed by nerli@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/845be8b8ba05
Disable test_temporary.js for failures on windows10-64-ccov r=jmaher
Keywords: checkin-needed
Flags: needinfo?(kmaglione+bmo)
Summary: Perma-failing tier2 ccov TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Test timed out → Perma-failing tier2 TEST-UNEXPECTED-TIMEOUT | toolkit/mozapps/extensions/test/xpcshell/test_temporary.js | Test timed out
Assignee: kmaglione+bmo → nobody
Assignee: nobody → hsivonen
Attachment #9035670 - Flags: review?(aswan)
Attachment #9035670 - Flags: review?(aswan) → review+

Henri, can we land this?

Flags: needinfo?(hsivonen)
Pushed by hsivonen@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f88248b391c6
Disable test_temporary.js on Windows, because it fails with increased run-time stack size. r=aswan.

Landed.

Flags: needinfo?(hsivonen)
Keywords: leave-open

Thank you.

Status: NEW → RESOLVED
Closed: 10 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla66
You need to log in before you can comment on or make changes to this bug.