New issue
Advanced search Search tips
Starred by 1 user
Status: Assigned
Owner:
Cc:
Components:
HW: All
OS: All
Priority: 1
Type: Bug

Blocking:
issue 6936



Sign in to add a comment
Several deopt loops in lebab and espree tests
Project Member Reported by bmeu...@chromium.org, Oct 23 Back to list
The lebab test of the web-tooling-benchmark seems to hit another set of deopt loops. All of these result from "wrong map", so probably the ICs report inconsistent/unstable state and don't make progress in the feedback lattice.
 
wtb-lebab.js
4.1 MB View Download
lebab.json
10.0 MB View Download
wtb-lebab.png
472 KB View Download
Cc: ishell@chromium.org
For example in the pp.eat function we see 24 deopts on a common run:

================================================================
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
<wtb-lebab.js:63497:12>	Reason: wrong map
================================================================

The function is pretty simple:

================================================================
// Predicate that tests whether the next token is of the given
// type, and if yes, consumes it as a side effect.

pp.eat = function(type) {
  if (this.type === type) {
    this.next();
    return true
  } else {
    return false
  }
};
================================================================
It looks like the LOAD_IC is in RECOMPUTE_HANDLER state when we miss on this:

========================================================================
$ grep -a 'wtb-lebab.js:63497' ic.txt
LoadIC (.->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x22a83050d8d1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x22a83050ed71)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db23305a2c1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db23305a311)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db23304dca1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db23304dcf1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db23304efb1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db23304f001)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233050b81)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233050bd1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233051da1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233051df1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233052f71)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233052fc1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db2330540f1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233054141)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233010031)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233010081)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233011161)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db2330111b1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db2330121f1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233012241)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233013231)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233013281)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233014221)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233014271)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db2330151c1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x1db233015211)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x22a830512151)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x22a8305121a1)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x22a830513051)
LoadIC (^->1) at ~pp.eat wtb-lebab.js:63497:12 type (map 0x22a8305130a1)
========================================================================

This doesn't look healthy.
Cc: -ishell@chromium.org bmeu...@chromium.org danno@chromium.org
Components: -Compiler
Owner: ishell@chromium.org
The reason why we end up in this sad state is that IC::ShouldRecomputeHandler() always returns true, because it finds a deprecated old_map. So somehow we run into some kind of "deprecation loop" here, where the runtime never settles on a stable state.

Assigning to ishell@ for investigation and fixes.
Cc: ishell@chromium.org
Owner: marja@chromium.org
Summary: Several deopt loops in lebab and espree tests (was: Several deopt loops in lebab test)
Found the same bug in the espree test. Interestingly it's also in the tokenizer code, and again it's IC::ShouldRecomputeHandler() that returns true for the deprecated maps.
espree.json
9.0 MB View Download
wtb-espree.js
2.7 MB View Download
wtb-espree.png
333 KB View Download
Cc: -mvstan...@chromium.org hpayer@chromium.org
N00b debugging notes, part 1 (the lebab test)

- In IC::ShouldRecomputeHandler, it happens 36734 times that the old map is deprecated.
- Map::DeprecateTransitionTree is called 3703 times. Excluding the recursive calls, it's called 167 times.
- ReconfigureToDataField ends up calling ConstructNewMap 166 times.

-> We're doing ReconfigureToDataField and that is causing the map deprecations.
Interesting. This suggests that constant field tracking should be a win here (doesn't mean we don't need to fix this bug).
N00b debugging notes continue (lebab):

Number of objects per each deprecated map:

-    if (old_map->is_deprecated()) return true;
+    if (old_map->is_deprecated()) {
+      fprintf(stderr, "old map %p is deprecated\n", *old_map);
+      return true;
+    }

$ grep "old map" log.txt | sort | uniq -c | sort -nr

    735 old map 0x7d31f0ae301 is deprecated
    735 old map 0x7d31f0ad271 is deprecated
    735 old map 0x7d31f0ac141 is deprecated
    735 old map 0x7d31f0ab011 is deprecated
    735 old map 0x7d31f0a9e91 is deprecated
    735 old map 0x7d31f0a8cc1 is deprecated
    735 old map 0x7d31f0a7aa1 is deprecated
    735 old map 0x7d31f0a5ed1 is deprecated
    735 old map 0x7d31f0a4bc1 is deprecated
    734 old map 0x7d31f0a1471 is deprecated
    690 old map 0x7d31f08ed71 is deprecated
    440 old map 0x7d31f0ae2b1 is deprecated
    440 old map 0x7d31f0ad221 is deprecated
    440 old map 0x7d31f0ac0f1 is deprecated
    440 old map 0x7d31f0aafc1 is deprecated
    440 old map 0x7d31f0a9e41 is deprecated
    440 old map 0x7d31f0a8c71 is deprecated
    440 old map 0x7d31f0a7a51 is deprecated
    440 old map 0x7d31f0a5e81 is deprecated
    440 old map 0x7d31f0a4b71 is deprecated
    440 old map 0x7d31f0a1421 is deprecated
    433 old map 0x7d31f0af2f1 is deprecated
    300 old map 0x7d31f08d8d1 is deprecated
     69 old map 0x7d31f0a07a1 is deprecated
     etc.

(Now looking into what property causes the map to be deprecated.)
Correction: the previous maps are not maps of the objects, but maps stored in the IC. So it happens 735 times that map 0x7d31f0ae301 is the FirstTargetMap of the IC, and that's why we need to recompute the handler.
More debugging notes (thanks ishell@ for a debugging session!)

In the LoadIC related to .type in function pp.eat, we always see an object with a new map coming in (the map is not deprecated at that point, so we don't migrate the object or anything). At that point, the IC contains one deprecated map. We kick it out in

https://cs.chromium.org/chromium/src/v8/src/ic/ic.cc?type=cs&l=518

and replace it with the new map (so the IC stays monomorphic).

But then this happens again; we see an object with a new map, and at that point, the previous map we put to the IC is deprecated.

For the curious, the debug prints needed for this observation are here:
https://chromium-review.googlesource.com/#/c/v8/v8/+/741225

The following modification is also needed to the wtb-lebab, in order to pinpoint the interesting IC:

Instead of
pp.eat = function() ... 

do:

function fooo(type) {
  if (this.type === type) {
    this.next();
    return true
  } else {
    return false
  }
};

pp.eat =  fooo;

So now the interesting ICs occur in the log near
#type
#fooo

-> The IC system is working as intended. TurboFan and map check generation too.

Next step: find out where this series of deprecated maps is coming from.
Update: there are 20 maps that hit this IC, let's call them 1-20, in the order we see them. And then I see something weird...

Map1 has value:h + funcs are all constant, and Map2 has value:t and funcs are all constant.

Map3 is like Map1 but parseExprAtom turns into data. Map4 is like Map2 but parseExprAtom turns into data.

Map5 is like Map3 but readToken turns into data. Map6 is like Map4 but readToken turns into data.

And so on, for 7 other functions, in the same order for both "branches". The curious thing is that for odd-numbered maps, value is "h", and for even-numbered maps, value is "t".

I still don't know how this weird structure is created; I know that Map1 gets deprecated when we create Map2, Map3 gets deprecated when we create Map4 etc. but I yet don't know why we deprecate Map2 and how Map3 gets created etc.

This is not a deopt loop, we're making progress (just that we're making progress in this curious two-steps-ahead-one-step-back fashion).
One possible explanation (which we think is probably what happens):

First we create an object o1 w/ value:h, it's map is m1. Then we turn set its value into something tagged, now the map is m1. This deprecates part of the transition tree.

Then we create an object o2, which is almost like o1, except that parseExprAtom is not a const but a data. The field "value" comes later than parseExprAtom, so, at that point, we just branch at "parseExprAtom", and later on, add "value" as "h", and this is m3. Creating that deprecates m2.

And then it goes on. We make value t in o2, that creates m4 and deprecates m3. Etc.

That explains the maps we see coming in.

s/now the map is m1/now the map is m2
Here's an updated version of the test case from the latest 0.3.1 web-tooling-benchmark, which now runs fixed number of iterations (20 x 2 iterations to be precise).
wtb-lebab.js
4.1 MB View Download
Here's a small repro for the "constantly recomputing handlers" behavior:

===== test.js ====

function A() {
  for (let i = 0; i < 50; i++) {
    this["p"+i] = new Function("/* " + i + " */");
  }
}

function f(o) {
  return o.x;
}

for (let i = 0; i < 10; i++) {
  let o = new A();
  f(o);
}

Cc: jkummerow@chromium.org
Here's what's happening:

1. When the first instance of A is created we have the following transition tree:
  {} --> p0(const) --> p1(const) --> ... -> p49(const)

2. When the second instance is created: 
2.1. The runtime figures out that it has to generalize p0 to be a data field since we are trying to store a different constant. This leads us to the following state of transition tree (the old branch to p0(const) map is removed from the transition tree and deprecated - *):
  {} -X-> *p0(const) --> *p1(const) --> ... -> *p49(const)
   \
    +-> p0(field)

2.2. Then the constructor initializes p1:
  {} -X-> *p0(const) --> *p1(const) --> ... -> *p49(const)
   \
    +-> p0(field) --> p1(const)

...

2.50. And finally, after all properties are initialized we have the following state of transition tree:
  {} -X-> *p0(const) --> *p1(const) --> ... -> *p49(const)
   \
    +-> p0(field) --> p1(const) --> ... -> p49(const)

3. When the third instance of A is created:
3.1. Initialization of p0 just transitions the object to already existing p0(field) map
3.2. Initialization of p1 generalizes p1 to data field since we are trying to store a different constant. This leads us to the following state of transition tree (the old branch to p1(const) map is removed from the transition tree and deprecated):
  {} -X-> *p0(const) --> *p1(const) --> ... -> *p49(const)
   \
    +-> p0(field) -X-> *p1(const) --> ... -> *p49(const)
                \
                 +-> p1(field)

...

3.50. Finally we have the following transition tree:
  {} -X-> *p0(const) --> *p1(const) --> ... -> *p49(const)
   \
    +-> p0(field) -X-> *p1(const) --> ... -> *p49(const)
                \
                 +-> p1(field) --> ... -> p49(const)


So, as we can see each new instance of A gets a new map till all the constant properties generalized to mutable fields.
Similar pattern can happen if the reason for a property generalization is a field representation change (smi->double->tagged).

I see two possible solutions:
1. Try to artificially re-attach the deprecated transition tree to a map with generalized field to ensure that the old state of transition tree is taken into account when the new transitions are created.
2. Always generalize maps in-place and use field dependency mechanism instead of map deprecation. This approach will require:
  a) constant field tracking (to ensure that the compiler can still figure out the constant function's values)
  b.a) teaching the IC system to dynamically check representation of a loaded or stored field
    OR
  b.b) use NaN-tagging for fields.

To be honest, both approaches require quite some efforts.

Project Member Comment 19 by bugdroid1@chromium.org, Nov 6
The following revision refers to this bug:
  https://chromium.googlesource.com/v8/v8.git/+/ca0c951a7e8888cc57fb2837763550a1ae300796

commit ca0c951a7e8888cc57fb2837763550a1ae300796
Author: Igor Sheludko <ishell@chromium.org>
Date: Mon Nov 06 10:09:34 2017

[runtime] Prepare for turning constant field tracking on.

This CL ensures that elements kind transitions don't cause silent
mutable-to-constant field migrations when the following options
are enabled: --track_constant_fields --modify_map_inplace.

Bug: v8:5495, v8:6980
Change-Id: Ie28daab84f91d424110e71504b025a2e465bfe16
Reviewed-on: https://chromium-review.googlesource.com/753087
Commit-Queue: Igor Sheludko <ishell@chromium.org>
Reviewed-by: Toon Verwaest <verwaest@chromium.org>
Cr-Commit-Position: refs/heads/master@{#49133}
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/src/api-natives.cc
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/src/bootstrapper.cc
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/src/factory.cc
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/src/lookup.cc
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/src/map-updater.cc
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/src/map-updater.h
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/src/objects.cc
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/src/objects/map-inl.h
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/src/objects/map.h
[modify] https://crrev.com/ca0c951a7e8888cc57fb2837763550a1ae300796/test/cctest/test-field-type-tracking.cc

Sign in to add a comment