Closed Bug 1460811 Opened 2 years ago Closed 1 year ago

re-implement XULStore using rkv

Categories

(Toolkit :: Storage, enhancement, P3)

enhancement

Tracking

()

RESOLVED FIXED
mozilla68
Tracking Status
firefox68 --- fixed

People

(Reporter: myk, Assigned: myk)

References

Details

Attachments

(1 file, 3 obsolete files)

We should re-implement XULStore using rkv to improve its reliability, reduce its complexity, and potentially improve startup performance.
Attached patch XULStore on rkv proof-of-concept (obsolete) — Splinter Review
Priority: -- → P3
Assignee: nobody → myk
Attachment #8975635 - Attachment is obsolete: true
Nika, I was reading through https://github.com/servo/servo/wiki/San-Francisco-Oxidation and noticed that you're concerned about lack of usage of the Rust XPCOM bindings that you recently introduced.

FWIW, the proof of concept in this bug uses them to retrieve the profile directory from the directory service <https://github.com/mykmelez/gecko/blob/a2f791d398c6b979fff011a059f668ca64827d8e/toolkit/components/xulstore/src/lib.rs#L76-L82>.

And a complete implementation might also implement nsIObserver (to update the directory on profile-after-change), as you demonstrate in xpcom/rust/gtest/xpcom/test.rs <https://searchfox.org/mozilla-central/rev/8384a6519437f5eefbe522196f9ddf5c8b1d3fb4/xpcom/rust/gtest/xpcom/test.rs#22-40>.

I also attempted to implement nsIStringEnumerator, although I ran into the limitation "Cannot #[derive(xpcom)] on a generic type" <https://github.com/mykmelez/gecko/blob/a2f791d398c6b979fff011a059f668ca64827d8e/toolkit/components/xulstore/src/lib.rs#L478-L523>.

Perhaps there are better ways to do these things, and we shouldn't be using the XPCOM bindings for them.  I'm relatively new to Rust, and I might be misusing it.  (Or overusing it.  Perhaps we shouldn't implement the XULStore API in Rust at all but rather in C++ that calls into the underlying Rust storage engine, so all code that interacts with XPCOM is in C++).

I just thought you should know that there are at least some potential consumers.  I'd also be happy to get feedback on whether you think this potential usage is a good use of those bindings.
Status: NEW → ASSIGNED
Attached file migrate XULStore to rkv (obsolete) —
Attachment #8983254 - Attachment is obsolete: true

@bgrins This is a synchronous version of a XULStore API using rkv. I've triggered tryserver builds for the base revision (central):

https://treeherder.mozilla.org/#/jobs?repo=try&revision=1000fdb9e613e4e779e88ccf494948dfd22a74a5

As well as the async version of the API:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=7e68b3b31a18460f4b0f44e37434f26c26220b4f

And this synchronous version:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=9e6a6d0fc0c0eba8522b6158e565f55712d1c3e5

I'll use their results to compare the two versions of the API.

(In reply to Myk Melez [:myk] [@mykmelez] from comment #5)

I'll use their results to compare the two versions of the API.

FYI, it generally takes 6 rebuilds on talos for perfherder to be give confident results. There may be other ways to get good data out of it, but what I typically do is use this syntax in all three configurations (base, sync version applied, async version applied):

./mach try fuzzy -q '/-talos-e10s' --rebuild 6

Then plug the revs into the originalRevision and newRevision GET params at: https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=&newProject=try&newRevision=&framework=1&showOnlyImportant=1

(In reply to Brian Grinstead [:bgrins] from comment #6)

(In reply to Myk Melez [:myk] [@mykmelez] from comment #5)

I'll use their results to compare the two versions of the API.

FYI, it generally takes 6 rebuilds on talos for perfherder to be give confident results. There may be other ways to get good data out of it, but what I typically do is use this syntax in all three configurations (base, sync version applied, async version applied):

./mach try fuzzy -q '/-talos-e10s' --rebuild 6

Then plug the revs into the originalRevision and newRevision GET params at: https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=&newProject=try&newRevision=&framework=1&showOnlyImportant=1

Hm, looking again at your pushes and it seems it did do the appropriate number of rebuilds, but I don't see any rebuilds specified in https://hg.mozilla.org/try/rev/7e68b3b31a18460f4b0f44e37434f26c26220b4f. Maybe you know something I don't, or try syntax got smarter and started automatically doing this for us? Anyway, disregard Comment 6 then.

(In reply to Brian Grinstead [:bgrins] from comment #6)

./mach try fuzzy -q '/-talos-e10s' --rebuild 6

Thanks, that's helpful! I didn't know about the --rebuild flag.

(In reply to Brian Grinstead [:bgrins] from comment #7)

Hm, looking again at your pushes and it seems it did do the appropriate number of rebuilds, but I don't see any rebuilds specified in https://hg.mozilla.org/try/rev/7e68b3b31a18460f4b0f44e37434f26c26220b4f. Maybe you know something I don't, or try syntax got smarter and started automatically doing this for us?

I manually retriggered Talos jobs via the "Trigger all Talos jobs" item in one of the Treeherder menus, which prompts for the number of times to run each job (and defaults to 6). That works reasonably well, but it'd be even easier to specify the number of rebuilds on the command line. I'll do that next time!

Attachment #9051203 - Attachment is obsolete: true
Component: General → Storage
Attachment #9054406 - Attachment description: migrate XULStore to rkv with synchronous API → migrate XULStore to rkv
Pushed by myk@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/2f8f0e53a7db
migrate XULStore to rkv r=bgrins,lina

Backed out for perma failures.

Push with failure: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&searchStr=windows%2C10%2Cx64%2Cdebug%2Cmochitests%2Ctest-windows10-64%2Fdebug-mochitest-a11y-e10s%2Cm%28a11y%29&revision=2f8f0e53a7dbb3f6d2259cfb0536a83ff84267ac&selectedJob=241258442

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=241258442&repo=autoland&lineNumber=6176

21:15:17 INFO - nsTraceRefcnt::DumpStatistics: 2368 entries
21:15:17 INFO - TEST-INFO | leakcheck | default leaked 1 CondVar
21:15:17 INFO - TEST-INFO | leakcheck | default leaked 1 Mutex
21:15:17 INFO - TEST-INFO | leakcheck | default leaked 1 ThreadEventTarget
21:15:17 INFO - TEST-INFO | leakcheck | default leaked 1 ThreadTargetSink
21:15:17 INFO - TEST-INFO | leakcheck | default leaked 3 nsTArray_base
21:15:17 INFO - TEST-INFO | leakcheck | default leaked 1 nsThread
21:15:17 INFO - TEST-UNEXPECTED-FAIL | leakcheck | default 496 bytes leaked (CondVar, Mutex, ThreadEventTarget, ThreadTargetSink, nsTArray_base, ...)
21:15:17 INFO -
21:15:17 INFO - leakcheck | Processing leak log file c:\users\task_1555618748\appdata\local\temp\tmpv486cs.mozrunner\runtests_leaks_plugin_pid10324.log
21:15:17 INFO -
21:15:17 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, plugin process 10324
21:15:17 INFO -
21:15:17 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
21:15:17 INFO - | | Per-Inst Leaked| Total Rem|
21:15:17 INFO - 0 |TOTAL | 68 0| 9357 0|
21:15:17 INFO -
21:15:17 INFO - nsTraceRefcnt::DumpStatistics: 95 entries
21:15:17 INFO - TEST-PASS | leakcheck | plugin no leaks detected!
21:15:17 INFO - leakcheck | Processing leak log file c:\users\task_1555618748\appdata\local\temp\tmpv486cs.mozrunner\runtests_leaks_plugin_pid5584.log
21:15:17 INFO -
21:15:17 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, plugin process 5584
21:15:17 INFO -
21:15:17 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
21:15:17 INFO - | | Per-Inst Leaked| Total Rem|
21:15:17 INFO - 0 |TOTAL | 62 0| 1388 0|
21:15:17 INFO -
21:15:17 INFO - nsTraceRefcnt::DumpStatistics: 93 entries
21:15:17 INFO - TEST-PASS | leakcheck | plugin no leaks detected!
21:15:17 INFO - runtests.py | Running tests: end.
21:15:17 INFO - Buffered messages finished
21:15:17 INFO - SUITE-END | took 274s
21:15:17 INFO - Return code: 0
21:15:17 ERROR - Got 1 unexpected statuses
21:15:17 INFO - TinderboxPrint: mochitest-a11y<br/>713/<em class="testfail">1</em>/0
21:15:17 WARNING - # TBPL WARNING #
21:15:17 WARNING - setting return code to 1
21:15:17 WARNING - The mochitest suite: a11y ran with return status: WARNING
21:15:17 INFO - Running post-action listener: _package_coverage_data
21:15:17 INFO - Running post-action listener: _resource_record_post_action
21:15:17 INFO - Running post-action listener: process_java_coverage_data
21:15:17 INFO - [mozharness: 2019-04-18 21:15:17.546000Z] Finished run-tests step (success)
21:15:17 INFO - Running post-run listener: _resource_record_post_run
21:15:17 INFO - Validating Perfherder data against Z:\task_1555618748\mozharness\external_tools\performance-artifact-schema.json
21:15:17 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 12.628421052631571}, {"name": "io_write_bytes", "value": 394473472}, {"name": "io.read_bytes", "value": 33558528}, {"name": "io_write_time", "value": 8}, {"name": "io_read_time", "value": 1}], "extraOptions": ["e10s", "taskcluster-c5.2xlarge"], "name": "mochitest.a11y.a11y.overall"}, {"subtests": [{"name": "time", "value": 2.555999994277954}, {"name": "cpu_percent", "value": 26.6875}], "name": "mochitest.a11y.a11y.install"}, {"subtests": [{"name": "time", "value": 0.0}], "name": "mochitest.a11y.a11y.stage-files"}, {"subtests": [{"name": "time", "value": 284.59100008010864}, {"name": "cpu_percent", "value": 12.4720744680851}], "name": "mochitest.a11y.a11y.run-tests"}]}
21:15:17 INFO - Total resource usage - Wall time: 286s; CPU: 12.0%; Read bytes: 33558528; Write bytes: 394473472; Read time: 1; Write time: 8
21:15:17 INFO - TinderboxPrint: CPU usage<br/>12.5%
21:15:17 INFO - TinderboxPrint: I/O read bytes / time<br/>33,558,528 / 1
21:15:17 INFO - TinderboxPrint: I/O write bytes / time<br/>394,473,472 / 8
21:15:17 INFO - TinderboxPrint: CPU idle<br/>2,002.1 (87.4%)
21:15:17 INFO - TinderboxPrint: CPU system<br/>84.7 (3.7%)
21:15:17 INFO - TinderboxPrint: CPU user<br/>203.8 (8.9%)
21:15:17 INFO - install - Wall time: 3s; CPU: 27.0%; Read bytes: 0; Write bytes: 11583488; Read time: 0; Write time: 0
21:15:17 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
21:15:17 INFO - run-tests - Wall time: 285s; CPU: 12.0%; Read bytes: 33419264; Write bytes: 372568064; Read time: 1; Write time: 6
21:15:17 WARNING - returning nonzero exit status 1
[taskcluster 2019-04-18T21:15:17.733Z] Exit Code: 1
[taskcluster 2019-04-18T21:15:17.733Z] User Time: 0s
[taskcluster 2019-04-18T21:15:17.733Z] Kernel Time: 15.625ms
[taskcluster 2019-04-18T21:15:17.733Z] Wall Time: 10m5.0306786s
[taskcluster 2019-04-18T21:15:17.733Z] Result: FAILED
[taskcluster 2019-04-18T21:15:17.733Z] === Task Finished ===
[taskcluster 2019-04-18T21:15:17.733Z] Task Duration: 10m5.0306786s
[taskcluster 2019-04-18T21:15:18.474Z] Uploading artifact public/logs/localconfig.json from file logs\localconfig.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2020-04-17T19:59:59.505Z
[taskcluster 2019-04-18T21:15:19.463Z] Uploading artifact public/test_info/a11y_errorsummary.log from file build\blobber_upload_dir\a11y_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2020-04-17T19:59:59.505Z
[taskcluster 2019-04-18T21:15:19.966Z] Uploading artifact public/test_info/a11y_raw.log from file build\blobber_upload_dir\a11y_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2020-04-17T19:59:59.505Z
[taskcluster 2019-04-18T21:15:20.978Z] Uploading artifact public/test_info/manifests.list from file build\blobber_upload_dir\manifests.list with content encoding "gzip", mime type "application/octet-stream" and expiry 2020-04-17T19:59:59.505Z
[taskcluster 2019-04-18T21:15:21.586Z] Uploading artifact public/test_info/resource-usage.json from file build\blobber_upload_dir\resource-usage.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2020-04-17T19:59:59.505Z
[taskcluster 2019-04-18T21:15:22.116Z] Uploading artifact public/test_info/system-info.log from file build\blobber_upload_dir\system-info.log with content encoding "gzip", mime type "text/plain" and expiry 2020-04-17T19:59:59.505Z
[taskcluster 2019-04-18T21:15:22.844Z] Uploading redirect artifact public/logs/live.log to URL https://queue.taskcluster.net/v1/task/eQN-XfUxTvqDPbwZmyOP8A/runs/0/artifacts/public/logs/live_backing.log with mime type "text/plain; charset=utf-8" and expiry 2020-04-17T19:59:59.505Z
[taskcluster:error] exit status 1

Backout: https://hg.mozilla.org/integration/autoland/rev/cf8038ca2da37288169690932880e737024d5afc

Flags: needinfo?(myk)
Pushed by myk@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/37054e6d6bbb
migrate XULStore to rkv r=bgrins,lina

The new implementation stores a static reference to a RefPtr<nsIThread>, which is what appeared to leak on shutdown. I fixed the apparent regression by adding an xpcom-shutdown observer that clears the static.

Flags: needinfo?(myk)

Backed out for marionette failures

Backout: https://hg.mozilla.org/integration/autoland/rev/8d72d3ac9677942ff8342aa39c61b7e6692c75a1

Failure push: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=37054e6d6bbb0285f9db1e7f30def75ba9b6521b

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=241492803&repo=autoland&lineNumber=1419

[task 2019-04-19T20:49:45.831Z] 20:49:45 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_cli_arguments.py TestCommandLineArguments.test_start_in_safe_mode
[task 2019-04-19T20:49:45.836Z] 20:49:45 INFO - 1555706985830 Marionette DEBUG Closed connection 9
[task 2019-04-19T20:49:45.837Z] 20:49:45 INFO - 1555706985833 Marionette DEBUG Accepted connection 10 from 127.0.0.1:52492
[task 2019-04-19T20:49:45.838Z] 20:49:45 INFO - 1555706985834 Marionette DEBUG 10 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2019-04-19T20:49:45.840Z] 20:49:45 INFO - 1555706985835 Marionette TRACE [2147483649] Frame script loaded
[task 2019-04-19T20:49:45.841Z] 20:49:45 INFO - 1555706985837 Marionette TRACE [2147483649] Frame script registered
[task 2019-04-19T20:49:45.845Z] 20:49:45 INFO - 1555706985841 Marionette DEBUG 10 <- [1,1,null,{"sessionId":"e7c40d16-562c-4736-8e90-6b8a4a06b0ee","capabilities":{"browserName":"firefox","browserVersion":"68.0a ... mp/tmpuM0l_I.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2019-04-19T20:49:45.847Z] 20:49:45 INFO - 1555706985843 Marionette DEBUG 10 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2019-04-19T20:49:45.849Z] 20:49:45 INFO - 1555706985843 Marionette DEBUG 10 <- [1,2,null,{"value":null}]
[task 2019-04-19T20:49:45.850Z] 20:49:45 INFO - 1555706985844 Marionette DEBUG 10 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2019-04-19T20:49:45.850Z] 20:49:45 INFO - 1555706985845 Marionette DEBUG 10 <- [1,3,null,{"value":null}]
[task 2019-04-19T20:49:45.854Z] 20:49:45 INFO - 1555706985847 Marionette DEBUG 10 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2019-04-19T20:49:45.859Z] 20:49:45 INFO - 1555706985847 Marionette DEBUG 10 <- [1,4,null,{"value":null}]
[task 2019-04-19T20:49:45.895Z] 20:49:45 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -safe-mode -profile /tmp/tmpuM0l_I.mozrunner
[task 2019-04-19T20:49:46.200Z] 20:49:46 INFO - 1555706986198 Marionette TRACE Received observer notification profile-after-change
[task 2019-04-19T20:49:46.268Z] 20:49:46 INFO - 1555706986266 Marionette TRACE Received observer notification command-line-startup
[task 2019-04-19T20:49:46.269Z] 20:49:46 INFO - 1555706986266 Marionette TRACE Received observer notification nsPref:changed
[task 2019-04-19T20:49:46.270Z] 20:49:46 INFO - 1555706986266 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false)
[task 2019-04-19T20:49:46.328Z] 20:49:46 INFO - 1555706986320 Marionette TRACE Received observer notification domwindowopened
[task 2019-04-19T20:49:46.329Z] 20:49:46 INFO - 1555706986321 Marionette TRACE Received observer notification toplevel-window-ready
[task 2019-04-19T20:49:46.414Z] 20:49:46 INFO - 1555706986410 Marionette TRACE Safe mode detected, supressing dialog
[task 2019-04-19T20:49:47.470Z] 20:49:47 INFO - 1555706987466 Marionette TRACE Received observer notification toplevel-window-ready
[task 2019-04-19T20:49:48.341Z] 20:49:48 INFO - ExceptionHandler::GenerateDump cloned child 1208
[task 2019-04-19T20:49:48.341Z] 20:49:48 INFO - ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2019-04-19T20:49:48.341Z] 20:49:48 INFO - ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2019-04-19T20:49:48.439Z] 20:49:48 INFO - Exiting due to channel error.
[task 2019-04-19T20:49:48.510Z] 20:49:48 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/FBYeHRoTR9SXacxXg4RVew/artifacts/public/build/target.crashreporter-symbols.zip
[task 2019-04-19T20:49:52.316Z] 20:49:52 INFO - mozcrash Copy/paste: /builds/worker/workspace/build/linux64-minidump_stackwalk /tmp/tmpuM0l_I.mozrunner/minidumps/2504c4e9-492c-5754-c252-670f7e6d1214.dmp /tmp/tmpBZ81ZR
[task 2019-04-19T20:49:57.617Z] 20:49:57 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/2504c4e9-492c-5754-c252-670f7e6d1214.dmp
[task 2019-04-19T20:49:57.617Z] 20:49:57 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/2504c4e9-492c-5754-c252-670f7e6d1214.extra
[task 2019-04-19T20:49:57.722Z] 20:49:57 INFO - PROCESS-CRASH | testing/marionette/harness/marionette_harness/tests/unit/test_cli_arguments.py TestCommandLineArguments.test_start_in_safe_mode | application crashed [@ GeckoCrash]
[task 2019-04-19T20:49:57.722Z] 20:49:57 INFO - Crash dump filename: /tmp/tmpuM0l_I.mozrunner/minidumps/2504c4e9-492c-5754-c252-670f7e6d1214.dmp
[task 2019-04-19T20:49:57.723Z] 20:49:57 INFO - Operating system: Linux
[task 2019-04-19T20:49:57.724Z] 20:49:57 INFO - 0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
[task 2019-04-19T20:49:57.725Z] 20:49:57 INFO - CPU: amd64
[task 2019-04-19T20:49:57.725Z] 20:49:57 INFO - family 6 model 62 stepping 4
[task 2019-04-19T20:49:57.725Z] 20:49:57 INFO - 2 CPUs
[task 2019-04-19T20:49:57.725Z] 20:49:57 INFO -
[task 2019-04-19T20:49:57.726Z] 20:49:57 INFO - GPU: UNKNOWN
[task 2019-04-19T20:49:57.726Z] 20:49:57 INFO -
[task 2019-04-19T20:49:57.726Z] 20:49:57 INFO - Crash reason: SIGSEGV /SEGV_MAPERR
[task 2019-04-19T20:49:57.726Z] 20:49:57 INFO - Crash address: 0x0
[task 2019-04-19T20:49:57.726Z] 20:49:57 INFO - Process uptime: not available
[task 2019-04-19T20:49:57.727Z] 20:49:57 INFO -
[task 2019-04-19T20:49:57.727Z] 20:49:57 INFO - Thread 42 (crashed)
[task 2019-04-19T20:49:57.727Z] 20:49:57 INFO - 0 libxul.so!GeckoCrash [nsAppRunner.cpp:37054e6d6bbb0285f9db1e7f30def75ba9b6521b : 5106 + 0xa]
[task 2019-04-19T20:49:57.727Z] 20:49:57 INFO - rax = 0x0000557145c13920 rdx = 0x00007fb10e067e12
[task 2019-04-19T20:49:57.728Z] 20:49:57 INFO - rcx = 0x0000000000010000 rbx = 0x000000000000002a
[task 2019-04-19T20:49:57.728Z] 20:49:57 INFO - rsi = 0x0000000000000079 rdi = 0x00007fb10e06801a
[task 2019-04-19T20:49:57.728Z] 20:49:57 INFO - rbp = 0x00007fb10e067e00 rsp = 0x00007fb10e067e00
[task 2019-04-19T20:49:57.728Z] 20:49:57 INFO - r8 = 0x00007fb10e06820a r9 = 0x0000000000000000
[task 2019-04-19T20:49:57.728Z] 20:49:57 INFO - r10 = 0x0000000000000000 r11 = 0x00007fb12c0df150
[task 2019-04-19T20:49:57.729Z] 20:49:57 INFO - r12 = 0x00007fb1214f9a70 r13 = 0x000000000000002a
[task 2019-04-19T20:49:57.729Z] 20:49:57 INFO - r14 = 0x0000000000000079 r15 = 0x0000000000000000
[task 2019-04-19T20:49:57.729Z] 20:49:57 INFO - rip = 0x00007fb11e050fae
[task 2019-04-19T20:49:57.729Z] 20:49:57 INFO - Found by: given as instruction pointer in context
[task 2019-04-19T20:49:57.730Z] 20:49:57 INFO - 1 libxul.so!gkrust_shared::panic_hook [lib.rs:37054e6d6bbb0285f9db1e7f30def75ba9b6521b : 241 + 0x9]
[task 2019-04-19T20:49:57.730Z] 20:49:57 INFO - rbx = 0x000000000000002a rbp = 0x00007fb121434c5b
[task 2019-04-19T20:49:57.730Z] 20:49:57 INFO - rsp = 0x00007fb10e067e10 r12 = 0x00007fb1214f9a70
[task 2019-04-19T20:49:57.731Z] 20:49:57 INFO - r13 = 0x000000000000002a r14 = 0x0000000000000079
[task 2019-04-19T20:49:57.731Z] 20:49:57 INFO - r15 = 0x0000000000000000 rip = 0x00007fb11f9d526c
[task 2019-04-19T20:49:57.731Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.731Z] 20:49:57 INFO - 2 libxul.so!core::ops::function::Fn::call [function.rs:91856ed52c58aa5ba66a015354d1cc69e9779bdf : 69 + 0x9]
[task 2019-04-19T20:49:57.732Z] 20:49:57 INFO - rbx = 0x0000000000000001 rbp = 0x00007fb1223b4860
[task 2019-04-19T20:49:57.732Z] 20:49:57 INFO - rsp = 0x00007fb10e068240 r12 = 0x00007fb1214f9a70
[task 2019-04-19T20:49:57.732Z] 20:49:57 INFO - r13 = 0x000000000000002a r14 = 0x0000000000000005
[task 2019-04-19T20:49:57.732Z] 20:49:57 INFO - r15 = 0x0000000000000000 rip = 0x00007fb11f9d5199
[task 2019-04-19T20:49:57.733Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.733Z] 20:49:57 INFO - 3 libxul.so!rust_panic_with_hook [panicking.rs:91856ed52c58aa5ba66a015354d1cc69e9779bdf : 482 + 0x6]
[task 2019-04-19T20:49:57.733Z] 20:49:57 INFO - rbx = 0x0000000000000001 rbp = 0x00007fb1223b4860
[task 2019-04-19T20:49:57.734Z] 20:49:57 INFO - rsp = 0x00007fb10e068250 r12 = 0x00007fb1214f9a70
[task 2019-04-19T20:49:57.734Z] 20:49:57 INFO - r13 = 0x000000000000002a r14 = 0x0000000000000005
[task 2019-04-19T20:49:57.734Z] 20:49:57 INFO - r15 = 0x0000000000000000 rip = 0x00007fb1201ebfd9
[task 2019-04-19T20:49:57.735Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.736Z] 20:49:57 INFO - 4 libxul.so!std::panicking::begin_panic [panicking.rs:91856ed52c58aa5ba66a015354d1cc69e9779bdf : 412 + 0x1d]
[task 2019-04-19T20:49:57.737Z] 20:49:57 INFO - rbx = 0x0000000000000000 rbp = 0x00007fb10e0684a0
[task 2019-04-19T20:49:57.737Z] 20:49:57 INFO - rsp = 0x00007fb10e068360 r12 = 0x00007fb1224f7188
[task 2019-04-19T20:49:57.738Z] 20:49:57 INFO - r13 = 0x00007fb1224f71b0 r14 = 0x00007fb1223c1e50
[task 2019-04-19T20:49:57.738Z] 20:49:57 INFO - r15 = 0x00007fb10e068608 rip = 0x00007fb11fab47d4
[task 2019-04-19T20:49:57.739Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.740Z] 20:49:57 INFO - 5 libxul.so!std::sync::once::Once::call_once::{{closure}} [once.rs:91856ed52c58aa5ba66a015354d1cc69e9779bdf : 220 + 0x48b]
[task 2019-04-19T20:49:57.740Z] 20:49:57 INFO - rbx = 0x0000000000000000 rbp = 0x00007fb10e0684a0
[task 2019-04-19T20:49:57.746Z] 20:49:57 INFO - rsp = 0x00007fb10e068380 r12 = 0x00007fb1224f7188
[task 2019-04-19T20:49:57.746Z] 20:49:57 INFO - r13 = 0x00007fb1224f71b0 r14 = 0x00007fb1223c1e50
[task 2019-04-19T20:49:57.747Z] 20:49:57 INFO - r15 = 0x00007fb10e068608 rip = 0x00007fb11fab8ecb
[task 2019-04-19T20:49:57.747Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.747Z] 20:49:57 INFO - 6 libxul.so!call_inner [once.rs:91856ed52c58aa5ba66a015354d1cc69e9779bdf : 387 + 0x9]
[task 2019-04-19T20:49:57.747Z] 20:49:57 INFO - rbx = 0x0000000000000000 rbp = 0x00007fb10e0684b2
[task 2019-04-19T20:49:57.747Z] 20:49:57 INFO - rsp = 0x00007fb10e0684b0 r12 = 0x0000000000000002
[task 2019-04-19T20:49:57.747Z] 20:49:57 INFO - r13 = 0x00007fb1224f71b0 r14 = 0x00007fb1223c1e50
[task 2019-04-19T20:49:57.748Z] 20:49:57 INFO - r15 = 0x00007fb10e068608 rip = 0x00007fb1201f977a
[task 2019-04-19T20:49:57.748Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.748Z] 20:49:57 INFO - 7 libxul.so!xulstore::statics::get_database [statics.rs:37054e6d6bbb0285f9db1e7f30def75ba9b6521b : 45 + 0x234]
[task 2019-04-19T20:49:57.748Z] 20:49:57 INFO - rbx = 0x00007fb10d272970 rbp = 0x00007fb10e0688b0
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - rsp = 0x00007fb10e068550 r12 = 0x00007fb10e068720
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - r13 = 0x00007fb1224f71f8 r14 = 0x0000000000000000
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - r15 = 0x0000000000000001 rip = 0x00007fb11fab42f7
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - 8 libxul.so!<xulstore::persist::PersistTask as moz_task::Task>::run [persist.rs:37054e6d6bbb0285f9db1e7f30def75ba9b6521b : 128 + 0xf6]
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - rbx = 0x00007fb10d272970 rbp = 0x00007fb10e0688b0
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - rsp = 0x00007fb10e0686a0 r12 = 0x00007fb10d3c2000
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - r13 = 0x00007fb1224f71f8 r14 = 0x0000000000000000
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - r15 = 0x0000000000000001 rip = 0x00007fb11fabc941
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - 9 libxul.so!moz_task::TaskRunnable::allocate::Run [lib.rs:37054e6d6bbb0285f9db1e7f30def75ba9b6521b : 82 + 0x31]
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - rbx = 0x00007fb10d08a8d0 rbp = 0x00007fb10e068d00
[task 2019-04-19T20:49:57.749Z] 20:49:57 INFO - rsp = 0x00007fb10e0688c0 r12 = 0x00007fb10a37fdc0
[task 2019-04-19T20:49:57.750Z] 20:49:57 INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000001
[task 2019-04-19T20:49:57.750Z] 20:49:57 INFO - r15 = 0x0000000000000001 rip = 0x00007fb11fe2a7a1
[task 2019-04-19T20:49:57.750Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.750Z] 20:49:57 INFO - 10 libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:37054e6d6bbb0285f9db1e7f30def75ba9b6521b : 1180 + 0x6]
[task 2019-04-19T20:49:57.750Z] 20:49:57 INFO - rbx = 0x0000000000000000 rbp = 0x00007fb10e068db0
[task 2019-04-19T20:49:57.750Z] 20:49:57 INFO - rsp = 0x00007fb10e0688e0 r12 = 0x00007fb10a37fdc0
[task 2019-04-19T20:49:57.750Z] 20:49:57 INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000001
[task 2019-04-19T20:49:57.750Z] 20:49:57 INFO - r15 = 0x0000000000000001 rip = 0x00007fb11e58948f
[task 2019-04-19T20:49:57.751Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.751Z] 20:49:57 INFO - 11 libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:37054e6d6bbb0285f9db1e7f30def75ba9b6521b : 333 + 0x12]
[task 2019-04-19T20:49:57.751Z] 20:49:57 INFO - rbx = 0x00007fb10a37fdc0 rbp = 0x00007fb10e068e00
[task 2019-04-19T20:49:57.751Z] 20:49:57 INFO - rsp = 0x00007fb10e068dc0 r12 = 0x00007fb10ee4ebc0
[task 2019-04-19T20:49:57.751Z] 20:49:57 INFO - r13 = 0x00007fb10a98fe80 r14 = 0x00007fb10a98fe80
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - r15 = 0x00007fb10a992000 rip = 0x00007fb11eb0e93d
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - 12 libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:37054e6d6bbb0285f9db1e7f30def75ba9b6521b : 454 + 0x4c]
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - rbx = 0x00007fb10d2729d0 rbp = 0x00007fb10e068ec0
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - rsp = 0x00007fb10e068e10 r12 = 0x00007fb10ee4ebc0
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - r13 = 0x00007fb10a992040 r14 = 0x00007fb10a37fdc0
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - r15 = 0x0000000000000001 rip = 0x00007fb11e970642
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - 13 libnspr4.so!_pt_root [ptthread.c:37054e6d6bbb0285f9db1e7f30def75ba9b6521b : 201 + 0x8]
[task 2019-04-19T20:49:57.752Z] 20:49:57 INFO - rbx = 0x0000000000000002 rbp = 0x00007fb10e068f10
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - rsp = 0x00007fb10e068ed0 r12 = 0x00007fb12bd589f8
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - r13 = 0x00007fb10a992040 r14 = 0x00007fb10e069700
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - r15 = 0x00007fb12bd14080 rip = 0x00007fb12d3c74a4
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - 14 libpthread-2.23.so + 0x76ba
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - rbx = 0x0000000000000000 rbp = 0x0000000000000000
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - rsp = 0x00007fb10e068f20 r12 = 0x0000000000000000
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - r13 = 0x00007ffcf9dd752f r14 = 0x0000000000040000
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - r15 = 0x00007fb10ec94e70 rip = 0x00007fb12cfc76ba
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - Found by: call frame info
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - 15 libc-2.23.so + 0x10741d
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - rsp = 0x00007fb10e068fc0 rip = 0x00007fb12c05041d
[task 2019-04-19T20:49:57.760Z] 20:49:57 INFO - Found by: stack scanning

Flags: needinfo?(myk)

I fixed the obvious issue that caused the test bustage and relanded.

Flags: needinfo?(myk)
Pushed by myk@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/76a363f06ebd
migrate XULStore to rkv r=bgrins,lina
Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla68

Is this expected to do more main thread I/O than the previous implementation? This is what I'm seeing in recent startup profiles: https://perfht.ml/2W3Ct2Z

Flags: needinfo?(myk)

(In reply to Florian Quèze [:florian] from comment #17)

Is this expected to do more main thread I/O than the previous implementation? This is what I'm seeing in recent startup profiles: https://perfht.ml/2W3Ct2Z

It isn't, so I've filed bug 1546838 to investigate the file I/O that shows up in that profile.

Flags: needinfo?(myk)
See Also: → 1584160
You need to log in before you can comment on or make changes to this bug.