search

Haiyang-Sun / nodeprof.js

Instrumentation framework for Node.js compliant to ECMAScript 2020 based on GraalVM.
Apache License 2.0
53 stars 22 forks source link

WIP: handle control flow exceptions #58

Closed alexjordan closed 5 years ago

alexjordan commented 5 years ago

This contains a test for return from the discussion in #37 that showed that functionExit is missing return values (1) when issued from a try-catch block and (2) _return callbacks are missing for the ConstantReturnNode.

Haiyang-Sun commented 5 years ago

@alexjordan do you expect to have two functionExit events in the try/catch/finally function? I think it would be simpler to have always a matched functionEnter/Exit while we can have multiple _return events. And we can provide the function and arguments in the callback of functionExit and _return events for convenience in the analysis.

_return callbacks are missing for the ConstantReturnNode.

Which return values are missing in this example? I tried with the latest master, and I can see both return events for 42 and 43 without changes.

alexjordan commented 5 years ago

@Haiyang-Sun

do you expect to have two functionExit events

Sorry, the output was a bit confusing ('functionExit' was logged twice from the same callback), I cleaned it up in 9a784d1.

Which return values are missing in this example?

I was able to fix the _return callbacks in f45ca38, but the final return value is missing from functionExit, thus you should see this error:

Testing exitException.js in minitests with analysis enter-exit
Fail @enter-exit
15c15
< functionExit: (src/ch.usi.inf.nodeprof.test/js/minitests/exitException.js:48:2:58:2) / returnVal (number): 43
---
> functionExit: (src/ch.usi.inf.nodeprof.test/js/minitests/exitException.js:48:2:58:2) / 3
Haiyang-Sun commented 5 years ago

Thanks, I have just pushed a fix for the root event. I guess maybe we could make use of this ReturnException to implement the missing feature of Jalangi to change the return value of some expression, e.g., by throwing a return exception in the callback part to force returning a given value from the dynamic analysis. @eleinadani , what do you think?

Haiyang-Sun commented 5 years ago

@alexjordan The tests pass now, however, I notice a compiler warning when testing mx test-npm: https://travis-ci.com/Haiyang-Sun/nodeprof.js/builds/133268691#L4741 (should not be materialized (must not let virtual object escape at node 33392|EndNode):) And the stack trace does seem to point to the right place for the problem.

Haiyang-Sun commented 5 years ago

It's true that the return slot might be missing when ReturnValueInFrame is disabled. For now, it is safe as it is only used in places where the ReturnValueInFrame has to enabled. Ideally, the ReturnException could be handled in the Truffle instrumentation layer. I

The yield attribute is to distinguish the "fake" function exit (suspension) and a real function exit for a generator function or an asynchronous function. The execution of such functions can be suspended. To track the suspension of the execution, we track and mark the function exits with exception.yield=true. This makes sure that every (async)functionEnter has a corresponding (async)functionExit and we can tell a suspended function if the yield attribute is true.

mwaldrich commented 4 years ago

I've tried testing this PR, and it seems to only work sometimes. Whether or not these callbacks work seems to depend on the body of the function itself.

For example, the callbacks do not work for the exact program I put in this issue (async.js). However, they do work for the very slightly modified version that was used as a test case in this PR.

The difference between the program I provided and the program used as a test case in this PR is extremely minimal: a few console.log's were added to the countTo6 function. From my testing it seems that, in general, if a function is more complex, the async/await callbacks are more likely to work. For example, if you added only one console.log to the original program I suggested, the callbacks do not work correctly. Adding two console.log's seems to make the callbacks work correctly. Adding something like a variable declaration to the countTo6 function will also make it work.

Here are some examples that I found make the async/await callbacks work correctly/not work correctly:

Works

async function countTo6(x) {
    // adding two `console.log`'s
    console.log("hi 1!");
    console.log("hi 2!");
    if (x > 5) {
          return x;
    } else {
        return await countTo6(x + 1);
    }
}

async function main() {
      return await countTo6(1);
}

main().then(v => console.log("done! answer = " + v));

Doesn't work

async function countTo6(x) {
    // adding only one `console.log`
    console.log("hi 1!");
    if (x > 5) {
          return x;
    } else {
        return await countTo6(x + 1);
    }
}

async function main() {
      return await countTo6(1);
}

main().then(v => console.log("done! answer = " + v));

Works

async function countTo6(x) {
    // adding a variable declaration
    let uselessVariable = 0;
    if (x > 5) {
          return x;
    } else {
        return await countTo6(x + 1);
    }
}

async function main() {
      return await countTo6(1);
}

main().then(v => console.log("done! answer = " + v));

Doesn't work

async function countTo6(x) {
    // the original function I suggested
    if (x > 5) {
          return x;
    } else {
        return await countTo6(x + 1);
    }
}

async function main() {
      return await countTo6(1);
}

main().then(v => console.log("done! answer = " + v));
mwaldrich commented 4 years ago

I also found a simple test program that causes NodeProf to crash.

analysis.js

// DO NOT INSTRUMENT
(function (sandbox) {
    function MyAnalysis() {
            this.awaitPre = function (iid, valAwaited) {
                console.log(valAwaited);
            }
    }
    sandbox.analysis = new MyAnalysis();
})(J$);

program.js

async function func1(x) {
    await func2(x);
    await func2(x);
}

async function func2(x) {
    return await func3(x);
}

async function func3(x) {
    return x;
}

func1(5);

Analysis output

Promise { 5 }
Promise { <pending> }
Promise { 5 }
Promise { 5 }
Promise { 5 }
Promise { <pending> }
java.lang.AssertionError
    at ch.usi.inf.nodeprof.jalangi.factory.AbstractFactory.setPreArguments(AbstractFactory.java:128)
    at ch.usi.inf.nodeprof.jalangi.factory.AwaitFactory$1.executePre(AwaitFactory.java:48)
    at ch.usi.inf.nodeprof.analysis.ProfilerExecutionEventNode.onInputValue(ProfilerExecutionEventNode.java:84)
    at com.oracle.truffle.api.instrumentation.ProbeNode$EventProviderChainNode.innerOnInputValue(ProbeNode.java:1443)
    at com.oracle.truffle.api.instrumentation.ProbeNode$EventChainNode.onInputValue(ProbeNode.java:957)
    at com.oracle.truffle.api.instrumentation.ProbeNode.onInputValue(ProbeNode.java:317)
    at com.oracle.truffle.api.instrumentation.ProbeNode$InputValueChainNode.innerOnReturnValue(ProbeNode.java:1518)
    at com.oracle.truffle.api.instrumentation.ProbeNode$EventChainNode.onReturnValue(ProbeNode.java:1012)
    at com.oracle.truffle.api.instrumentation.ProbeNode.onReturnValue(ProbeNode.java:171)
    at com.oracle.truffle.js.nodes.access.JSTargetableNodeWrapper.executeWithTarget(JSTargetableNodeWrapper.java:574)
    at com.oracle.truffle.js.nodes.control.AwaitNode.resumeAwait(AwaitNode.java:228)
    at com.oracle.truffle.js.nodes.control.AwaitNode.resume(AwaitNode.java:220)
    at com.oracle.truffle.js.nodes.control.GeneratorWrapperNode.execute(GeneratorWrapperNode.java:114)
    at com.oracle.truffle.js.nodes.JavaScriptNodeWrapper.execute(JavaScriptNodeWrapper.java:48)
    at com.oracle.truffle.js.nodes.control.ReturnNode$TerminalPositionReturnNode.execute(ReturnNode.java:163)
    at com.oracle.truffle.js.nodes.JavaScriptNodeWrapper.execute(JavaScriptNodeWrapper.java:48)
    at com.oracle.truffle.js.nodes.control.AsyncFunctionBodyNode$AsyncFunctionRootNode.execute(AsyncFunctionBodyNode.java:99)
    at com.oracle.truffle.api.impl.DefaultCallTarget.callDirectOrIndirect(DefaultCallTarget.java:85)
    at com.oracle.truffle.api.impl.DefaultDirectCallNode.call(DefaultDirectCallNode.java:59)
    at com.oracle.truffle.js.nodes.function.InternalCallNode.directCall(InternalCallNode.java:70)
    at com.oracle.truffle.js.nodes.function.InternalCallNodeGen.execute(InternalCallNodeGen.java:40)
    at com.oracle.truffle.js.nodes.control.AwaitResumeNode.execute(AwaitResumeNode.java:68)
    at com.oracle.truffle.js.nodes.control.AwaitNode$1AwaitFulfilledRootNode.execute(AwaitNode.java:271)
    at com.oracle.truffle.api.impl.DefaultCallTarget.callDirectOrIndirect(DefaultCallTarget.java:85)
    at com.oracle.truffle.api.impl.DefaultDirectCallNode.call(DefaultDirectCallNode.java:59)
    at com.oracle.truffle.js.nodes.function.JSFunctionCallNode$UnboundJSFunctionCacheNode.executeCall(JSFunctionCallNode.java:1250)
    at com.oracle.truffle.js.nodes.function.JSFunctionCallNode.executeCall(JSFunctionCallNode.java:233)
    at com.oracle.truffle.js.nodes.promise.PromiseReactionJobNode$1PromiseReactionJob.execute(PromiseReactionJobNode.java:125)
    at com.oracle.truffle.api.impl.DefaultCallTarget.call(DefaultCallTarget.java:102)
    at com.oracle.truffle.js.runtime.builtins.JSFunction.call(JSFunction.java:369)
    at com.oracle.truffle.js.runtime.JSAgent.processAllPromises(JSAgent.java:147)
    at com.oracle.truffle.trufflenode.GraalJSAccess.isolateRunMicrotasks(GraalJSAccess.java:2482)
    at com.oracle.truffle.trufflenode.NativeAccess.executeFunction0(Native Method)
    at com.oracle.truffle.trufflenode.node.ExecuteNativeFunctionNode.executeFunction0(ExecuteNativeFunctionNode.java:278)
    at com.oracle.truffle.trufflenode.node.ExecuteNativeFunctionNode.execute(ExecuteNativeFunctionNode.java:154)
    at com.oracle.truffle.trufflenode.node.ExecuteNativeFunctionNode$NativeFunctionRootNode.execute(ExecuteNativeFunctionNode.java:342)
    at com.oracle.truffle.api.impl.DefaultCallTarget.callDirectOrIndirect(DefaultCallTarget.java:85)
    at com.oracle.truffle.api.impl.DefaultDirectCallNode.call(DefaultDirectCallNode.java:59)
    at com.oracle.truffle.js.nodes.function.JSFunctionCallNode$UnboundJSFunctionCacheNode.executeCall(JSFunctionCallNode.java:1250)
    at com.oracle.truffle.js.nodes.function.JSFunctionCallNode.executeAndSpecialize(JSFunctionCallNode.java:291)
    at com.oracle.truffle.js.nodes.function.JSFunctionCallNode.executeCall(JSFunctionCallNode.java:237)
    at com.oracle.truffle.js.nodes.function.JSFunctionCallNode$CallNode.execute(JSFunctionCallNode.java:505)
    at com.oracle.truffle.js.nodes.JavaScriptNode.executeVoid(JavaScriptNode.java:212)
    at com.oracle.truffle.js.nodes.control.AbstractBlockNode.executeVoid(AbstractBlockNode.java:91)
    at com.oracle.truffle.js.nodes.control.AbstractBlockNode.executeVoid(AbstractBlockNode.java:74)
    at com.oracle.truffle.js.nodes.control.VoidBlockNode.execute(VoidBlockNode.java:58)
    at com.oracle.truffle.js.nodes.instrumentation.JSTaggedExecutionNode.execute(JSTaggedExecutionNode.java:113)
    at com.oracle.truffle.js.nodes.JavaScriptNode.executeVoid(JavaScriptNode.java:212)
    at com.oracle.truffle.js.nodes.control.AbstractRepeatingNode.executeBody(AbstractRepeatingNode.java:73)
    at com.oracle.truffle.js.nodes.control.WhileNode$DoWhileRepeatingNode.executeRepeating(WhileNode.java:186)
    at com.oracle.truffle.api.nodes.RepeatingNode.executeRepeatingWithValue(RepeatingNode.java:106)
    at com.oracle.truffle.api.impl.DefaultLoopNode.execute(DefaultLoopNode.java:71)
    at com.oracle.truffle.js.nodes.control.WhileNode.executeVoid(WhileNode.java:168)
    at com.oracle.truffle.js.nodes.control.DirectBreakTargetNode.executeVoid(DirectBreakTargetNode.java:73)
    at com.oracle.truffle.js.nodes.control.AbstractBlockNode.executeVoid(AbstractBlockNode.java:91)
    at com.oracle.truffle.js.nodes.control.AbstractBlockNode.executeVoid(AbstractBlockNode.java:74)
    at com.oracle.truffle.js.nodes.control.VoidBlockNode.execute(VoidBlockNode.java:58)
    at com.oracle.truffle.js.nodes.function.FunctionBodyNode.execute(FunctionBodyNode.java:73)
    at com.oracle.truffle.js.nodes.function.FunctionRootNode.executeInRealm(FunctionRootNode.java:147)
    at com.oracle.truffle.js.runtime.JavaScriptRealmBoundaryRootNode.execute(JavaScriptRealmBoundaryRootNode.java:93)
    at com.oracle.truffle.api.impl.DefaultCallTarget.call(DefaultCallTarget.java:102)
    at com.oracle.truffle.js.runtime.builtins.JSFunction.call(JSFunction.java:369)
    at com.oracle.truffle.js.runtime.JSRuntime.call(JSRuntime.java:2436)
    at com.oracle.truffle.trufflenode.GraalJSAccess.functionCall(GraalJSAccess.java:1295)
    at com.oracle.truffle.trufflenode.GraalJSAccess.functionCall0(GraalJSAccess.java:1304)
Caused by: Attached Guest Language Frames (5)

Debugging

I found that making the following changes to program.js cause NodeProf not to crash:

Haiyang-Sun commented 4 years ago

Hi, I have found the cause to the problem here and am still working on a solution to fix it. Will start a PR to Graal.js once done.

Haiyang-Sun commented 4 years ago

@mwaldrich You can already have a preview of my fix in this branch: https://github.com/Haiyang-Sun/nodeprof.js/commits/asyncawait-fix

It should be able to fix these problems you mentioned above.

mwaldrich commented 4 years ago

@Haiyang-Sun I tried using the new branch, and it seems not to crash anymore. Thanks!

eleinadani commented 4 years ago

@mwaldrich does the PR from @Haiyang-Sun (https://github.com/Haiyang-Sun/nodeprof.js/commits/asyncawait-fix) fix all the problems you reported above, or just the AssertionError crash in Nodeprof?