Get js stack in hermes engine

[ThomsonTong13]

Problem

I found that the runtime.cpp file in the hermes source code has getCallStackNoAlloc. I tried to make this API public and called it in objective-c, and found that the stack it got was empty. Why is this?

Additional Context

I have public this API in hermes.h file:

std::string getCallStackNoAlloc();

and indirect call in hermes.cpp file:

std::string HermesRuntime::getCallStackNoAlloc() {
  return impl(this)->runtime_.getCallStackNoAlloc();
}

After that, I get hermesRuntimeRef through the runtime of RCTBridge, which is the pointer of facebook::hermes::HermesRuntime. I use it to call the getCallStackNoAlloc API. The stack I get is always empty. I don’t know why.

[(RCTCxxBridge *)bridge.batchedBridge ensureOnJavaScriptThread:^{
    RCTCxxBridge *cxxbridge = (RCTCxxBridge*)(bridge.batchedBridge);
    DecoratedRuntime *decoratedRuntime = (DecoratedRuntime *)[cxxbridge runtime];
    if (decoratedRuntime) {
        facebook::hermes::HermesRuntime &hermesRuntimeRef = decoratedRuntime->getHermesRuntime();
        std::string stack = hermesRuntimeRef.getCallStackNoAlloc();
        printf("[Stack] %s\n", stack.c_str());
    }
}];

[avp]

There's a couple possible reasons you could be getting empty string back from this function.

1. You're calling into the Runtime when there are no call frames, i.e. from the event loop when no JS is executing. You'd have to ensure that you're looking for the callstack while the JS has frames currently running.
2. It's very unlikely, but maybe the HermesRuntime you're calling the function on is not pointing to a valid HermesRuntime.

[ThomsonTong13]

There's a couple possible reasons you could be getting empty string back from this function.

1. You're calling into the Runtime when there are no call frames, i.e. from the event loop when no JS is executing. You'd have to ensure that you're looking for the callstack while the JS has frames currently running.
2. It's very unlikely, but maybe the HermesRuntime you're calling the function on is not pointing to a valid HermesRuntime.

I think there is no problem with the HermesRuntime pointing, because I have tried to synchronously call the Native method from RN through JSI. At this time, calling getCallStackNoAlloc can get the stack.

Most likely it is due to the event loop when no JS is executing, but I have also tried calling it while monitor JSThread's RunLoop and calling it after suspending JSThread. Anyway, as long as it is actively obtained by Native, the JS call stack cannot be obtained through this API.

[fbmal7]

Is there a particular reason you need to use getCallStackNoAlloc? Otherwise this is quite simple to get the error string using JSI.

// Grab "Error" from the global namespace
auto errorObj = runtime_.global().getPropertyAsFunction(runtime_, "Error");

// var errInstance = Error();
auto errInstance = errorObj.call(runtime_).asObject(runtime_);

// var stack = errInstance.stack;
auto stack = errInstance.getProperty(runtime_, "stack");

if (stack.isString()) {
  // You now have a std::string you can do whatever you want with
  auto stackStr = stack.getString(runtime_).utf8(runtime_);
}

[ThomsonTong13]

Is there a particular reason you need to use getCallStackNoAlloc? Otherwise this is quite simple to get the error string using JSI.

// Grab "Error" from the global namespace
auto errorObj = runtime_.global().getPropertyAsFunction(runtime_, "Error");

// var errInstance = Error();
auto errInstance = errorObj.call(runtime_).asObject(runtime_);

// var stack = errInstance.stack;
auto stack = errInstance.getProperty(runtime_, "stack");

if (stack.isString()) {
  // You now have a std::string you can do whatever you want with
  auto stackStr = stack.getString(runtime_).utf8(runtime_);
}

I want to monitor the RunLoop of the jsThread and obtain the js stack after detecting timeout.

[fbmal7]

I'm still not sure I understand why you need to use getCallStackNoAlloc. Either way, this seems to be a question more so about RN, not Hermes. Hermes has no concept of a RunLoop or jsThread. Those exist at the RN layer. As @avp mentioned, it's most likely that you are simply calling into the runtime when there is no JS running. For instance, if your action of obtaining the JS stack is put on to the same queue as the pending JS work, then it makes sense you would always end up with an empty stack. By definition, the stack checking would execute after all JS is finished. But it is impossible to know without understanding the details of RN's threading model for JS execution.

[tmikov]

@ThomsonTong13 if you are detecting a timeout, does that mean that you want to obtain the stack asynchronously, while the JS is still running?

[ThomsonTong13]

@ThomsonTong13 if you are detecting a timeout, does that mean that you want to obtain the stack asynchronously, while the JS is still running?

Yes, I want to obtain the stack and report it at the time point when the freeze is detected.

The way to monitor lagging is to monitor the RunLoop of jsThread. To obtain the js stack, I saw that the hermes source code has the getCallStackNoAlloc API.

My idea is to set a timeout (for example, 1 second), and when the time interval between kCFRunLoopBeforeWaiting and kCFRunLoopAfterWaiting exceeds this time, call this API to obtain the stack for reporting, so that the execution time of the business function can be monitored and the user experience can be optimized.

[ThomsonTong13]

I'm still not sure I understand why you need to use getCallStackNoAlloc. Either way, this seems to be a question more so about RN, not Hermes. Hermes has no concept of a RunLoop or jsThread. Those exist at the RN layer. As @avp mentioned, it's most likely that you are simply calling into the runtime when there is no JS running. For instance, if your action of obtaining the JS stack is put on to the same queue as the pending JS work, then it makes sense you would always end up with an empty stack. By definition, the stack checking would execute after all JS is finished. But it is impossible to know without understanding the details of RN's threading model for JS execution.

I also realized that it was a problem with my calling timing, so I tried to call this API after suspending jsThread. Unfortunately, the stack I got was still empty.

The JSC engine has a watchdog mechanism, which provides a JSContextGroupSetExecutionTimeLimit API. I can set the timeout period and timeout callback. When the js code execution timeout, the timeout callback will be triggered. At this time, the stack can be obtained in this callback(get stack from JSC apis).

But I looked through the Hermes source code, and there is nothing related to watchdog. There is only a watchTimeLimit API that is similar to it, but unfortunately it is not.

[ThomsonTong13]

I'm still not sure I understand why you need to use getCallStackNoAlloc. Either way, this seems to be a question more so about RN, not Hermes. Hermes has no concept of a RunLoop or jsThread. Those exist at the RN layer. As @avp mentioned, it's most likely that you are simply calling into the runtime when there is no JS running. For instance, if your action of obtaining the JS stack is put on to the same queue as the pending JS work, then it makes sense you would always end up with an empty stack. By definition, the stack checking would execute after all JS is finished. But it is impossible to know without understanding the details of RN's threading model for JS execution.

I also realized that it was a problem with my calling timing, so I tried to call this API after suspending jsThread. Unfortunately, the stack I got was still empty.

The JSC engine has a watchdog mechanism, which provides a JSContextGroupSetExecutionTimeLimit API. I can set the timeout period and timeout callback. When the js code execution timeout, the timeout callback will be triggered. At this time, the stack can be obtained in this callback(get stack from JSC apis).

But I looked through the Hermes source code, and there is nothing related to watchdog. There is only a watchTimeLimit API that is similar to it, but unfortunately it is not.

Attached source code:

[neildhar]

@ThomsonTong13 When execution is interrupted due to a timeout (after setting watchTimeLimit), we throw a JavaScript exception carrying the stack. This exception cannot be caught in JS, but you can catch it in C++ and examine the exception message to determine the cause of the timeout.

For example:

try {
  // Run code that causes a timeout
}
catch (const jsi::JSError& err){
  const std::string &stack = err.getStack();
  // Examine stack
}

If you're looking to figure out where time is being spent in your application, we also expose methods to run a sampling profiler, that produces a trace which you can view in Chrome DevTools.

[ThomsonTong13]

@ThomsonTong13 When execution is interrupted due to a timeout (after setting watchTimeLimit), we throw a JavaScript exception carrying the stack. This exception cannot be caught in JS, but you can catch it in C++ and examine the exception message to determine the cause of the timeout.

For example:

try {
  // Run code that causes a timeout
}
catch (const jsi::JSError& err){
  const std::string &stack = err.getStack();
  // Examine stack
}

If you're looking to figure out where time is being spent in your application, we also expose methods to run a sampling profiler, that produces a trace which you can view in Chrome DevTools.

Thanks for your patient answer.

But we want to do is to automatically collect the stack of time-consuming methods of the program, rather than targeting a specific method or collecting it through debug tools.

The effect we want to achieve is to obtain the Android/iOS stuck method stack through this solution, report it for analysis, continuously optimize and improve the user experience.

I also tried using the method you mentioned to use a loop to continuously obtain the stack, but unfortunately I only got the stack of printLog, which could not achieve the effect I wanted.

DecoratedRuntime *decoratedRuntime = getDecoratedRuntimeForBridge(bridge);
if (decoratedRuntime != NULL) {
    facebook::hermes::HermesRuntime &hermesRuntimeRef = decoratedRuntime->getHermesRuntime();
    [NSTimer scheduledTimerWithTimeInterval:5 repeats:YES block:^(NSTimer * _Nonnull timer) {
        hermesRuntimeRef.watchTimeLimit(50);
        std::string injectedScript = "function printLog() { console.log('print log'); }  printLog();";
        auto buffer = std::make_shared<const facebook::jsi::StringBuffer>(injectedScript);
        try {
            hermesRuntimeRef.evaluateJavaScript(buffer, "Test");
        } catch (const facebook::jsi::JSError& error) {
            std::string stack = error.getStack();
            printf("This is a log message. %s\n", stack.c_str());
        }
    }];
}