Closed Bug 1252228 Opened 4 years ago Closed 4 years ago

Wrong function is inlined (but not executed) in kraken stanford-crypto-pbkdf2 benchmark.

Categories

(Core :: JavaScript Engine: JIT, defect)

defect
Not set

Tracking

()

RESOLVED FIXED
mozilla47
Tracking Status
firefox47 --- fixed

People

(Reporter: arai, Assigned: jandem)

References

Details

Attachments

(2 files)

While executing stanford-crypto-ccm and stanford-crypto-pbkdf2 sequentially in kraken benchmark in arewefastyet, like following command:

js \
    --ion-offthread-compile=off \
    -e "var tests = ['stanford-crypto-ccm', 'stanford-crypto-pbkdf2'], suitePath = 'test/kraken-1.1'; suiteName='kraken-1.1';" \
    -f resources/sunspider-standalone-driver.js


A function defined in stanford-crypto-ccm-data.js is inlined into a function defined in stanford-crypto-pbkdf2-data.js. they don't share any code, but use same global variable name and similar object structure, and same function body for some functions.


https://dxr.mozilla.org/mozilla-central/rev/5e0140b6d11821e0c2a2de25bc5431783f03380a/js/src/jit/IonBuilder.cpp#6611
> bool
> IonBuilder::jsop_call(uint32_t argc, bool constructing)
> {
> ...
>     // Acquire known call target if existent.
>     ObjectVector targets(alloc());
>     TemporaryTypeSet* calleeTypes = current->peek(calleeDepth)->resultTypeSet();
>     if (calleeTypes && !getPolyCallTargets(calleeTypes, constructing, targets, 4))
>         return false;
> 
>     CallInfo callInfo(alloc(), constructing);
>     if (!callInfo.init(current, argc))
>         return false;
> 
>     // Try inlining
>     InliningStatus status = inlineCallsite(targets, callInfo);

while compiling 1st `new b` call in `sjcl.misc.hmac` [1] function in stanford-crypto-ccm-data.js, `getPolyCallTargets` returns `sjcl.hash.sha256` [2] function defined in stanford-crypto-ccm-data.js.

It should return `sjcl.hash.sha256` [3] function defined in stanford-crypto-ccm-data.js, or just return nothing.

here's prettified code.  The `sjcl.hash.sha256` definition in both files are same, but even I modified one of them to make them different, still function in stanford-crypto-ccm-data.js is inlined.

sjcl.misc.hmac = function(a, b) {
    this.M = b = b || sjcl.hash.sha256;
    var c = [
            [],
            []
        ],
        d = b.prototype.blockSize / 32;
    this.l = [new b, new b];
    if (a.length > d) a = b.hash(a);
    for (b = 0; b < d; b++) {
        c[0][b] = a[b] ^ 909522486;
        c[1][b] = a[b] ^ 1549556828
    }
    this.l[0].update(c[0]);
    this.l[1].update(c[1])
};

sjcl.hash.sha256 = function(a) {
    this.a[0] || this.w();
    if (a) {
        this.n = a.n.slice(0);
        this.i = a.i.slice(0);
        this.e = a.e
    } else this.reset()
};


[1] https://github.com/h4writer/arewefastyet/blob/master/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-pbkdf2-data.js#L26
[2] https://github.com/h4writer/arewefastyet/blob/master/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-ccm-data.js#L15
[3] https://github.com/h4writer/arewefastyet/blob/master/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-pbkdf2-data.js#L26
posted totally wrong comment :P

I meant following

https://dxr.mozilla.org/mozilla-central/rev/
5e0140b6d11821e0c2a2de25bc5431783f03380a/js/src/jit/IonBuilder.cpp#6611
> bool
> IonBuilder::jsop_call(uint32_t argc, bool constructing)
> {
> ...
>     // Acquire known call target if existent.
>     ObjectVector targets(alloc());
>     TemporaryTypeSet* calleeTypes = current->peek(calleeDepth)->resultTypeSet();
>     if (calleeTypes && !getPolyCallTargets(calleeTypes, constructing, targets, 4))
>         return false;
> 
>     CallInfo callInfo(alloc(), constructing);
>     if (!callInfo.init(current, argc))
>         return false;
> 
>     // Try inlining
>     InliningStatus status = inlineCallsite(targets, callInfo);

while compiling 1st `new b` call in `sjcl.misc.hmac` [1] function in stanford-crypto-pbkdf2-data.js, `getPolyCallTargets` returns `sjcl.hash.sha256` [2] function defined in stanford-crypto-ccm-data.js.

It should return `sjcl.hash.sha256` [3] function defined in stanford-crypto-pbkdf2-data.js, or just return nothing.
the issue disappears with either following change:

1. rename `sjcl` to `sjcl2` in stanford-crypto-pbkdf2-data.js and stanford-crypto-pbkdf2.js.

2. apply following change to kraken test driver to run each test in different global

> --- a/benchmarks/kraken/resources/sunspider-standalone-driver.js
> +++ b/benchmarks/kraken/resources/sunspider-standalone-driver.js
> @@ -33,10 +33,11 @@ for (var krakenCounter = 0; krakenCounter < tests.length; krakenCounter++) {
>      var testBase = "tests/" + suiteName + "/" + tests[krakenCounter];
>      var testName = testBase + ".js";
>      var testData = testBase + "-data.js";
> +    var g = newGlobal();
>      // load test data
> -    load(testData);
> +    g.load(testData);
>      var startTime = new Date;
> -    load(testName);
> +    g.load(testName);
>      times[krakenCounter] = new Date() - startTime;
>      gc();
>  }


so, maybe an issue in type inference or similar place.
(In reply to Tooru Fujisawa [:arai] from comment #1)
> while compiling 1st `new b` call in `sjcl.misc.hmac` [1] function in
> stanford-crypto-pbkdf2-data.js, `getPolyCallTargets` returns
> `sjcl.hash.sha256` [2] function defined in stanford-crypto-ccm-data.js.

actually, sjcl.hash.sha256 in ccm is recorded to `current->peek(calleeDepth)` instruction (MUnbox), as singleton object.

>     TemporaryTypeSet* calleeTypes = current->peek(calleeDepth)->resultTypeSet();
>     if (calleeTypes && !getPolyCallTargets(calleeTypes, constructing, targets, 4))
forgot to note that the inlined *wrong* function is not actually executed.
also, there are several more functions seem to be inlined.
Summary: Wrong function is inlined in kraken stanford-crypto-pbkdf2 benchmark. → Wrong function is inlined (but not executed) in kraken stanford-crypto-pbkdf2 benchmark.
marking ss until we can investigate this further. The title is terrifying.
Group: core-security
Group: core-security → javascript-core-security
To be clear, here's the way I confirmed this issue.
Let me know if I'm doing something wrongly.

Steps to reproduce:

  1. Apply attached patch (adds is_ccm function that is used in step 4)
  2. make test.js with following content

var tests = ['stanford-crypto-ccm', 'stanford-crypto-pbkdf2'], suitePath = 'test/kraken-1.1'; suiteName='kraken-1.1';

  3. run JS shell on debugger, inside arewefastyet/benchmarks/kraken

cd arewefastyet/benchmarks/kraken
lldb path/to/js

  4. add breakpoint to is_ccm function added in step 1

b is_ccm

  5. run benchmark

run --ion-offthread-compile=off -f test.js resources/sunspider-standalone-driver.js

Result:

get following log, and hit a breakpoint in is_ccm:

> ...
> **** IonBuilder, /Users/arai/projects/arewefastyet/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-pbkdf2-data.js:307:19
> **** IonBuilder, /Users/arai/projects/arewefastyet/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-pbkdf2-data.js:573:27
> **** IonBuilder, /Users/arai/projects/arewefastyet/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-pbkdf2-data.js:553:25
> **** IonBuilder, /Users/arai/projects/arewefastyet/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-ccm-data.js:294:27

the benchmark executes stanford-crypto-pbkdf2 *after* stanford-crypto-ccm.
so function in ccm shouldn't be compiled after a function in pbkdf2 gets compiled.


here's the backtrace:

* thread #1: tid = 0x63cefb, 0x0000000100347346 js`is_ccm() + 22 at IonBuilder.cpp:123, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
  * frame #0: 0x0000000100347346 js`is_ccm() + 22 at IonBuilder.cpp:123
    frame #1: 0x0000000100347868 js`js::jit::IonBuilder::IonBuilder(this=0x00007fff5fbf5350, analysisContext=0x0000000104241c00, comp=0x0000000104227000, options=0x00007fff5fbf694c, temp=0x00007fff5fbf67d0, graph=0x00007fff5fbf6738, constraints=0x000000010459e048, inspector=0x00007fff5fbf5300, info=0x00000001045a2ac8, optimizationInfo=0x0000000101e54bc8, baselineFrame=0x0000000000000000, inliningDepth=1, loopDepth=0) + 1272 at IonBuilder.cpp:180
    frame #2: 0x0000000100344510 js`js::jit::IonBuilder::IonBuilder(this=0x00007fff5fbf5350, analysisContext=0x0000000104241c00, comp=0x0000000104227000, options=0x00007fff5fbf694c, temp=0x00007fff5fbf67d0, graph=0x00007fff5fbf6738, constraints=0x000000010459e048, inspector=0x00007fff5fbf5300, info=0x00000001045a2ac8, optimizationInfo=0x0000000101e54bc8, baselineFrame=0x0000000000000000, inliningDepth=1, loopDepth=0) + 208 at IonBuilder.cpp:170
    frame #3: 0x0000000100365816 js`js::jit::IonBuilder::inlineScriptedCall(this=0x00007fff5fbf68c0, callInfo=0x00007fff5fbf5e18, target=0x000000010438e600) + 2118 at IonBuilder.cpp:5140
    frame #4: 0x0000000100367235 js`js::jit::IonBuilder::inlineSingleCall(this=0x00007fff5fbf68c0, callInfo=0x00007fff5fbf5e18, targetArg=0x000000010438e600) + 197 at IonBuilder.cpp:5652
    frame #5: 0x00000001003674a5 js`js::jit::IonBuilder::inlineCallsite(this=0x00007fff5fbf68c0, targets=0x00007fff5fbf5ea8, callInfo=0x00007fff5fbf5e18) + 581 at IonBuilder.cpp:5708
    frame #6: 0x000000010035697d js`js::jit::IonBuilder::jsop_call(this=0x00007fff5fbf68c0, argc=0, constructing=true) + 669 at IonBuilder.cpp:6645
    frame #7: 0x000000010034e186 js`js::jit::IonBuilder::inspectOpcode(this=0x00007fff5fbf68c0, op=JSOP_NEW) + 3206 at IonBuilder.cpp:1910
    frame #8: 0x000000010034abb7 js`js::jit::IonBuilder::traverseBytecode(this=0x00007fff5fbf68c0) + 999 at IonBuilder.cpp:1544
    frame #9: 0x0000000100344d24 js`js::jit::IonBuilder::build(this=0x00007fff5fbf68c0) + 2052 at IonBuilder.cpp:940
    frame #10: 0x00000001003437eb js`js::jit::AnalyzeNewScriptDefiniteProperties(cx=0x0000000104241c00, fun=0x00000001043e7380, group=0x0000000104341070, baseobj=js::HandlePlainObject @ 0x00007fff5fbf68b0, initializerList=0x00007fff5fbf7360) + 1483 at IonAnalysis.cpp:3729
    frame #11: 0x0000000100b4317a js`js::TypeNewScript::maybeAnalyze(this=0x00000001046c4910, cx=0x0000000104241c00, group=0x0000000104341070, regenerate=0x0000000000000000, force=true) + 1802 at TypeInference.cpp:3747
    frame #12: 0x0000000100320403 js`js::jit::IonCompile(cx=0x0000000104241c00, script=0x00000001043424a0, baselineFrame=0x00007fff5fbf7cf8, osrPc="\343\202V", constructing=false, recompile=false, optimizationLevel=Normal) + 2131 at Ion.cpp:2208
    frame #13: 0x000000010031aec4 js`js::jit::Compile(cx=0x0000000104241c00, script=JS::HandleScript @ 0x00007fff5fbf7a10, osrFrame=0x00007fff5fbf7cf8, osrPc="\343\202V", constructing=false, forceRecompile=false) + 1188 at Ion.cpp:2432
    frame #14: 0x000000010031b886 js`BaselineCanEnterAtBranch(cx=0x0000000104241c00, script=JS::HandleScript @ 0x00007fff5fbf7ac0, osrFrame=0x00007fff5fbf7cf8, pc="\343\202V") + 870 at Ion.cpp:2619
    frame #15: 0x000000010031b230 js`js::jit::IonCompileScriptForBaseline(cx=0x0000000104241c00, frame=0x00007fff5fbf7cf8, pc="\343\202V") + 720 at Ion.cpp:2678
    frame #16: 0x0000000100232ef6 js`js::jit::DoWarmUpCounterFallbackOSR(cx=0x0000000104241c00, frame=0x00007fff5fbf7cf8, stub=0x00000001062abf70, infoPtr=0x00007fff5fbf7ca0) + 390 at BaselineIC.cpp:141
    frame #17: 0x00000001034810b5
some more debug log that shows functions in different files are mixed

(lldb) up
up
frame #1: 0x0000000100347868 js`js::jit::IonBuilder::IonBuilder(this=0x00007fff5fbf5350, analysisContext=0x0000000104241c00, comp=0x0000000104227000, options=0x00007fff5fbf694c, temp=0x00007fff5fbf67d0, graph=0x00007fff5fbf6738, constraints=0x000000010459e048, inspector=0x00007fff5fbf5300, info=0x00000001045a2ac8, optimizationInfo=0x0000000101e54bc8, baselineFrame=0x0000000000000000, inliningDepth=1, loopDepth=0) + 1272 at IonBuilder.cpp:180
   177 	
   178 	    if (is_pbkdf2) {
   179 	        if (strstr(script_->filename(), "ccm") != nullptr) {
-> 180 	            is_ccm();
   181 	        }
   182 	    }
   183 	    if (strstr(script_->filename(), "pbkdf2") != nullptr) {
(lldb) 

frame #2: 0x0000000100344510 js`js::jit::IonBuilder::IonBuilder(this=0x00007fff5fbf5350, analysisContext=0x0000000104241c00, comp=0x0000000104227000, options=0x00007fff5fbf694c, temp=0x00007fff5fbf67d0, graph=0x00007fff5fbf6738, constraints=0x000000010459e048, inspector=0x00007fff5fbf5300, info=0x00000001045a2ac8, optimizationInfo=0x0000000101e54bc8, baselineFrame=0x0000000000000000, inliningDepth=1, loopDepth=0) + 208 at IonBuilder.cpp:170
   167 	    lazyArguments_(nullptr),
   168 	    inlineCallInfo_(nullptr),
   169 	    maybeFallbackFunctionGetter_(nullptr)
-> 170 	{
   171 	    script_ = info->script();
   172 	    fprintf(stderr, "**** IonBuilder, %s:%zu:%zu\n",
   173 	            script_->filename(),
(lldb) 

frame #3: 0x0000000100365816 js`js::jit::IonBuilder::inlineScriptedCall(this=0x00007fff5fbf68c0, callInfo=0x00007fff5fbf5e18, target=0x000000010438e600) + 2118 at IonBuilder.cpp:5140
   5137	    AutoAccumulateReturns aar(graph(), returns);
   5138	
   5139	    // Build the graph.
-> 5140	    IonBuilder inlineBuilder(analysisContext, compartment, options, &alloc(), &graph(), constraints(),
   5141	                             &inspector, info, &optimizationInfo(), nullptr, inliningDepth_ + 1,
   5142	                             loopDepth_);
   5143	
(lldb) p script_->filename()
p script_->filename()
(const char *) $0 = 0x00000001046c1f60 "/Users/arai/projects/arewefastyet/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-pbkdf2-data.js"
(lldb) p script_->lineno()
p script_->lineno()
(size_t) $1 = 553
(lldb) p script_->column()
p script_->column()
(size_t) $2 = 25
(lldb) p calleeScript
p calleeScript
(JSScript *) $3 = 0x000000010436e3d0
(lldb) p calleeScript->filename()
p calleeScript->filename()
(const char *) $4 = 0x00000001046b49b0 "/Users/arai/projects/arewefastyet/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-ccm-data.js"
(lldb) p calleeScript->lineno()
p calleeScript->lineno()
(size_t) $5 = 294
(lldb) p calleeScript->column()
p calleeScript->column()
(size_t) $6 = 27
and more log that shows resultTypeSet contains wrong thing.

(lldb) up
up
frame #4: 0x0000000100367235 js`js::jit::IonBuilder::inlineSingleCall(this=0x00007fff5fbf68c0, callInfo=0x00007fff5fbf5e18, targetArg=0x000000010438e600) + 197 at IonBuilder.cpp:5652
   5649	    // Track success now, as inlining a scripted call makes a new return block
   5650	    // which has a different pc than the current call pc.
   5651	    trackInlineSuccess();
-> 5652	    if (!inlineScriptedCall(callInfo, target))
   5653	        return InliningStatus_Error;
   5654	    return InliningStatus_Inlined;
   5655	}
(lldb) up
up
frame #5: 0x00000001003674a5 js`js::jit::IonBuilder::inlineCallsite(this=0x00007fff5fbf68c0, targets=0x00007fff5fbf5ea8, callInfo=0x00007fff5fbf5e18) + 581 at IonBuilder.cpp:5708
   5705	            callInfo.setFun(constFun);
   5706	        }
   5707	
-> 5708	        return inlineSingleCall(callInfo, target);
   5709	    }
   5710	
   5711	    // Choose a subset of the targets for polymorphic inlining.
(lldb) up
up
frame #6: 0x000000010035697d js`js::jit::IonBuilder::jsop_call(this=0x00007fff5fbf68c0, argc=0, constructing=true) + 669 at IonBuilder.cpp:6645
   6642	        return false;
   6643	
   6644	    // Try inlining
-> 6645	    InliningStatus status = inlineCallsite(targets, callInfo);
   6646	    if (status == InliningStatus_Inlined)
   6647	        return true;
   6648	    if (status == InliningStatus_Error)
(lldb) p calleeTypes
p calleeTypes
(js::TemporaryTypeSet *) $7 = 0x00000001045a0630
(lldb) p calleeTypes->getObjectCount()
p calleeTypes->getObjectCount()
(unsigned int) $8 = 1
(lldb) p calleeTypes->getSingleton(0)
p calleeTypes->getSingleton(0)
(JSObject *) $9 = 0x000000010438e600
(lldb) p ((JSFunction*)calleeTypes->getSingleton(0))->nonLazyScript()
p ((JSFunction*)calleeTypes->getSingleton(0))->nonLazyScript()
(JSScript *) $10 = 0x000000010436e3d0
(lldb) p ((JSFunction*)calleeTypes->getSingleton(0))->nonLazyScript()->filename()
p ((JSFunction*)calleeTypes->getSingleton(0))->nonLazyScript()->filename()
(const char *) $11 = 0x00000001046b49b0 "/Users/arai/projects/arewefastyet/benchmarks/kraken/tests/kraken-1.1/stanford-crypto-ccm-data.js"
(lldb) p ((JSFunction*)calleeTypes->getSingleton(0))->nonLazyScript()->lineno()
p ((JSFunction*)calleeTypes->getSingleton(0))->nonLazyScript()->lineno()
(size_t) $12 = 294
(lldb) p ((JSFunction*)calleeTypes->getSingleton(0))->nonLazyScript()->column()
p ((JSFunction*)calleeTypes->getSingleton(0))->nonLazyScript()->column()
(size_t) $13 = 27
what could be the reason why wrong function is added to the result type set?
where should I look into next?
Flags: needinfo?(bhackett1024)
in the graphs generated by iongraph, all references to function in stanford-crypto-ccm-data.js is "call"ed, not inlined.
(iiuc, if a functions is inlined, the function's constant is shown in the graph but the constant is not referred, and the block jumps to the next block that is the inlined code, right?)

functions referred (called) in the graph are following:
  * sjcl.bitArray.P
  * sjcl.bitArray.clamp
  * sjcl.bitArray.concat
  * sjcl.codec.utf8String.toBits
  * sjcl.exception.invalid

functions passed to IonBuilder ctor (from IonBuilder::inlineScriptedCall) are following:
  * sjcl.bitArray.partial
  * sjcl.bitArray.getPartial
  * sjcl.bitArray.P
  * sjcl.codec.utf8String.toBits
  * sjcl.hash.sha256
  * sjcl.hash.sha256.hash

will look into how those possibly inlined code is handled later today (maybe discarded somewhere?)
This seems pretty weird, looking into it..
Flags: needinfo?(bhackett1024) → needinfo?(jdemooij)
Attached patch PatchSplinter Review
There's an heuristic in PropertyReadNeedsTypeBarrier that adds property types to the observed typeset if the observed set is empty. It only adds the first type, though, so that's causing the confusion here. This patch changes the |if (types.length())| check to |if (types.length() == 1)|.

Not a correctness bug because we'll add a type barrier that will bail at runtime.
Assignee: nobody → jdemooij
Status: NEW → ASSIGNED
Flags: needinfo?(jdemooij)
Attachment #8725132 - Flags: review?(efaustbmo)
Group: javascript-core-security
Comment on attachment 8725132 [details] [diff] [review]
Patch

Review of attachment 8725132 [details] [diff] [review]:
-----------------------------------------------------------------

Works for me.
Attachment #8725132 - Flags: review?(efaustbmo) → review+
https://hg.mozilla.org/mozilla-central/rev/9d9502981ba6
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla47
You need to log in before you can comment on or make changes to this bug.