Thursday, April 25, 2013

Probes or How to Analyze Application State in a Profiler

Disclaimer: I'm not affiliated with Yourkit, but I am grateful for their free licenses for open source projects. I've been using Yourkit for my work on Xtext and Xtend.


Introduction

Improving the performance of an application can be a challenging thing to do. As a developer, you usually have some immediate ideas of what are the performance bottlenecks. However, as Ed said in his presentation at EclipseCon North America 2013, "Don't trust yourself, don't trust your friends, and don't even trust me."

I fully approve his message. Why? Experience shows there is truth in this statement.

If trust doesn't work, we need facts: We need to measure. We need to measure how much time it takes to execute our program for specific tasks. Two tools probably come to your mind as you read this:

  • java.lang.System.nanoSeconds(): This simple but useful method gives you access to a decently precise time stamp at any time. You can call this method from your own code and calculate and report the time for what every your desire. But there's a catch: You need to modify the code that you want to inspect, which you sometimes can't do because the code is part of a library/framework or you just don't want to pollute the code.
  • A Profiler (such as Yourkit): This powerful tool lets you measure measure the execution time of every since method invocation. Sounds awesome? Yes, but there are some problems with it:
    • The "lost in the jungle syndrome": The result of a profiling session are a bunch of trees representing all states of the call stack your application had during the profiling session. And just like in a jungle, these trees are incredibly huge. Sometimes the profiler can point out some performance hot spots, but I think that only works well if you have some very obvious performance problems. So you end up spending a lot of time climbing through the trees, considering for every branch whether its existence and time consumption is justified.
    • Observing a system changes it: A profiler usually uses a java agent, which is a hook in the JVM that allows to manipulate class files before they're executed. This way the profiler can inject byte code for performance measurements into the to-be-analyzed classes. Surely this injected code is small and fast, but it can have an impact on how the Java JIT can optimize the byte code. Example: A method that could be in-lined before may not be in-lined anymore. I don't mind if an application runs slower during a profiling session, but I do mind if the times measured during profiling are disproportional to the actual times.
    • Parameter values are not available: To understand what the code is doing, you sometimes need to know the values of the method parameters. Consider questions such as: Does a certain value occur so often that introducing an early-exit to the method would improve the speed? Does the same value occur because the method was accidentally called from within a loop? Would it help to cache the result of the method?

Probes to the Rescue

Yourkit allows you to have so-called Probes. Here are some facts in a nutshell:

  • A probe is a Java class that hooks into the invocation of methods of the to-be-analyzed code. Such hooks can be registered to be invoked before or after a method has been invoked.
  • Installing pre-/post-invocation hooks into methods may sounds familiar to you from Aspect Oriented Programming (AOP). It's indeed the same kind of hook, but unlike in AOP you don't need to a special compiler: Yourkit registers the probes at runtime via its Java agent. Therefore, probes don't change your build and are applicable for already compiled libraries.
  • You can use probes independently of CPU profiling (sampling/tracing). A probe is active once it has been registered and you can choose not to enable CPU profiling at the same time. This may safe you from getting the "Observing a system changes it" bias.
  • Yourkit ships with a set of predefined probes for standard events, such as Tread lifecycles, file system I/O, etc. You can as well implement your own probes.
  • In a probe's implementation, you can access the hooked method's parameter- and return values.
  • Youkit encourages you to build a Java data structure for your measured data that resembles a relational data base. If you follow that pattern, Yourkit has a nice graphical user interface to explore your measured data.

Probing EMF ResourceSets and Resources

As an example and for further illustration, I've build a small probe that tracks instantiation of EMF ResourceSets and invocation of EMF Resources. In the terminology of the Eclipse Modeling Framework (EMF) a Resource usually represents a file from the file system. A resource furthermore provides implementations to load a file into memory as an object tree (aka model) or persist a tree back to disk.

The following screenshot shows an Eclipse IDE with two open editors. One editor shows an *.xtend file and the other one a *.genmodel. Even though both use EMF under the hood, they have little in common:

  1. The *.xtend text-editor shows a file persisted as plain text; It's Resource.load() implementation delegates to an ANTLR parser.
  2. The *.genmodel tree-editor shows the structure of a file that is persisted as XML. Here, an XML parser is used.

The Yourkit probe was registered while opening both editors. The following screenshot shows the measured data:

  • In the tree view on the left hand side you can see all available probes. The probe "EMF ResourceSets" has been developed by me, all others ship with Yourkit. The checkbox does not register/unregister the probe. The checkbox shows/hides the data measured by the probe in the views on the right-hand side of the tree-view.
  • The table on the top on the right-hand side shows a list of all ResourceSets that have been instantiated. The AdapterFactoryEditingDomainResourceSet is the one used by the *.genmodel editor. As you can see, there was more going on in my Eclipse instance before I took the screenshot. A click on the column labeled "stack trace" would reveal how a specific ResourceSet has been instantiated.
  • The table on the bottom right-hand side shows all invocations of Resource.load() for the ResourceSet that is selected in the table above. Here we can see that tracking of application state is possible: The column "uri" displays the file name of the file that has been loaded. The "wall time" is the time in milliseconds that was spent executing the load() method.

Implementing a Probe

You can find the full source code of this example here on github.

Before we start implementing a probe, some considerations:

  • The code that the probe hooks into needs to have the probe implementation on the classpath. Furthermore, it is helpful if the probe has the code it hooks into on the classpath, since otherwise the probe implementation would need to use Java reflection to inspect the to-be-analyzed object. This sounds tricky since it is in fact a cyclic dependency between the probe and the inspected code. Luckily Eclipse has a simple mechanism to contribute to a plugin's classapth: Fragments. A fragment is a bundle with class files, own dependencies and extension points that at runtime is integrated into the classpath of a chosen host-plugin. We choose org.eclipse.emf.ecore to be that host-plugin.
  • Probes need to be registered: We could do that by changing the JVM's startup arguments, but in an Eclipse environment it seems more convenient to use the extension point org.eclipse.ui.startup.
  • The probe implementation uses Java API provided by Yourkit. This API ca be found in /lib/yjp.jar inside the Yourkit installation.

The next screenshot shows the the implementation of the probe. It is a java class with static members to

  • define the data structures for storing the measured values (TABLE_RESOURCESET, TABLE_RESOURCE).
  • intercept calls to ResourceSet constructors (ResourceSetInit) and Resource#load() invocations.
  • map ResourceSet-Objects to Table-Row-IDs (rs2row and getResourceSetRow()).

Now that you've had an overview over the probe implementation, here is finally the core, the actual hooks: Each method-hook is a static Java class that can implement the static methods onEnter() and onReturn(). Annotations are used for further configuration:

  • @MethodPattern specifies the signature of the to-be-intercepted method.
  • @This gives access to the object on which the method has been called.
  • @OnEnterResult gives access to the return value of the onEnter method.
  • @Param(1) gives access to the first parameter of the intercepted method.
  • etc.

Conclusion

  1. Probes can deliver concise and precise performance measurements for an application or a group of applications that are based on the same frameworks/libraries.
  2. Probes have the potential to define reasonable performance metrics for specific applications that can be shared across a team of developers.
  3. Probes cause significantly less side-effects compared to general profiling.
  4. Probes can make use of more information than a profiler, such as application state, parameter values and return values.
  5. Implementing probes is some effort. This may be of less significance when probes can be reused. However, in scenarios were reuse in not intended - for example the explorative search for performance issues - their use may be too much effort.

Thursday, April 18, 2013

Pattern-Aware Formatting

During the last year I had the pleasure to implement a formatter for a programming language. You know, this little but incredibly useful thing that arranges indentation, line-wraps and whitespace in your code nicely. If you know me, you may have guessed that the programming languages in question is Xtend. Version 2.4.0 is the first version to ship with this formatter.

In case you haven't heard of Xtend, it is a language that compiles down to human-readable Java code and integrates seamlessly with any Java project.

We like to advertise Xtend as a language that is more concise and expressive compared to Java. And indeed it is, due to powerful type inference, higher-order functions, and less syntactical noise. Furthermore, Xtend supports concepts that provide a great degree of syntactical freedom to the developer. Among them are extension methods, operator overloading, and an implicit variable called "it".

This conciseness, expressiveness and syntactical freedom gives a great deal of power to the developer. This is a power a developer can use to increase his/her efficiency and at the same time write code in exactly that way that he/she considers the most readable to a human. It makes Xtend a perfect match for internal DSLs.

This has interesting consequences for formatting:

  • People who care about the readability of their code do have a strong opinion about formatting. This is easy to explain: Unformatted code just isn't readable.
  • But the strong opinion is about more than just having the code formatted. It's about having the code formatted in exactly the way they consider the most readable. Suddenly the formatting strategy doesn't depend on which syntactical element is being formatted, but on how a syntactical element is being used. This is an interesting thing I had to learn, as it is completely different from how the Eclipse Java formatter does its job.

The question is, how can a formatter decide how a syntactical element is being used? The amount of APIs, internal DSLs and programming styles converges to infinite, so there is no way of considering all of them. However, there are a small number of recurring formatting patterns.

Example 1: The If-Expression

This is probably how you would express it in Java: Imperative programming style and formatted as one line per statement:

var String z
if(variable == 1)
  z = "it is one"
else
  z = "it differs from one"

In Xtend, however, the if-statement is actually an if-expression, i.e. it has a result value. Java has an If-Expression as well, it is the ternary operator: (variable == 1) ? "then" : "else". Instead of assigning values inside the bodies of the if-statement, we can directly assign the if-expression. Besides being more concise, this has the tremendous advantage that the variable can be immutable and will never exist in an uninitialized state. Here is the snippet, we choose to keep the formatting style from the example above:

val y = if(variable == 1)
    "it is one"
  else
    "it differs from one"

We could also want to write it in a single line, just like you would do it with the ternary operator in Java:

val x = if(variable == 1) "it is one" else "it differs from one"

What we see here are two different formatting patterns that are alternative to each other. An if-expression can be formatted single-line as well as multi-line. You might argue that it should be formatted multi-line when it is used as a statement and single-line when it is used as an expression. While this might sound like a smart strategy at the beginning and it will probably work for most scenarios, it will frustrate the developer for the remaining cases. Frustration is something we should prevent by all costs. Therefore, the Xtend formatter leaves the choice to the developer: It recognizes which formatting pattern the developer had in mind. The decision strategy is as follows:

  1. If the then- or the else-body contain at least one line-wrap, format the if-expression multi-line.
  2. If the length of the full if-expression exceeds the maximum length of a line, format it multi line.
  3. Apply single-line formatting in all other cases.

This empowers the developer to choose for every individual if-expression, if he/she prefers the sing-line or multi-line style.

Example 2: Lambda-Expressions

Thanks to lambda-expressions you can choose a functional programming style when you work with Xtend. You can think of lambda-expressions as executable snippets of code that can be passed around in parameters and variables.

The following example calculates the total size of all files within the same directory. You can recognize the lambda-expressions by their square brackets "[" "]".

val file = new java.io.File(".")
val totalLength = file.listFiles.filter[isFile].map[length].reduce[x, y|x + y]
println("The size of all files in " + file + " is " + totalLength + " bytes.")

  • filter[isFile] removes all items from the list which are not files, such as directories.
  • map[length] converts a list of files into a list of integers, each representing the file size (length).
  • reduce[x, y|x + y] applies x + y to all list items until all are summed up to a single value.

I think there is some beauty in this code since you can understand it just by reading it from the left to the right. Furthermore, it is much more concise than anything you can do with loops in Java.

For this code to be readable, surely we want the lambda-expressions to be formatted without line-wraps, similar to parameters of a method call.

Another use case for lambdas is to provide handlers for events and asynchronous communication. The following example creates an instance of java.lang.Runnable that prints to stdout when run() is called.

val Runnable runnable = [ |
  println("Hello from " + Thread::currentThread.name)
]

Here, a multi-line style of the lambda-expression may be preferable if the implementation of the handler follows imperative programming style. If the lambda-expression does nothing but delegate to another method, a single-line style may be preferable.

A third use case for lambda-expression are named parameter values. In this example the assignments to name and priority are compiled to thread.setName(...) and thread.setPriority(...).

val thread = new Thread(runnable) => [
  name = "my thread"
  priority = Thread::MIN_PRIORITY
]

Here as well, a multi-line style is usually preferable.

Similar to if-expressions, there is no automated way for the formatter to decide for single-line or multi-line formatting. Therefore, the decision strategy is as follows:

  1. If there is a line-wrap before the closing bracket "]", apply multi-line style.
  2. If the the length of the closure exceeds the maximum line length, apply multi-line style.
  3. Apply single-line style in any other cases.

I decided that the "magic line-wrap" that triggers multi-line formatting of a lambda-expression should only be the line-wrap before the closing bracket "]" to make it easier to convert a multi-line lambda back to its single-line style. In this scenario, you'll only need to remove one single line-wrap and re-run the formatter instead of removing multiple line-wraps.

Other Examples You Can Try

As of Xtend 2.4.0, the following formatting patterns are supported besides the ones listed above:

  • single-line/multi-line style for method parameter declarations, triggered by the line-wrap before the closing parenthesis ")".
  • single-line/multi-line style for method call parameters, triggered by the line-wrap before the closing parenthesis ")".
  • switch-exprssions can be formatted single-line or multi line.
  • case-blocks inside switch-expressions can be formatted single-line or multi-line.