Tuesday 22 December 2015

How long does it take the jvm to effect escape analysis? Maybe longer than you think.

This post looks at escape analysis, in particular how long it takes for the jvm to effect escape analysis in a running program. I make some observations but don't have all the explanation at this point.

By way of introduction let's take a detour to look at a little known and even less used flag (which we'll see is a good thing) in the jvm, -Xcomp

The behaviour for this flag is defined in the jvm documentation as:




-Xcomp





Forces compilation of methods on first invocation. By default, the Client VM (-client) performs 1,000 interpreted method invocations and the Server VM (-server) performs 10,000 interpreted method invocations to gather information for efficient compilation. Specifying the -Xcomp option disables interpreted method invocations to increase compilation performance at the expense of efficiency.


At first sight this seems to be an excellent option.  A shortcut to warming up the jvm through 10,000 cycles - we can get the code to compile straight away. Shouldn't we always enable this option by default?

But the documentation does warn that this will be 'at the expense of efficiency'.

The jvm learns about code behaviour in the 10,000 warmup cycles so that when it comes to compiling it compiles in the most efficient way possible.  Compiling the code right away will mean that yes the code is indeed compiled but that the compiled code may not be the most efficient. You can read more about it in this blogpost - but that's not really the subject of this post.

Something else that doesn't happen if you use -Xcomp is escape analysis. This is actually rather surprising as the jvm shouldn't need to learn about whether escape analysis is possible by running the program.  This should be evident by a static analysis of the code.

Have a look at this code (I was inspired by the ideas in this blog):


We need to make sure that the program runs without a gc (I suggest these flags):

-verbosegc -Xmx4g -Xms4g

When the program waits for input carry out a heap dump to see how many Optional object have been created. Then hit any key to resume the program.

To perform a heap dump first run jps to identify the pid of the program then run:

jmap -histo pid | head
  
Do this once without the -Xcomp flag and once with -Xcomp flag.

Without the -Xcomp flag:

After first iteration:


num     #instances         #bytes  class name
----------------------------------------------
   1:           644      123241360  [I
   2:        234496        3751936  java.util.Optional
   3:          6582         791968  [C
   4:          2717         540712  [B
   5:          4786         114864  java.lang.String
   6:           662          75144  java.lang.Class
   7:          1349          63912  [Ljava.lang.Object;

After second iteration:

num     #instances         #bytes  class name
----------------------------------------------
   1:           644      116687472  [I
   2:        644095       10305520  java.util.Optional
   3:          6583         792056  [C
   4:          2717         540712  [B
   5:          4787         114888  java.lang.String
   6:           662          75144  java.lang.Class
   7:          1349          63912  [Ljava.lang.Object;

All subsequent iterations are the same no further objects are created:

There's clearly escape analysis kicking in after 234k iterations - not sure why it should take so long, usually (for example with compiling code) 10k iterations is enough? Also in the second iteration it creates another ~400k objects before escape analysis kick in which is also a bit mysterious.

With the -Xcomp flag

After the first iteration:


num     #instances         #bytes  class name
----------------------------------------------
   1:           653      153880352  [I
   2:       1000001       16000016  java.util.Optional
   3:          7397         834744  [C
   4:          2717         540728  [B
   5:          5685         136440  java.lang.String
   6:           672          76208  java.lang.Class
   7:          1349          63912  [Ljava.lang.Object;

After the second iteration:


num     #instances         #bytes  class name
----------------------------------------------
   1:           654      159354896  [I
   2:       2000001       32000016  java.util.Optional
   3:          7398         834832  [C
   4:          2717         540728  [B
   5:          5686         136464  java.lang.String
   6:           672          76208  java.lang.Class
   7:          1349          63912  [Ljava.lang.Object;

After each iteration the number of Optional objects goes up by 1m.



Summary

  • -Xcomp is a switch that should almost certainly never be used in production. I can imagine some scenarios where you might want to play around with disabling the interpreter but those would be very specific edge cases. 
  • It seems to take at least 200K iteration for escape analysis to be effective.  So you need to allow longer than the 10k iterations for a full warm up.
  • There is also another phase where after escaping out objects it seems to need to do this again. This needs further understanding. 
  • If you slow the program down a bit by doing some work in between the calls to create the Optional the number of objects reduces.  For example I found that a call to Math.sin reduces the Optional objects by about 50%.

Monday 14 December 2015

One liner JUnit Productivity Tip

There's nothing clever or complicated about this tip - nevertheless it's one that once discovered saved me a lot of time.

The tip is for the case when you're comparing two long strings.

Say you have the following code which compares two strings:

String expect = "a,aah,aahed,aahing,aahs,aardvark,aardvarks,aardwolf,ab,abaci,aback,abacus,abacuses,abaft,abalone,abalones,abandon,abandoned,abandonedly,abandonee,abandoner,abandoners,abandoning,abandonment,abandonments,abandons,abase,abased,abasedly,abasement,abaser,abasers,abases,abash,abashed,abashedly,abashes,abashing,abashment,abashments,abasing,abatable,abate,abated,abatement,abatements,abater,abaters,abates,abating,abatis,abatises,abator,abattoir,abattoirs,abbacies,abbacy,abbatial,abbe,abbes,abbess,abbesses";
String actual = "a,aah,aahed,aahing,aahs,aardvark,aardvarks,aardwolf,ab,abaci,aback,abacus,abacuses,abaft,abalone,abalones,abandon,abandoned,abandonedly,abandonee,abandoner,abandoners,abandoning,abandonment,abandonments,abandons,abase,abased,abasedly,abasement,abaser,abasers,abases,abash,abashed,abashedly,abashes,abashing,abashment,abashments,abasing,abatable,abate,abated,abatement,abatements,abater,abaters,abates,abating,abatis,abatises,abator,abattoir,abattoirs,abbacies,abbacy ,abbatial,abbe,abbes,abbess,abbesses";

assertEquals(expect, actual);

As it happens these strings are not exactly the same so you get this failure message when you run the test in IntelliJ:

org.junit.ComparisonFailure: 
Expected :a,aah,aahed,aahing,aahs,aardvark,aardvarks,aardwolf,ab,abaci,aback,abacus,abacuses,abaft,abalone,abalones,abandon,abandoned,abandonedly,abandonee,abandoner,abandoners,abandoning,abandonment,abandonments,abandons,abase,abased,abasedly,abasement,abaser,abasers,abases,abash,abashed,abashedly,abashes,abashing,abashment,abashments,abasing,abatable,abate,abated,abatement,abatements,abater,abaters,abates,abating,abatis,abatises,abator,abattoir,abattoirs,abbacies,abbacy,abbatial,abbe,abbes,abbess,abbesses
Actual   :a,aah,aahed,aahing,aahs,aardvark,aardvarks,aardwolf,ab,abaci,aback,abacus,abacuses,abaft,abalone,abalones,abandon,abandoned,abandonedly,abandonee,abandoner,abandoners,abandoning,abandonment,abandonments,abandons,abase,abased,abasedly,abasement,abaser,abasers,abases,abash,abashed,abashedly,abashes,abashing,abashment,abashments,abasing,abatable,abate,abated,abatement,abatements,abater,abaters,abates,abating,abatis,abatises,abator,abattoir,abattoirs,abbacies,abbacy ,abbatial,abbe,abbes,abbess,abbesses

 

The error messages isn't particularly helpful to say the least....

Fortunately IntelliJ provides us with a 'click to see the difference dialog' - but when you click and open the dialog, although it will highlight the difference it's really not immediately obvious where the differences are and you end up scrolling a very long way to find them. And it's certainly impossible to see all the differences at a glance.



So here's the tip instead of this:

assertEquals(expect, actual);

Insert new lines into your string as below:

assertEquals(expect.replace(',', '\n'), actual.replace(',', '\n'));

Then when you click to see the difference you get a dialog that looks like this and you 
are able to see the issues at a glance. Simple but effective.


 





Thursday 10 December 2015

7 Tips for Successful Code Generation in Java

By way of introduction, I've been a bit quiet recently and part of the reason for that is that I've been busy working on Chronicle-FIX. This is a new ultra low latency library in the Chronicle-Enterprise suite where we have proven that we can parse and store message in low single digit micro-seconds.  Of course it leverages our open source products Chronicle-Queue, Chronicle-Network and Chronicle-Bytes

One of the secrets of the low latency we achieve is that each implementation can generate a custom built fix engine based exactly on the schema it requires. In order to achieve this I've built a whole lot of code generation code.

So I thought I would share some of the lessons I learnt during this process.

1. Use a code generation library

This is by far the most important tip. I can't stress enough how important this is and how much time and complexity you will save.  You really don't want to be messing around trying to get the correct spacing in you code or doubly and triply escaping quotes when creating string literals!

I used JavaPoet, it's open source (Apache 2) and it is excellent. It handled everything I wanted to do including some quite complex generics. The only thing it didn't support was declaring static imports but that was easy to work around and an insignificant quibble for what was an excellent library.

JavaPoet decomposes Java code into objects: TypeSpec (the class or interface), MethodSpec (methods), FieldSpec (fields), CodeBlocks (blocks of code).  It cleverly provides a rich syntax for building up statements (lines of code) based on the printf pattern. You will find that following this paradigm will leave you with cleaner and more succinct code than trying to this yourself where it's easy to stray down the procedural coding route for this type of problem.

2. Write the code by hand first

Don't try and code generate without having written some example code first. It's not easy coding through the rear view mirror, and double complicated if you're working it out as you go along.

Spend a little bit of time write the code by hand first and then produce the code generation for it.

Additionally you will be wanting to produce the most optimal code possible which can only be done if you spend the time and effort writing it by hand first.  

3. Generate as little code as possible

Generate only as much code as you need. So for example, if all your generated classes need to implement a certain method use a helper class that can be called by the generated code rather than generating that method multiple times. Alternatively get your code to extend a static base class with the method on the base class.

4. Make sure you can blow away all generated code in one go

Don't mix your static code with your generated code. What you want to do is to have a package like com.test.generatedcode.xx.xx.  At the end of each test/development run you should be able to delete the whole folder com/test/generatedcode which means that you have no static code in that folder at all.

You will find that arranging your code in this way will make the testing cycle that much faster.

5. Start with a small verifiable set of code

The point of code generation is often to produce lots of code. It can be hard to test whether the code you have produced is correct or not.  For this reason start with a small but complex example that you can check both by reading the code and for which you have a test case.

Hopefully for cases after that it will be more of the same.

6. Generate test cases 

As mentioned in point 5) verifying that your code generator is correct for all cases can be difficult.  For this reason you should try and generate test cases as part of the code that is generated. You can then generate many skews of complicated code from your generator and have it test itself.

7. Be verbose

Code to generate code, by its nature, can be extremely difficult to read and understand. Code generating code will never have to be fast so don't worry about making it verbose. Use lots of comments but more importantly try and make it as explicit as possible so that you will be able to look back at it in a year and still be able to maintain it.