XPIProvider.jsm imports OS.File during startup
Categories
(Toolkit Graveyard :: OS.File, task)
Tracking
(firefox87 fixed)
| Tracking | Status | |
|---|---|---|
| firefox87 | --- | fixed |
People
(Reporter: beth, Assigned: masterwayz)
References
Details
(Keywords: perf-alert)
Attachments
(1 file)
According to this startup profile, XPIProvider.jsm runs during startup and imports osfile.jsm. We should migrate this to the new IOUtils replacement for osfile.jsm when possible.
Stack:
(root) []
XREMain::XRE_main []
XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [libxul.so]
XREMain::XRE_mainRun() [libxul.so]
nsXREDirProvider::DoStartup() [libxul.so]
SharedStub [libxul.so]
PrepareAndDispatch [libxul.so]
XPCWrappedJS method call []
nsXPCWrappedJS::CallMethod(unsigned short, nsXPTMethodInfo const*, nsXPTCMiniVariant*) [libxul.so]
JS_CallFunctionValue(JSContext*, JS::Handle<JSObject*>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) [libxul.so]
js::RunScript []
observe [resource://gre/modules/addonManager.js:84:9]
startup [resource://gre/modules/AddonManager.jsm:3461:9]
startup [resource://gre/modules/AddonManager.jsm:638:9]
_startProvider [resource://gre/modules/AddonManager.jsm:574:16]
callProvider [resource://gre/modules/AddonManager.jsm:206:21]
js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [libxul.so]
Interpret(JSContext*, js::RunState&) [libxul.so]
js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [libxul.so]
js::fun_apply(JSContext*, unsigned int, JS::Value*) [libxul.so]
js::RunScript []
startup [resource://gre/modules/addons/XPIProvider.jsm:2424:9]
js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [libxul.so]
Interpret(JSContext*, js::RunState&) [libxul.so]
setupInstallLocations [resource://gre/modules/addons/XPIProvider.jsm:2221:23]
0xff4eaa5dcb3 []
js::jit::DoSpreadCallFallback(JSContext*, js::jit::BaselineFrame*, js::jit::ICCall_Fallback*, JS::Value*, JS::MutableHandle<JS::Value>) [libxul.so]
js::SpreadCallOperation(JSContext*, JS::Handle<JSScript*>, unsigned char*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::MutableHandle<JS::Value>) [libxul.so]
js::RunScript []
DirectoryLoc [resource://gre/modules/addons/XPIProvider.jsm:2222:25]
DirectoryLocation [resource://gre/modules/addons/XPIProvider.jsm:996:13]
> XPIStateLocation [resource://gre/modules/addons/XPIProvider.jsm:676:13]
js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [libxul.so]
Interpret(JSContext*, js::RunState&) [libxul.so]
js::NativeGetExistingProperty(JSContext*, JS::Handle<JSObject*>, JS::Handle<js::NativeObject*>, JS::Handle<js::Shape*>, JS::MutableHandle<JS::Value>) [libxul.so]
js::CallGetter(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::MutableHandle<JS::Value>) [libxul.so]
js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [libxul.so]
mozilla::dom::module_getter::ModuleGetter(JSContext*, unsigned int, JS::Value*) [libxul.so]
mozJSComponentLoader::Import(JSContext*, nsTSubstring<char> const&, JS::MutableHandle<JSObject*>, JS::MutableHandle<JSObject*>, bool) [libxul.so]
profiler_get_backtrace() [libxul.so]
Registers::SyncPopulate() [libxul.so]
Comment 1•5 years ago
|
||
There's one usage of OS.File in XPIProvider.jsm here.
This particular usage is concerning to me because:
- This is a side effect in a constructor
- This is async code in a constructor which isn't
thend orawaited on
I could replace the call to OS.File.mkDir with IOUtils.makeDirectory and leave the potentially uncaught promise exception, but refactoring this code to avoid this behaviour in the first place would be better (thought quite honestly, I'm a bit out of my depth trying to understand it).
Comment 2•5 years ago
|
||
Hey Kris, I was wondering if I could get some context about the XPIStateLocation ctor in question here. Right now this constructor is firing a promise off into the void and hoping it completes in time — otherwise, supposing the path doesn't exist by the time its required, an exception will be thrown elsewhere.
Since this code isn't broken, my current plan is to drop in replace OS.File.makeDir with a call to IOUtils.makeDirectory, and add a .catch for the returned promise that will log a warning if it fails. Is that ok?
It might be worth refactoring later though.
| Assignee | ||
Comment 4•5 years ago
|
||
Updated•5 years ago
|
Comment 7•5 years ago
|
||
Backed out changeset 3d61ae105362 (bug 1649590) for browser_startup_mainthreadio failures.
Backout link: https://hg.mozilla.org/integration/autoland/rev/f8d523ae0c5c8b6dd4b7be94149584a5c35292b7
Failure log: https://treeherder.mozilla.org/logviewer?job_id=322134985&repo=autoland&lineNumber=1830
...
[task 2020-11-18T02:34:55.565Z] 02:34:55 INFO - (PoisonIOInterposer) read - C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\xulstore\data.mdb
[task 2020-11-18T02:34:55.565Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner as many times as expected before opening first browser window -
[task 2020-11-18T02:34:55.565Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\cookies.sqlite-journal as many times as expected before opening first browser window -
[task 2020-11-18T02:34:55.566Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | write on C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\cookies.sqlite-journal as many times as expected before opening first browser window -
[task 2020-11-18T02:34:55.566Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\cookies.sqlite as many times as expected before opening first browser window -
[task 2020-11-18T02:34:55.566Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | read on C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\cookies.sqlite as many times as expected before opening first browser window -
[task 2020-11-18T02:34:55.566Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | write on C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\cookies.sqlite as many times as expected before opening first browser window -
[task 2020-11-18T02:34:55.569Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\cookies.sqlite-wal as many times as expected before opening first browser window -
[task 2020-11-18T02:34:55.569Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\extensions allowed 1 more times before opening first browser window -
[task 2020-11-18T02:34:55.570Z] 02:34:55 INFO - Buffered messages finished
[task 2020-11-18T02:34:55.570Z] 02:34:55 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/performance/browser_startup_mainthreadio.js | no main thread IO when we expected some during before opening first browser window: C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\extensions (ProfD:extensions) -
[task 2020-11-18T02:34:55.570Z] 02:34:55 INFO - Stack trace:
[task 2020-11-18T02:34:55.570Z] 02:34:55 INFO - chrome://mochikit/content/browser-test.js:test_ok:1304
[task 2020-11-18T02:34:55.570Z] 02:34:55 INFO - chrome://mochitests/content/browser/browser/base/content/test/performance/browser_startup_mainthreadio.js:null:881
[task 2020-11-18T02:34:55.570Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on Z:\task_1605665346\AppData\Roaming\Mozilla\Firefox allowed 1 more times before opening first browser window -
[task 2020-11-18T02:34:55.571Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | read on C:\Users\task_1605665346\AppData\Local\Temp\tmpcjk_gu.mozrunner\xulstore\data.mdb as many times as expected before opening first browser window -
[task 2020-11-18T02:34:55.572Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on Z:\task_1605665346\build\application\firefox\browser\features\doh-rollout@mozilla.org.xpi allowed 1 more times before opening first browser window -
[task 2020-11-18T02:34:55.573Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | close on Z:\task_1605665346\build\application\firefox\browser\features\doh-rollout@mozilla.org.xpi allowed 2 more times before opening first browser window -
[task 2020-11-18T02:34:55.574Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on Z:\task_1605665346\build\application\firefox\browser\features\formautofill@mozilla.org.xpi allowed 1 more times before opening first browser window -
[task 2020-11-18T02:34:55.574Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | close on Z:\task_1605665346\build\application\firefox\browser\features\formautofill@mozilla.org.xpi allowed 2 more times before opening first browser window -
[task 2020-11-18T02:34:55.575Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on Z:\task_1605665346\build\application\firefox\browser\features\screenshots@mozilla.org.xpi allowed 1 more times before opening first browser window -
[task 2020-11-18T02:34:55.576Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | close on Z:\task_1605665346\build\application\firefox\browser\features\screenshots@mozilla.org.xpi allowed 2 more times before opening first browser window -
[task 2020-11-18T02:34:55.577Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on Z:\task_1605665346\build\application\firefox\browser\features\webcompat-reporter@mozilla.org.xpi allowed 1 more times before opening first browser window -
[task 2020-11-18T02:34:55.577Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | close on Z:\task_1605665346\build\application\firefox\browser\features\webcompat-reporter@mozilla.org.xpi allowed 2 more times before opening first browser window -
[task 2020-11-18T02:34:55.577Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | stat on Z:\task_1605665346\build\application\firefox\browser\features\webcompat@mozilla.org.xpi allowed 1 more times before opening first browser window -
[task 2020-11-18T02:34:55.578Z] 02:34:55 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_mainthreadio.js | close on Z:\task_1605665346\build\application\firefox\browser\features\webcompat@mozilla.org.xpi allowed 2 more times before opening first browser window -
[task 2020-11-18T02:34:55.581Z] 02:34:55 INFO - known main thread IO paths during before first paint:
[task 2020-11-18T02:34:55.581Z] 02:34:55 INFO - Z:\task_1605665346\AppData\Local\Mozilla\updates\AF27AA334654FCD0 - condition: true, stat: 1, listedPath: OldUpdRootD:
[task 2020-11-18T02:34:55.581Z] 02:34:55 INFO - C:\ProgramData\Mozilla\updates\AF27AA334654FCD0\updates\0\update.status - condition: true, stat: 1, listedPath: UpdRootD:updates/0/update.status
[task 2020-11-18T02:34:55.581Z] 02:34:55 INFO - Z:\task_1605665346\AppData\Roaming\Mozilla - condition: true, stat: 1, listedPath: UserPlugins.parent:
[task 2020-11-18T02:34:55.581Z] 02:34:55 INFO - Z:\task_1605665346\build\application\firefox\distribution\distribution.ini - condition: true, stat: 1, listedPath: XREAppDist:distribution.ini
[task 2020-11-18T02:34:55.581Z] 02:34:55 INFO - *Fonts\StaticCache.dat - condition: true, ignoreIfUnused: true, read: 1, listedPath: *Fonts/StaticCache.dat
[task 2020-11-18T02:34:55.582Z] 02:34:55 INFO - C:\windows\system32\spool\drivers\color\* - condition: true, read: 1, listedPath: SysD:spool/drivers/color/*
[task 2020-11-18T02:34:55.582Z] 02:34:55 INFO - Z:\task_1605665346\AppData\Roaming\Mozilla\Firefox - ignoreIfUnused: true, condition: true, stat: 1, listedPath: UAppData:
...
| Assignee | ||
Comment 8•5 years ago
|
||
Been working on the issue with mixedpuppy. Hopefully the new revision fixes it.
Comment 10•5 years ago
|
||
| bugherder | ||
Comment 11•5 years ago
|
||
(In reply to Pulsebot from comment #5)
Pushed by emalysz@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/3d61ae105362
Convert XPIProvider.jsm to use IOUtils r=emalysz,mixedpuppy
== Change summary for alert #27823 (as of Mon, 23 Nov 2020 12:11:00 GMT) ==
Regressions:
| Ratio | Suite | Test | Platform | Options | Absolute values (old vs new) |
|---|---|---|---|---|---|
| 10% | ts_paint_webext | ts_paint_webext | windows10-64-shippable-qr | e10s stylo webrender-sw | 380.63 -> 418.08 |
| 6% | ts_paint_webext | ts_paint_webext | windows10-64-shippable-qr | e10s stylo webrender-sw | 400.25 -> 423.92 |
For up to date results, see: https://treeherder.mozilla.org/perfherder/alerts?id=27823
Comment 12•5 years ago
|
||
(In reply to Bogdan Tara[:bogdan_tara | bogdant] from comment #7)
Backed out changeset 3d61ae105362 (bug 1649590) for browser_startup_mainthreadio failures.
Backout link: https://hg.mozilla.org/integration/autoland/rev/f8d523ae0c5c8b6dd4b7be94149584a5c35292b7
== Change summary for alert #27824 (as of Mon, 23 Nov 2020 12:15:10 GMT) ==
Improvements:
| Ratio | Suite | Test | Platform | Options | Absolute values (old vs new) |
|---|---|---|---|---|---|
| 7% | ts_paint_webext | ts_paint_webext | windows10-64-shippable-qr | e10s stylo webrender-sw | 406.33 -> 379.42 |
For up to date results, see: https://treeherder.mozilla.org/perfherder/alerts?id=27824
Updated•5 years ago
|
Comment 13•5 years ago
|
||
Backed out for causing Bug 1679252
backout: https://hg.mozilla.org/integration/autoland/rev/a60fbae9e78163ee36e0c89efe704e22eebd3d72
Comment 14•5 years ago
|
||
Backout merged: https://hg.mozilla.org/mozilla-central/rev/a60fbae9e781
Comment 15•5 years ago
|
||
(In reply to Natalia Csoregi [:nataliaCs] from comment #13)
Backed out for causing Bug 1679252
backout: https://hg.mozilla.org/integration/autoland/rev/a60fbae9e78163ee36e0c89efe704e22eebd3d72
== Change summary for alert #27886 (as of Sun, 29 Nov 2020 15:23:41 GMT) ==
Regressions:
| Ratio | Suite | Test | Platform | Options | Absolute values (old vs new) |
|---|---|---|---|---|---|
| 16% | ts_paint_webext | ts_paint_webext | linux64-shippable-qr | e10s stylo webrender-sw | 200.67 -> 232.42 |
| 15% | ts_paint | ts_paint | linux64-shippable-qr | e10s stylo webrender-sw | 201.75 -> 232.75 |
| 13% | ts_paint_webext | ts_paint_webext | linux64-shippable-qr | e10s stylo webrender | 219.17 -> 248.67 |
| 12% | ts_paint | ts_paint | linux64-shippable-qr | e10s stylo webrender | 217.71 -> 243.92 |
| 4% | startup_about_home_paint_realworld_webextensions | startup_about_home_paint_realworld_webextensions | linux64-shippable | e10s stylo | 555.50 -> 575.17 |
Improvements:
| Ratio | Suite | Test | Platform | Options | Absolute values (old vs new) |
|---|---|---|---|---|---|
| 2% | startup_about_home_paint_realworld_webextensions | startup_about_home_paint_realworld_webextensions | linux64-shippable-qr | e10s stylo webrender | 858.46 -> 840.25 |
For up to date results, see: https://treeherder.mozilla.org/perfherder/alerts?id=27886
Comment 16•5 years ago
|
||
Comment 17•5 years ago
|
||
Backed out for failures on browser_content_sandbox_fs.js
backout: https://hg.mozilla.org/integration/autoland/rev/642b19199dd4808ae90394b36ebeafd2d2a503d9
failure log: https://treeherder.mozilla.org/logviewer?job_id=328946371&repo=autoland&lineNumber=23221
[task 2021-02-05T02:11:49.952Z] 02:11:49 INFO - TEST-PASS | security/sandbox/test/browser_content_sandbox_fs.js | directory list is empty (/proc/self/fd) -
[task 2021-02-05T02:11:49.953Z] 02:11:49 INFO - Buffered messages finished
[task 2021-02-05T02:11:49.954Z] 02:11:49 INFO - TEST-UNEXPECTED-FAIL | security/sandbox/test/browser_content_sandbox_fs.js | reading extensions dir from a web process is allowed (/tmp/tmpjWBLbz.mozrunner/extensions) -
[task 2021-02-05T02:11:49.954Z] 02:11:49 INFO - Stack trace:
[task 2021-02-05T02:11:49.955Z] 02:11:49 INFO - chrome://mochikit/content/browser-test.js:test_ok:1323
[task 2021-02-05T02:11:49.955Z] 02:11:49 INFO - chrome://mochitests/content/browser/security/sandbox/test/browser_content_sandbox_fs.js:testFileAccess:626
[task 2021-02-05T02:11:49.956Z] 02:11:49 INFO - TEST-PASS | security/sandbox/test/browser_content_sandbox_fs.js | reading chrome dir from a web process is allowed (/tmp/tmpjWBLbz.mozrunner/chrome) -
[task 2021-02-05T02:11:49.957Z] 02:11:49 INFO - TEST-PASS | security/sandbox/test/browser_content_sandbox_fs.js | reading cookies file from a web process is blocked (/tmp/tmpjWBLbz.mozrunner/cookies.sqlite) -
[task 2021-02-05T02:11:49.960Z] 02:11:49 INFO - TEST-PASS | security/sandbox/test/browser_content_sandbox_fs.js | reading cookies file from a file process is allowed (/tmp/tmpjWBLbz.mozrunner/cookies.sqlite) -
[task 2021-02-05T02:11:49.961Z] 02:11:49 INFO - Leaving test bound testFileAccess
Comment 18•5 years ago
|
||
Comment 19•5 years ago
|
||
| bugherder | ||
| Assignee | ||
Updated•5 years ago
|
| Comment hidden (obsolete) |
Updated•3 years ago
|
Description
•