thunderbird perma fail after bug 1667276 | toolkit/components/backgroundtasks/tests/xpcshell/test_backgroundtask_specific_pref.js, toolkit/components/backgroundtasks/tests/xpcshell/test_backgroundtask_policies.js, test_crash_backgroundtask_moz_crash.js
Categories
(Thunderbird :: Upstream Synchronization, defect, P5)
Tracking
(thunderbird_esr78 unaffected)
| Tracking | Status | |
|---|---|---|
| thunderbird_esr78 | --- | unaffected |
People
(Reporter: intermittent-bug-filer, Assigned: mkmelin)
References
(Regression)
Details
(Keywords: intermittent-failure, leave-open, regression, Whiteboard: [stockwell fixed:patch])
Attachments
(2 files)
|
2.07 KB,
patch
|
Details | Diff | Splinter Review | |
|
48 bytes,
text/x-phabricator-request
|
Details | Review |
Filed by: mkmelin [at] iki.fi
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=328141058&repo=comm-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/R4hznyBcQ0eqdigwlKGDiw/runs/0/artifacts/public/logs/live_backing.log
| Assignee | ||
Updated•4 years ago
|
| Assignee | ||
Comment 1•4 years ago
|
||
toolkit/crashreporter/test/unit/test_crash_backgroundtask_moz_crash.js is also from bug 1667276 (which added that)
| Assignee | ||
Comment 2•4 years ago
|
||
https://searchfox.org/mozilla-central/search?q=MOZ_BACKGROUNDTASKS&path=browser&case=false®exp=false would probably need to be ported.
Arguably the tests should bail out if AppConstants.MOZ_BACKGROUNDTASKS isn't on though.
| Assignee | ||
Comment 3•4 years ago
|
||
Rebuilt. AppConstants.MOZ_BACKGROUNDTASKS is true...
| Assignee | ||
Comment 4•4 years ago
|
||
For some reason ChromUtils.import("resource://gre/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm") will fail while the others work
| Comment hidden (Intermittent Failures Robot) |
| Assignee | ||
Comment 6•4 years ago
|
||
This should be done. Doesn't help with the test failure.
| Assignee | ||
Updated•4 years ago
|
| Assignee | ||
Comment 8•4 years ago
|
||
Nick, any ideas why this would fail for Thunderbird?
Comment 9•4 years ago
|
||
(In reply to Magnus Melin [:mkmelin] from comment #2)
https://searchfox.org/mozilla-central/search?q=MOZ_BACKGROUNDTASKS&path=browser&case=false®exp=false would probably need to be ported.
Arguably the tests should bail out if AppConstants.MOZ_BACKGROUNDTASKS isn't on though.
Yes, we should. I tried to ensure this but clearly missed some; patches appreciated.
(In reply to Magnus Melin [:mkmelin] from comment #8)
Nick, any ideas why this would fail for Thunderbird?
Not immediately. The logs report error 2, which isn't supposed to happen: it means the relevant promise hasn't resolved but that we're exiting for some reason. I think that must mean the event loop has processed all events.
Now, I fetched this macOS Thunderbird Daily and with that I find (after removing some log cruft):
~/Mozilla/gecko $ /Volumes/Thunderbird\ Daily/Thunderbird\ DailyDebug.app/Contents/MacOS/thunderbird --backgroundtask success
*** You are running in background task mode. ***
*** You are running in headless mode.
~/Mozilla/gecko $ echo $?
0
~/Mozilla/gecko $ /Volumes/Thunderbird\ Daily/Thunderbird\ DailyDebug.app/Contents/MacOS/thunderbird --backgroundtask failure
*** You are running in background task mode. ***
*** You are running in headless mode.
~/Mozilla/gecko $ echo $?
1
~/Mozilla/gecko $ /Volumes/Thunderbird\ Daily/Thunderbird\ DailyDebug.app/Contents/MacOS/thunderbird --backgroundtask exception
*** You are running in background task mode. ***
*** You are running in headless mode.
console.error: BackgroundTasksManager:
Backgroundtask named 'exception' threw exception
Message: Error: test
Stack:
runBackgroundTask@resource:///modules/backgroundtasks/BackgroundTask_exception.jsm:11:9
runBackgroundTaskNamed@resource://gre/modules/BackgroundTasksManager.jsm:117:26
~/Mozilla/gecko $ echo $?
3
That's all correct, so the actual --backgroundtask stuff is working, it's "just" something to do with the test harnesses. That strongly suggests that the mangling to load test-only background tasks isn't quite working for Thunderbird. The way this works is that the launching harness takes its own modules directory (i.e., it's own resources://testing-common URI) and puts it in the XPCSHELL_TESTING_MODULES_URI environment variable for the launched --backgroundtask process to find and search for task modules.
So the next thing would be to bump the background task logging pref toolkit.backgroundtasks.loglevel to debug, either by modifying the source here or with a try push that sets the preference. I haven't time to do that locally, sorry.
Alternately, you can default this to off in Thunderbird. I think this probably makes the most sense. See https://searchfox.org/mozilla-central/rev/fd853f4aea89186efdb368e759a71b7a90c2b89c/toolkit/moz.configure#2505.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Assignee | ||
Comment 12•4 years ago
|
||
The problem is it doesn't find the resource://gre/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm module -> exception in the outer try-catch.
success, failure and exception works. It's the specific_pref one that doesn't
Is this supposed to be working?
obj-x86_64-pc-linux-gnu/dist/bin/thunderbird --backgroundtask specific_pref
*** You are running in background task mode. ***
*** You are running in headless mode.
console.info: BackgroundTasksManager: Running background task named 'specific_pref' (with 0 arguments)
console.debug: BackgroundTasksManager:
Looking for background task at URI: resource:///modules/backgroundtasks/BackgroundTask_specific_pref.jsm
console.debug: BackgroundTasksManager:
Looking for background task at URI: resource://gre/modules/backgroundtasks/BackgroundTask_specific_pref.jsm
console.info: BackgroundTasksManager: Invoking Services.startup.quit(..., 2)
JavaScript error: resource://gre/modules/BackgroundTasksManager.jsm, line 82: NS_ERROR_UNEXPECTED
| Assignee | ||
Comment 13•4 years ago
|
||
Oh that doesn't work on Firefox nightly either. I guess test only...
The jsm does get put at ./obj-x86_64-pc-linux-gnu/_tests/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
Comment 14•4 years ago
|
||
(In reply to Magnus Melin [:mkmelin] from comment #13)
Oh that doesn't work on Firefox nightly either. I guess test only...
The jsm does get put at ./obj-x86_64-pc-linux-gnu/_tests/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
Can you run the test with the logging pref? You should see 3 Looking for background task ... lines, the third being the resource://testing-common/... search path, which is test-only. (The test should also be chatty about the resource://testing-common substitution.)
You can run the test with ./mach test toolkit/components/backgroundtasks/tests/xpcshell/test_backgroundtask_specific_pref.js, possibly with the path updated for Thunderbird's directory structure. Thanks for tracking this down with me!
| Assignee | ||
Comment 15•4 years ago
|
||
Thanks for looking! Hope the logging is useful, but it doesn't give me much clues. Like I wrote the issue seems to be that esource://gre/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm is not found. (So it doesn't get to the third "looking for")
./mach test toolkit/components/backgroundtasks/tests/xpcshell/test_backgroundtask_specific_pref.js
pid:296038 > *** You are running in background task mode. ***
0:08.29 pid:296038 > *** You are running in headless mode.
0:08.35 pid:296038 > console.info: BackgroundTasksManager: Running background task named 'backgroundtask_specific_pref' (with 1 arguments)
0:08.35 pid:296038 > console.error: BackgroundTasksManager:
0:08.35 pid:296038 > Substitution set: resource://testing-common aliases file:///home/magnus/Code/tb/mozilla/obj-x86_64-pc-linux-gnu/_tests/modules/
0:08.35 pid:296038 > console.debug: BackgroundTasksManager:
0:08.35 pid:296038 > Looking for background task at URI: resource:///modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
0:08.35 pid:296038 > console.debug: BackgroundTasksManager:
0:08.35 pid:296038 > Looking for background task at URI: resource://gre/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
0:08.36 pid:296038 > console.info: BackgroundTasksManager: Invoking Services.startup.quit(..., 2)
0:08.36 pid:296038 > JavaScript error: resource://gre/modules/BackgroundTasksManager.jsm, line 82: NS_ERROR_UNEXPECTED
0:08.38 FAIL test_backgroundtask_specific_pref - [test_backgroundtask_specific_pref : 19] 79 == 2
/home/magnus/Code/tb/mozilla/obj-x86_64-pc-linux-gnu/_tests/xpcshell/toolkit/components/backgroundtasks/tests/xpcshell/test_backgroundtask_specific_pref.js:test_backgroundtask_specific_pref:19
/home/magnus/Code/tb/mozilla/testing/xpcshell/head.js:_do_main:239
/home/magnus/Code/tb/mozilla/testing/xpcshell/head.js:_execute_test:567
-e:null:1
0:08.38 INFO exiting test
0:08.38 ERROR Unexpected exception NS_ERROR_ABORT:
_abort_failed_test@/home/magnus/Code/tb/mozilla/testing/xpcshell/head.js:827:20
do_report_result@/home/magnus/Code/tb/mozilla/testing/xpcshell/head.js:928:5
Assert<@/home/magnus/Code/tb/mozilla/testing/xpcshell/head.js:73:21
proto.report@resource://testing-common/Assert.jsm:233:10
equal@resource://testing-common/Assert.jsm:275:8
test_backgroundtask_specific_pref@/home/magnus/Code/tb/mozilla/obj-x86_64-pc-linux-gnu/_tests/xpcshell/toolkit/components/backgroundtasks/tests/xpcshell/test_backgroundtask_specific_pref.js:19:10
_do_main@/home/magnus/Code/tb/mozilla/testing/xpcshell/head.js:239:6
_execute_test@/home/magnus/Code/tb/mozilla/testing/xpcshell/head.js:567:5
@-e:1:1
Comment 16•4 years ago
|
||
This is fascinating. So, based on
Substitution set: resource://testing-common aliases file:///home/magnus/Code/tb/mozilla/obj-x86_64-pc-linux-gnu/_tests/modules/
I can see that the test harness is configuring the environment correctly. However, what's happening is that the ChromeUtils.import(...) is throwing NS_ERROR_UNEXPECTED for resource://gre/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm when the code expects only NS_ERROR_FILE_NOT_FOUND.
Can you bump the catch here to be more general (catch both, or catch anything) and see if that addresses the issue? Then we could try to understand why the code path in MozJSComponentLoader.cpp diverges. If you can attach a debugger and see where this NS_ERROR_UNEXPECTED arises that would be grand. If it's from the only obvious place that suggests a subtle bug in the module loader when trying to load a module from multiple locations.
Thanks!
| Assignee | ||
Comment 17•4 years ago
|
||
If I catch anything (the NS_ERROR_UNEXPECTED really) and just dump it, then the test passes.
0:02.33 pid:306978 > Looking for background task at URI: resource:///modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
0:02.33 pid:306978 > xxxmagnus ex=[Exception... "File error: Not found" nsresult: "0x80520012 (NS_ERROR_FILE_NOT_FOUND)" location: "JS frame :: resource://gre/modules/BackgroundTasksManager.jsm :: findRunBackgroundTask :: line 82" data: no]console.debug: BackgroundTasksManager:
0:02.33 pid:306978 > Looking for background task at URI: resource://gre/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
0:02.33 pid:306978 > xxxmagnus ex=[Exception... "Unexpected error" nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)" location: "JS frame :: resource://gre/modules/BackgroundTasksManager.jsm :: findRunBackgroundTask :: line 82" data: no]console.debug: BackgroundTasksManager:
The failure is returned from here: https://searchfox.org/mozilla-central/rev/927e525f481a93a8f63d27a78ae6201e42b1b1fb/js/xpconnect/loader/mozJSComponentLoader.cpp#1238 - NS_ERROR_UNEXPECTED for
newEntry->resolvedURL=file:///home/magnus/Code/tb/mozilla/obj-x86_64-pc-linux-gnu/dist/bin/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
existingPath=resource:///modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
info.Key()=resource://gre/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
Comment 18•4 years ago
|
||
mccr8: can you explain what is supposed to happen in this case? In BackgroundTasksManager.jsm I iterate through possible module locations and use ChromeUtils.import(...) to try to import them. On Firefox, this appears to work fine, and modules that are not found return NS_ERROR_FILE_NOT_FOUND as I expect. However, on Thunderbird, we get an NS_ERROR_UNEXPECTED (see link above) for at least some modules that are not found, which suggests that the import code is modifying some data structure even though the load fails. Is there a bug here, or is my expectation for this API not correct?
| Comment hidden (Intermittent Failures Robot) |
Comment 20•4 years ago
|
||
Sorry for the delay. I'm not super familiar with this code so it took me a bit to get my head around what you were asking. :)
It looks like mozJSComponentLoader::Import() does mLocations.Put(), which adds the entry that gets looked up later. However, it looks like it can fail for many different reasons, but we don't remove the entry from mLocations if it does fail, so the second check will then fail at the earlier point as noted in comment 17. So I guess I'm not sure why it works in Firefox. Maybe in Firefox it always succeed the first time around the loop?
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 26•4 years ago
|
||
No failures since the 9th of February: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2021-02-04&endday=2021-02-11&tree=all&bug=168956
| Assignee | ||
Comment 27•4 years ago
|
||
I guess we just been lazy tagging it. It's still 100% happening.
| Comment hidden (Intermittent Failures Robot) |
| Assignee | ||
Comment 29•4 years ago
|
||
Some debugging (at https://searchfox.org/mozilla-central/rev/1b7ed77360ed02de111cf2098b2b48648c382fa1/js/xpconnect/loader/mozJSComponentLoader.cpp#1314)
For Thunderbird:
mLocations.Put(file:///home/magnus/Code/tb/mozilla/obj-x86_64-pc-linux-gnu/dist/bin/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm, resource:///modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm)
... and next call throws NS_ERROR_UNEXPECTED since it has the same key but the value is changing from
resource:///modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm to
resource://gre/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm
For Firefox:
mLocations.Put(file:///home/magnus/Code/tb/mozilla/obj-x86_64-pc-linux-gnu/dist/bin/browser/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm, resource:///modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm)
-> File not found (ok)
mLocations.Put(file:///home/magnus/Code/tb/mozilla/obj-x86_64-pc-linux-gnu/dist/bin/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm, resource://gre/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm)
-> File not found (ok)
mLocations.Put(file:///home/magnus/Code/tb/mozilla/obj-x86_64-pc-linux-gnu/_tests/modules/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm, resource://testing-common/backgroundtasks/BackgroundTask_backgroundtask_specific_pref.jsm)
Note the firefox dist/bin/browser/modules vs the thunderbird dist/bin/modules.
The NS_ERROR_UNEXPECTED doesn't happen for firefox because the mLocations key is different for all the calls.
I don't know if a dist/bin/browser location is expected or not.
| Comment hidden (Intermittent Failures Robot) |
| Assignee | ||
Comment 31•4 years ago
|
||
Clear the key from mLocations if it runs in into an error maybe?
| Comment hidden (Intermittent Failures Robot) |
Comment 33•4 years ago
|
||
Excellent debugging, Magnus -- I see the difference between browser/ and comm/ now. The expedient fix is to recognize that the app-specific path is the same as the toolkit path, and only check one. (Or just skip one of the checks on Thunderbird.) The deeper fix is to ensure we don't get into the bad state at all, by only filling mLocations on success, or clearing it on error, or whatever.
Can you investigate one of the simple fixes, which I will happily review and help land, and we'll file a ticket for the real issue separately?
| Assignee | ||
Comment 34•4 years ago
|
||
| Assignee | ||
Comment 35•4 years ago
|
||
Thanks, seems easiest to just do the real fix right away.
| Assignee | ||
Updated•4 years ago
|
| Assignee | ||
Updated•4 years ago
|
| Assignee | ||
Updated•4 years ago
|
Comment 36•4 years ago
|
||
Comment 37•4 years ago
|
||
| bugherder | ||
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Updated•4 years ago
|
Comment 40•4 years ago
|
||
Hi Magnus, should this be closed since there are no failures any longer?
| Assignee | ||
Comment 41•4 years ago
|
||
Yes indeed!
Description
•