How to use the Tiny Profiler with Rhino

[StSchnell]

This post describes the use of Tiny Profiler in the context of Rhino. The profiler is a development from Johannes Bechberger aka @parttimenerd. It is a tiny sampling profiler for Java, based on the Thread.getAllStackTraces() method. You can find a very good introduction to Tiny Profiler in the SAP Community.

What is a Profiler?

A profiler is a tool to deeply analyze the program execution. It helps developers amongst other things to identify performance problems and bottlenecks. It collects detailed execution information at runtime, like the number of calls of functions, and summarizes these as a result. From this result the programmer can derive necessary steps at which point an optimization makes the most sense.

Code to be Analyzed

As an example of the code to be analyzed, we choose the calculation of the Fibonacci number - equivalent to Fib.java from Tiny Profiler.

function fib(n) {
  if (n <= 1) {
    return n;
  }
  return fib(n-1) + fib(n-2);
}

function main() {
  var i = fib(40);
  java.lang.System.out.println(String(i));
}

main();

The structure of the program consists of two functions, the main function and the function which calculates the Fibonacci number. The main function calls the calculation function and finally outputs the result.

Save this code with the file name fibExample.js and compile it with the command
java -cp ".;rhino-1.7.14.jar" org.mozilla.javascript.tools.jsc.Main -opt 0 -debug fibExample.js.

Decompilation of the Class File

Hint: This step is not necessary. It is only intended to show which Java code is generated from the JavaScript code by the Rhino engine. It will help us better understand the profiler's results.

To see how the JavaScript code is converted into the generated Java code, we decompile the class file. For this we use the Java decompiler CFR. With the command java -jar cfr-0.152.jar fibExample.class > fibExample.java we get the Java source.

Let's take a look at the structure of Java source code. Below is an excerpt that only contains the method names and the data types of its interfaces.

public class fibExample extends NativeFunction implements Script {

  public fibExample(Scriptable, Context, int)
  public fibExample()
  public static void main(String[])
  public final Object exec(Context, Scriptable)
  public final Object call(Context, Scriptable, Scriptable, Object[])
  public int getLanguageVersion()
  public String getFunctionName()
  public int getParamCount()
  public int getParamAndVarCount()
  public String getParamOrVarName(int)
  public String getEncodedSource()
  public boolean getParamOrVarConst(int)
  protected boolean isGeneratorFunction()
  private final void _i1(Context, Scriptable)
  private final void _i2(Context, Scriptable)

  private static Object _c_script_0(fibExample, Context, Scriptable, Scriptable, Object[])
  private static Object _c_fib_1(fibExample, Context, Scriptable, Scriptable, Object[])
  private static Object _c_main_2(fibExample, Context, Scriptable, Scriptable, Object[])

}

As we can see, the code generator creates methods from our JavaScript functions that start with _c_, then comes the function name followed by an index. The method representing the main script is always _c_script_0, in our case only the call of the main function. As we will see later, the main, exec and call methods are also important.

Execute the Program with Tiny Profiler

In the next and final step we now run the Java class with the Tiny Profiler. Use the command java -cp ".;rhino-1.7.14.jar" -javaagent:tiny_profiler.jar fibExample.

This call generates a long list of methods and thus provides very interesting information about which were used during execution. Here we focus on the method calls that belong to our program fibExample. Below is the excerpt.

Method                                     Samples Percent OnTop Percent
fibExample.main (fibExample.js:-1)             206   99,04     0    0,00
fibExample.exec (fibExample.js:-1)             197   94,71     0    0,00
fibExample.call (fibExample.js:-1)             197   94,71     0    0,00
fibExample._c_script_0 (fibExample.js:13)      197   94,71     0    0,00
fibExample._c_main_2 (fibExample.js:9)         195   93,75     0    0,00
fibExample._c_fib_1 (fibExample.js:5)          195   93,75   165   79,33
fibExample._c_main_2 (fibExample.js:10)          2    0,96     0    0,00
fibExample.<init> (fibExample.js:-1)             2    0,96     0    0,00

We start with the method main, which calls exec which calls call. The entry into our JavaScript takes place by calling the method _c_script_0. Behind the method call we see the name of the JavaScript file and the line in which the call is located. _c_script_0 calls the main function in methode _c_main_2 and that calls the fib function in methode _c_fib_1. Last but not least the result is output.

This simple example shows very clearly what information we can gain. We can understand which of our functions requires the most time consumption.

Conclusion

The Tiny Profiler is a great tool. In the context of JavaScript with the Rhino engine it delivers with great ease valuable information about program execution, and this without additional changes at the source code. Even if the code generation somewhat obscures the traceability, the basic structures of the JavaScript source code are clearly visible. This allows us to get information about potential for improvement in the area of performance optimizing. We also learn a lot about which methods are actually called in the background.