1488786 - [gdocs] Missing JIT IC for GetElem on sparse elements

Status: RESOLVED FIXED

(Core :: JavaScript Engine: JIT, enhancement, P1)

Description

[Ted Campbell [:tcampbell]]

Profile: https://perf-html.io/public/af86f00f11f7c7719ed6018a24dab7a86ecc507b/calltree/?globalTrackOrder=0-1-2-3-4&hiddenGlobalTracks=0-1-2-3&hiddenLocalTracksByPid=2573-0&invertCallstack&localTrackOrderByPid=2573-0~&range=3.3981_8.3281~4.3286_7.4642&thread=5&v=3

CACHEIR_LOG example:

> {
>   "name":"GetElem",
>   "file":"https://docs.google.com/static/document/client/js/2349105360-kix_main_i18n_integrated_kix_core.js",
>   "mode":1,
>   "line":1620,
>   "column":134,
>   "pc":"158db35c561",
>   "base":{
>     "type":"Array",
>     "value":"158d7a634d0 (shape: 158ec982290)"
>   },
>   "property":{
>     "type":"number",
>     "value":"164252"
>   }
> },

Comment 1

[Randell Jesup [:jesup] (needinfo me)]

array_push() uses 25ms of 220ms in a keypress event in bug 1488435 (chrome takes around 50-60ms for keypress events there), and 13ms of 22ms in the final stage where it's calling u.remove() (Chrome takes 7ms for that phase).

Comment 2

[Matthew Gaudet (he/him) [:mgaudet]]

From conversation with evilpie on IRC: 

It's likely this is actually an IC miss on a non-dense array. I see a similar miss on a regular int32 argument here: 

> {
>   "name":"GetElem",
>   "file":"../jit-test/tests/cacheir/getelem-number.js",
>   "mode":0,
>   "line":9,
>   "column":4,
>   "pc":"10a031516",
>   "base":{
>     "type":"Array",
>     "value":"109b003a0 (shape: 109cafbf0)"
>   },
>   "property":{
>     "type":"int32",
>     "value":17
>   }
> },


and Tom pointed out that we are able to do Numeric indexes for dense arrays here [1]


[1]: https://searchfox.org/mozilla-central/source/js/src/jit/CacheIR.cpp#3035-3056

Comment 3

[Matthew Gaudet (he/him) [:mgaudet]]

Attachment: Bug 1488786 - Add an IC for sparse array element access r?jandem

Comment 4

[Matthew Gaudet (he/him) [:mgaudet]]

Attachment: Bug 1488786 - Correct Ion Type Barriers around sparse array indexes r=jandem

Comment 5

[Matthew Gaudet (he/him) [:mgaudet]]

Attachment: Bug 1488786 - Correct Ion Barrier selection logic for getElem caches w.r.t. prototype reads r?jandem

Comment 6

[Jan de Mooij [:jandem]]

Comment on attachment 9009218 [details]
Bug 1488786 - Correct Ion Barrier selection logic for getElem caches w.r.t. prototype reads r?jandem

Jan de Mooij [:jandem] has approved the revision.

Comment 7

[Jan de Mooij [:jandem]]

Comment on attachment 9008537 [details]
Bug 1488786 - Add an IC for sparse array element access r?jandem

Jan de Mooij [:jandem] has approved the revision.

Comment 8

[Matthew Gaudet (he/him) [:mgaudet]]

Pulsebot seems to be down right now: 

Pushed: 

https://hg.mozilla.org/integration/autoland/rev/e0f7882e7316
https://hg.mozilla.org/integration/autoland/rev/6c5b95f8154e

Comment 9

[Natalia Csoregi [:nataliaCs]]

Backed out for raptor gdocs failures

backout:  https://hg.mozilla.org/integration/autoland/rev/8bf660646ca6f18a269af9550c23d34a87140579

push: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=6c5b95f8154e63b67542892a8431370e5ee58b6a

failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=201251393&repo=autoland&lineNumber=680

11:46:11     INFO -  raptor-main starting firefox
11:46:11     INFO -  Application command: /Users/cltbld/tasks/task_1537814329/build/application/Firefox Nightly.app/Contents/MacOS/firefox -foreground -profile /var/folders/_6/fvrv10k16g34qs2w99kytz1800000w/T/tmpGBhsmk.mozrunner
11:46:14     INFO -  127.0.0.1 - - [24/Sep/2018 11:46:14] "GET /raptor-google-sheets-firefox.json HTTP/1.1" 200 -
11:46:14     INFO -  raptor-control-server reading test settings from raptor-google-sheets-firefox.json
11:46:14     INFO -  raptor-control-server sent test settings to web ext runner
11:46:14     INFO -  127.0.0.1 - - [24/Sep/2018 11:46:14] "POST / HTTP/1.1" 200 -
11:46:14     INFO -  raptor-control-server received webext_status: * pausing 30 seconds to let browser settle... *
11:46:44     INFO -  127.0.0.1 - - [24/Sep/2018 11:46:44] "POST / HTTP/1.1" 200 -
11:46:44     INFO -  raptor-control-server received webext_status: running 25 pagecycles of https://docs.google.com/spreadsheets/d/1jT9qfZFAeqNoOK97gruc34Zb7y_Q-O_drZ8kSXT-4D4/edit?usp=sharing
11:46:45     INFO -  127.0.0.1 - - [24/Sep/2018 11:46:45] "POST / HTTP/1.1" 200 -
11:46:45     INFO -  raptor-control-server received webext_status: begin pagecycle 1
11:46:50     INFO -  127.0.0.1 - - [24/Sep/2018 11:46:50] "POST / HTTP/1.1" 200 -
11:46:50     INFO -  raptor-control-server received webext_status: begin pagecycle 2
11:46:51     INFO -  PID 603 | [Parent 603, Gecko_IOThread] WARNING: pipe error: Broken pipe: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 729
11:46:51     INFO -  PID 603 | ###!!! [Parent][MessageChannel] Error: (msgtype=0x4C0019,name=PHttpChannel::Msg_DeleteSelf) Channel error: cannot send/recv
11:46:51     INFO -  PID 603 | ###!!! [Parent][MessageChannel] Error: (msgtype=0x190084,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
11:47:50     INFO -  127.0.0.1 - - [24/Sep/2018 11:47:50] "POST / HTTP/1.1" 200 -
11:47:50     INFO -  raptor-control-server received webext_raptor-page-timeout: [u'raptor-google-sheets-firefox', u'https://docs.google.com/spreadsheets/d/1jT9qfZFAeqNoOK97gruc34Zb7y_Q-O_drZ8kSXT-4D4/edit?usp=sharing']
11:47:50     INFO -  127.0.0.1 - - [24/Sep/2018 11:47:50] "POST / HTTP/1.1" 200 -
11:47:50     INFO -  raptor-control-server received webext_status: __raptor_shutdownBrowser
11:47:50     INFO -  raptor-control-server shutting down browser (pid: 603)
11:48:07     INFO -  mozcrash Copy/paste: /Users/cltbld/tasks/task_1537814329/build/macosx64-minidump_stackwalk /var/folders/_6/fvrv10k16g34qs2w99kytz1800000w/T/tmpGBhsmk.mozrunner/minidumps/1DF6E1F2-21DB-453C-98B0-996982D7C09D.dmp /var/folders/_6/fvrv10k16g34qs2w99kytz1800000w/T/tmpDbS_go
11:48:10     INFO -  mozcrash Saved minidump as /Users/cltbld/tasks/task_1537814329/build/blobber_upload_dir/1DF6E1F2-21DB-453C-98B0-996982D7C09D.dmp
11:48:10     INFO -  mozcrash Saved app info as /Users/cltbld/tasks/task_1537814329/build/blobber_upload_dir/1DF6E1F2-21DB-453C-98B0-996982D7C09D.extra
11:48:10     INFO -  PROCESS-CRASH | runner.py | application crashed [@ 0x11be34651b27]
11:48:10     INFO -  Crash dump filename: /var/folders/_6/fvrv10k16g34qs2w99kytz1800000w/T/tmpGBhsmk.mozrunner/minidumps/1DF6E1F2-21DB-453C-98B0-996982D7C09D.dmp
11:48:10     INFO -  Operating system: Mac OS X
11:48:10     INFO -                    10.10.5 14F27
11:48:10     INFO -  CPU: amd64
11:48:10     INFO -       family 6 model 69 stepping 1
11:48:10     INFO -       4 CPUs
11:48:10     INFO -  GPU: UNKNOWN
11:48:10     INFO -  Crash reason:  EXC_BAD_ACCESS / EXC_I386_GPFLT
11:48:10     INFO -  Crash address: 0x0
11:48:10     INFO -  Process uptime: 39 seconds
11:48:10     INFO -  Thread 34 (crashed)
11:48:10     INFO -   0  0x11be34651b27
11:48:10     INFO -      rax = 0x0000000000000901   rdx = 0x0007800000000000
11:48:10     INFO -      rcx = 0x0000000000000488   rbx = 0x000000013d3686e0
11:48:10     INFO -      rsi = 0x0000000000000002   rdi = 0x0000000000000000
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fc870
11:48:10     INFO -       r8 = 0x00000001317fc7b0    r9 = 0x0000000131948740
11:48:10     INFO -      r10 = 0x00000001317fc6e0   r11 = 0xfffe000000000000
11:48:10     INFO -      r12 = 0x0000000131a227e0   r13 = 0x0000000000000488
11:48:10     INFO -      r14 = 0x000000013d3d1118   r15 = 0x0000000131a71700
11:48:10     INFO -      rip = 0x000011be34651b27
11:48:10     INFO -      Found by: given as instruction pointer in context
11:48:10     INFO -   1  XUL + 0x51b479a
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fc920
11:48:10     INFO -      rip = 0x000000010c29479a
11:48:10     INFO -      Found by: stack scanning
11:48:10     INFO -   2  XUL + 0x4f51e20
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fc970
11:48:10     INFO -      rip = 0x000000010c031e20
11:48:10     INFO -      Found by: stack scanning
11:48:10     INFO -   3  XUL + 0x54c54df
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fca60
11:48:10     INFO -      rip = 0x000000010c5a54df
11:48:10     INFO -      Found by: stack scanning
11:48:10     INFO -   4  XUL + 0x4f54600
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fca80
11:48:10     INFO -      rip = 0x000000010c034600
11:48:10     INFO -      Found by: stack scanning
11:48:10     INFO -   5  XUL + 0x54c8f46
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fcad0
11:48:10     INFO -      rip = 0x000000010c5a8f46
11:48:10     INFO -      Found by: stack scanning
11:48:10     INFO -   6  XUL + 0x4e90052
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fcb00
11:48:10     INFO -      rip = 0x000000010bf70052
11:48:10     INFO -      Found by: stack scanning
11:48:10     INFO -   7  XUL + 0x4e8fe11
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fcb40
11:48:10     INFO -      rip = 0x000000010bf6fe11
11:48:10     INFO -      Found by: stack scanning
11:48:10     INFO -   8  XUL + 0x54cd768
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fcb80
11:48:10     INFO -      rip = 0x000000010c5ad768
11:48:10     INFO -      Found by: stack scanning
11:48:10     INFO -   9  XUL + 0x54ce95d
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fcc30
11:48:10     INFO -      rip = 0x000000010c5ae95d
11:48:10     INFO -      Found by: stack scanning
11:48:10     INFO -  10  XUL + 0x549acda
11:48:10     INFO -      rbp = 0xfff8800000000488   rsp = 0x00000001317fcce0
11:48:10     INFO -      rip = 0x000000010c57acda
11:48:10     INFO -      Found by: stack scanning

Comment 10

[Matthew Gaudet (he/him) [:mgaudet]]

Running a debug linux build I can see I'm getting yet-another 

    Assertion failure: Infallible unbox type mismatch, at /builds/worker/workspace/build/src/js/src/jit/MacroAssembler.cpp:2080

Investigating more -- last time tho this was a TI issue. The good news is I've repro'd under rr. 

Will get into this more later.

Comment 11

[Matthew Gaudet (he/him) [:mgaudet]]

So far I haven't gotten an RR log with quite enough debug information (my build with with the default --enable-optimize had a lot optimized out); will do yet another browser build during lunch that might do the trick. 

In the mean time, here's what I can say: 

When I first posted the patch on Phabricator, I mentioned a test that was failing [1]. Subsequent investigation showed that a read off the prototype was happening, which violated assumptions getElemAddCache had around when a type barrier would be required. 

The solution to that bug was D5802 [2], which borrowed the same logic getPropAddCache was using for property reads off the prototype to ensure the type barrier was being injected for that case. 

What I am seeing now in the Raptor Google Docs test document is yet another missing type barrier in getElemAddCache, resulting in a failed Infallible unbox type mismatch.So far I don't have enough information to say what check that would produce a type barrier as expected we are missing here. 

In terms of parallels to the getPropAddCache case, I do note that getPropAddCache has yet another case that forces a barrier [3], related to getters though I don't think that applies to elements (right?). 

I'm tempted to say that all cached element lookups should have a barrier, but that would just be fixing the proximate cause without understanding the root case. 

One option we could perhaps explore is getting fuzzing support on this change to see if they can drop out minimized test-case or three to help determination; doing this work on gdocs is not particularly quick. 


[1]: https://phabricator.services.mozilla.com/D5706#126974 
[2]: https://phabricator.services.mozilla.com/D5802
[3]: https://searchfox.org/mozilla-central/rev/881a3c5664ede5e08ee986d76433bc5c4b5680e6/js/src/jit/IonBuilder.cpp#11930-11934

Comment 12

[Matthew Gaudet (he/him) [:mgaudet]]

(PS: If anyone has tips for figuring out what I'm missing, pass them along :D! )

Comment 13

[Matthew Gaudet (he/him) [:mgaudet]]

Ok: Some more investigation leads to two direct questions: 

In getElemAddCache, the types computed here [1] by `bytecodeTypes()` seem confident that the knownMIrType() is MIRType::Object. 

The infallible unbox that fails indicates the actual type tag on the object is JSVAL_TAG_UNDEFINED, not object as the generated unbox expects. 

Question A) Do the byteCodeTypes include type information derived by Baseline ICs? 

In this section, we determine that a hole check is required [2]. 

Question B) When there's a required hole check, doesn't that directly imply that we'd need a type barrier, and if so, why not? 

I would ni? nbp, as I think he wrote the original versions of this code in Bug 840696, but he's not taking ni? right now, so sorry Jan, you're next on my TI question list (please feel free to punt if you're busy, this isn't really urgent) 

[1]: https://searchfox.org/mozilla-central/rev/881a3c5664ede5e08ee986d76433bc5c4b5680e6/js/src/jit/IonBuilder.cpp#8989
[2]: https://searchfox.org/mozilla-central/rev/881a3c5664ede5e08ee986d76433bc5c4b5680e6/js/src/jit/IonBuilder.cpp#9031-9038

Comment 14

[Ted Campbell [:tcampbell]]

So, one problem is that in [1] we rely on GETELEM to always set the negative index flag. This used to be fine when we guaranteed that only the FB would handle these cases. When attaching your IC you probably need always noteNegativeIndex(). (insert rant about BaselineInspector here). In [2] there is an example of how this fix can be approached.

[1] https://searchfox.org/mozilla-central/rev/ffe6eaf2f032e58ec3b0650a87df2c62ae4ca441/js/src/jit/BaselineIC.cpp#1782-1787
[2] https://searchfox.org/mozilla-central/rev/ffe6eaf2f032e58ec3b0650a87df2c62ae4ca441/js/src/jit/BaselineIC.cpp#2003-2005

Comment 15

[Ted Campbell [:tcampbell]]

(In reply to Matthew Gaudet (he/him) [:mgaudet] from comment #13)
> Question A) Do the byteCodeTypes include type information derived by
> Baseline ICs? 

The bytecodeTypes are covered by TypeMonitor ICs. They track the type of result of GetElem. They do not care about if this is sparse or dense since the jsid doesn't factor in. These are StackTypeSets. 


> Question B) When there's a required hole check, doesn't that directly imply
> that we'd need a type barrier, and if so, why not? 

One can have holes without sparse indices (eg [1,,3,4]). In this case, I believe it is conceivable to have a hole check but the type barrier elided (because we installed a constraint hook on OBJECT_FLAG_SPARSE_INDEXES).

Comment 16

[Jan de Mooij [:jandem]]

(In reply to Matthew Gaudet (he/him) [:mgaudet] from comment #11)
> In terms of parallels to the getPropAddCache case, I do note that
> getPropAddCache has yet another case that forces a barrier [3], related to
> getters though I don't think that applies to elements (right?). 

You could have something like |var o = {get 0() { ... }};|. However I'd expect your sparse index check to handle that, unless... this is an int32_t index < 0 because those are not stored in integer jsids and so the sparse index flag doesn't account for it. So that's something you could try to write a testcase for and see if a barrier is needed here (it should be):

var o = {};
Object.defineProperty(o, "-11", {get: function() { return 2; }}) 
assertEq(o[-11], 2);

Alternative is to log all indexes you see in your VMFunction and see if this shows up on gdocs.

> I'm tempted to say that all cached element lookups should have a barrier,
> but that would just be fixing the proximate cause without understanding the
> root case.

I agree. Always requiring a barrier might make sense but it would be nice to understand the bug.

Comment 17

[Jan de Mooij [:jandem]]

(Considering these two potential issues with index < 0, maybe we should guard >= 0 when attaching the stub and before calling the VM function?)

Comment 18

[Matthew Gaudet (he/him) [:mgaudet]]

Ok, so I can pretty confidently say the google docs case is not a negative index problem. 

I started by logging the indexes while loading the Raptor Google Docs page: No negative numbers. I also double checked by using the (currently unused, surprisingly) GuardIndexIsNonNegative op to ensure we fail out of the IC on negative indexes, and we still crash the tab. 

(I hedge mildly as I have yet to write / modify a test case as suggested; it is quite possible that in the -general case- we do still need to be specially considering/handling negative indexes). 

(In reply to Ted Campbell [:tcampbell] from comment #15)
> One can have holes without sparse indices (eg [1,,3,4]). In this case, I
> believe it is conceivable to have a hole check but the type barrier elided
> (because we installed a constraint hook on OBJECT_FLAG_SPARSE_INDEXES).

That's a good point, and definitely helps answer my question. Is it possible to assert that hook exists somehow?

Comment 19

[Matthew Gaudet (he/him) [:mgaudet]]

Attachment: bug1488786-2.js

After some chat on IRC today, I finally stopped being slow and looked -what path the runtime helper took just before the failure-. 

As a result of that, I've managed to get together a reduced test case! 

(I'm going to be gone tomorrow around 11am, so I don't think I'll get a fix in, but I wanted to post the reduced TC) 
    
    $  ./dist/bin/js --no-threads --ion-eager ../jit-test/tests/cacheir/bug1488786-2.js
    Assertion failure: Infallible unbox type mismatch, at /Users/mgaudet/mozilla-unified-clean/js/src/jit/MacroAssembler.cpp:2080
    Trace/BPT trap: 5

/me dances

Comment 20

[Matthew Gaudet (he/him) [:mgaudet]]

Attachment: Bug 1488786 - Always barrier getElem caches r?jandem

Comment 21

[Jan de Mooij [:jandem]]

Comment on attachment 9012850 [details]
Bug 1488786 - Always barrier getElem caches r?jandem

Jan de Mooij [:jandem] has approved the revision.

Comment 22

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f939ffbce06c
Always barrier getElem caches r=jandem
https://hg.mozilla.org/integration/mozilla-inbound/rev/0e43215b1975
Add an IC for sparse array element access r=jandem

Comment 23

[Daniel Varga [:dvarga]]

https://hg.mozilla.org/mozilla-central/rev/f939ffbce06c
https://hg.mozilla.org/mozilla-central/rev/0e43215b1975