Thursday, June 28, 2012

Catch a StackOverFlowError by its tail

One of the more annoying situations you might have to deal with when working with a Java program is a StackOverFlowError, if you have a nice producible test case then there are few options with regard to playing with the stack size, or setting a conditional breakpoint / trace of some kind.

But if you have a test case that might fail once in a 100 times, perhaps a race condition in AWTMulticaster as in my case, then you want to improve the diagnostics. The problem is that by default the VM won't any elements in a stack trace after the first 1024 entries. (At least for JDK 6) So if you run the following trivial example:

package other;

public class Overflow {


   public static final void call(double a, double b, double c, double d) {
       call(a,b,c,d);
   }


   public static void main(String[] args) {
       call(0,0,0,0);
   }

}

The output will stop before you get to the cause of the problem, making it very hard to resolve the issue.

> java other.Overflow 
Exception in thread "main" java.lang.StackOverflowError
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
        [ lots of lines removed ]
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
Process exited with exit code 1.

The good news is that this limit is one of the many official and unofficial things you can tweak when starting a VM.


> java -XX:MaxJavaStackTraceDepth=1000000 other.Overflow 
Exception in thread "main" java.lang.StackOverflowError
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
        [ lots of lines removed ]
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.call(Overflow.java:7)
 at other.Overflow.main(Overflow.java:12)
Process exited with exit code 1.

Notice that end of the stack now contains the root of the problem which will be incredibly useful when trying to diagnose the issue.

You probably don't want to leave this property set long term on a production servers because I am not entirely sure about the impact of it. Looking at the C++ code it appears that this is just a maximum value and won't affect most other stack traces as they are allocated in a linked list in segments of 32 entries.

Wednesday, May 30, 2012

try/with/resources refactoring that isn't


So I was looking at refactoring some code to use the new try/with/resources construct and found that perhaps it is not as simple as it first appears.

class Close implements AutoCloseable
   {
       @Override
       public void close() {
           System.out.println("Close");
       }
   }


   System.out.println("Normal version");


   Close close = new Close();
   try {
       throw new Error();
   }
   catch (Error e) {
       System.out.println("Catch");
   }
   finally {
       close.close();
   }

So the output for this is pretty easy to predict; but lets write it out just to be clear.

Normal version
Catch
Close

So this is pretty easy, lets throw some JDK 7 goodness on the code, this is an obvious refactoring right?

System.out.println("JDK 7 version");

   try (Close close2 = new Close()) {
       throw new Error();
   }
   catch (Error e) {
       System.out.println("Catch");
   }

So you can be pretty sure that given I am writing this up that the output is not going to be the same.


JDK 7 version
Close
Catch

So in this case the close is called before the catch, this might not be a problem but in some cases the catch block might need to make use of the resource before everything is shut down. If you want to perform a "refactoring" the code must behave the same before and after the changes. The following code is equivalent to the JDK 7 version without the try/with/resources

System.out.println("JDK 6 equivalent of JDK 7 version");

   Close close3 = new Close();
   try {
       try {
           throw new Error();
       }
       finally {
           close3.close();
       }
   }
   catch (Error e) {
       System.out.println("Catch");
   }


Just for completeness here is one possible refactoring of the original code which is functionally equivalent. Note quite as pretty I am afraid.

System.out.println("JDK 7 equivalent of original try/catch/finally");

   try (Close close4 = new Close()) {
       try {
         throw new Error();
       }
       catch (Error e) {
           System.out.println("Catch");
       }
   }

Now I ran this past my colleague Mark Warner and like me was surprised by the result. Mark pointed out that this nuance is noted in the java tutorial....

Note: A try-with-resources statement can have catch and finally blocks just like an ordinary try statement. In a try-with-resources statement, any catch or finally block is run after the resources declared have been closed.

...but it does feel like this rather important distinction is part of the small print that some people might at first glance assumed is related to the SQL example above it. (Yeah okay I didn't read the SQL example down to the end)

Again not something that will be a problem all the time; but it might be an important consideration in some quite important use cases.


try/with/resource context class loaders


For various reasons I seem to end up writing a lot of code that fiddles with the context class loader in order to get non-module code running in the OSGi environment that JDeveloper runs in. This leads to a whole bunch of code that looks like this:

 public void doSomething() {

       ClassLoader context = Thread.currentThread().getContextClassLoader();

       try {
           Thread.currentThread().setContextClassLoader(Example.class.getClassLoader());

           // Class class that required the context class loader
           Endpoint.publish(null, null);            
       }
       finally {
           Thread.currentThread().setContextClassLoader(context);

       }  
  }


Now it occurred to me that the try/with/resources feature in JDK 7 isn't just for the nasty things in life, well resources, you can use it for any operation that might previously used a try/finally for.



   public void doSomething() {

       try (CloseableContext c = contextClassLoader(Example.class)) {

           // Class class that required the context class loader
           Endpoint.publish(null, null);            
       }
   }


It would have been nice to just call the method an not to allocate any variables as in the following example but it isn't allowable in the spec.


   public void doSomething() {

       try (contextClassLoader(Example.class)) { // Compilation errors

           // Class class that required the context class loader
           Endpoint.publish(null, null);            
       }
   }


Still the implementation of this is rather trivial and does still tidy up the original code. The only wrinkle is the  need to have a public class/ interface subtype of AutoCloseable so that we can narrow the throws clause on the close() operation. If you don't do this then the original code has to deal with "throws Exception".



   public static CloseableContext contextClassLoader(Class loader) {
       return contextClassLoader(loader.getClassLoader());
   }

   public static CloseableContext contextClassLoader(ClassLoader loader) {
       final Thread currentThread = Thread.currentThread();
       final ClassLoader ocl = currentThread.getContextClassLoader();
       currentThread.setContextClassLoader(loader);
       return new CloseableContext(currentThread, ocl);
   }

   public static class CloseableContext implements AutoCloseable {
       private Thread _currentThread;
       private ClassLoader _ocl;

       private CloseableContext(Thread currentThread, ClassLoader ocl) {
           this._currentThread = currentThread;
           this._ocl = ocl;
       }

       @Override
       public void close() {
           this._currentThread.setContextClassLoader(this._ocl);
       }
   }

Saturday, May 26, 2012

Ignoring the return value of a command in Hudson/Jenkins sh task

So I was was trying to run pylint and nosetest running on a Jenkins instance; but these python commands tend to return a non zero status code if they see a non zero return code. This is a problem as it means that any further steps are ignored. The most obvious thing to try was this:

pylint src/openhea -f parseable ; true

The problem is that both statements are treated as separate steps so when the first one fails it never does the return true. Instead, and pointed out by a helpful chap in the #efdhack2012 room was to do the following

pylint src/openhea -f parseable || true

This correctly ignores the false status code, the only wrinkle is that you need to be careful when piping the output, it has to be to the left of the bars.

pylint src/openhea -f parseable > output.report || true

Thursday, May 10, 2012

Common try-with-resources idiom won't clean up properly

So I was re-reading some blogs on the JDK 7 language changes and I noticed the following idiom seems popular:

//
try (BufferedReader br = new BufferedReader(
        new FileReader("/tmp/click.xml"))) {
   System.out.println(br.readLine());
}

That seems all well and good; but consider what happens should something goes wrong constructing the BufferedReader. The contract for try-with-resources will only try to close and tidy up the declared field, if something goes wrong then FileReader is never closed.

So consider this example where the constructor of BufferedReader throws an Error, it could well be an OutOfMemoryError or any number of other failure modes.

//
package client;

import java.io.*;

public class BufferedFileExample {

    public static void main(String[] args) throws FileNotFoundException, 
                                                  IOException {

        try (BufferedReader br = new MyBufferedReader(
            new MyFileReader("/tmp/click.xml"))) {
            System.out.println(br.readLine());
        }
    }
    
    public static class MyFileReader extends FileReader 
    {

        public MyFileReader(String in) throws FileNotFoundException {
            super(in);
        }
        
        public void close() throws IOException {
            super.close();
            System.out.println("Close called");
        }
    }
    
    
    
    public static class MyBufferedReader extends BufferedReader 
    {

        public MyBufferedReader(Reader in) {
            super(in);
            throw new Error();
        }
    }
}

This gets us the following output and as such the close is not performed on the FileReader which until the finaliser is called. You are stuck until the gc wakes up in the future to tidy it up.

Exception in thread "main" java.lang.Error
 at client.BufferedFileExample$MyBufferedReader.(BufferedFileExample.java:38)
 at client.BufferedFileExample.main(BufferedFileExample.java:12)
Process exited with exit code 1.

Luckily there is an easy fix for this, the language change supports multiple entries in try statement, so you can modify this code to be:

//
try (FileReader fr = new MyFileReader("/tmp/click.xml");
     BufferedReader br = new MyBufferedReader(
        fr)) {
   System.out.println(br.readLine());
}

So if you run the code with the modification above then you find that close is now called:

Close called
Exception in thread "main" java.lang.Error
 at client.BufferedFileExample$MyBufferedReader.(BufferedFileExample.java:38)
 at client.BufferedFileExample.main(BufferedFileExample.java:12)
Process exited with exit code 1.

So problem solved, well unfortunately there is another wrinkle here, if we remove the code that throws the Error then we will see the following output:

Close called
Close called
Process exited with exit code 0.

So this is fine for classes that implement the existing java.io.Closeble interface because calling close for a second time is fine; but the more generic interface that is used for other closeable resources unfortunately doesn't have this restriction, so quote the spec

Note that unlike the close method of Closeable, this close method is not required to be idempotent. In other words, calling this close method more than once may have some visible side effect, unlike Closeable.close which is required to have no effect if called more than once. However, implementers of this interface are strongly encouraged to make their close methods idempotent.

So in order to using a split-try-with-resources idiom you first need to make sure that the resources have a idempotent close method. I suspect that most API will do this; but you need to check first and perhaps need to further wrap your objects to make this the case.

One final point with try-with-resource is the handling of exceptions when the close and construction fails. JDK 7 introduced the concept of suppressed exceptions, so you it make the split version of the code throw an exception both in the constructor or the MyBufferedReader and in the close of MyFileReader you get to see the following novel stack trace.

Close called
Exception in thread "main" java.lang.Error
 at client.BufferedFileExample$MyBufferedReader.(BufferedFileExample.java:38)
 at client.BufferedFileExample.main(BufferedFileExample.java:12)
 Suppressed: java.lang.Error: close
  at client.BufferedFileExample$MyFileReader.close(BufferedFileExample.java:27)
  at client.BufferedFileExample.main(BufferedFileExample.java:14)
Process exited with exit code 1.

This might not be what you calling code is expecting - certainly it might differ slightly from what the try/finally code you are replacing would produce, worth know thing that exceptions are handled slightly differently. For example if there is just an Error thrown during the close method would would see this odd self-referential stack trace.

Close called
Close called
Exception in thread "main" java.lang.Error: close
 at client.BufferedFileExample$MyFileReader.close(BufferedFileExample.java:28)
 at java.io.BufferedReader.close(BufferedReader.java:517)
 at client.BufferedFileExample.main(BufferedFileExample.java:15)
 Suppressed: java.lang.Error: close
  at client.BufferedFileExample$MyFileReader.close(BufferedFileExample.java:28)
  ... 1 more
Process exited with exit code 1.

So the lesson here is that the impact of some of the new JDK 7 constructs are going to a little bit subtler than we might expect. Many thanks to my valued colleague Mark Warner for talking this one through with me.

Tuesday, April 3, 2012

Off-loading test execution using Hudson part 3, skipping the queue

Previously I had looked at preflighting, (1, 2) with Hudson (And Jenkins) but forgot to mention a very important plugin that is essential if you want to convince your developer to preflight there work. The problem is that is the slave allotment/smallholder/farm is busy running other jobs then they are forced to wait before merging.

The easy solution to this problem is the priority sorter plugin. This allows you to specify that some jobs are more or less important then others. The default priority is 100, so seeing your preflight job to 1000 should see it jump to the front of the queue.

It is interesting how the length of tests affects my commuting behaviour, now that is take around an hour to run the long tests just for our components. It makes sense to start a work at home, kick of a job and you should have you nice shiny test results by the time we get into work. One day I might even get a blue ball if I am so very lucky with our dependencies. :-)

Friday, March 16, 2012

Catalog support for WADL client generation

I have just been fixing a few bugs in the WADL client generator that I have been working on recently. In particular one bug relates to being able to control the server the client uses at deploy time. (WADL-44)

So for example you have a standard packaged ?ar file that contains a client to a production service, in order to run automated testing you want to be able to use the same archive; but redirect the request to an internal server. Using a deployment plan, for example, you can update or introduce an extra deployment descriptor called META-INF/jax-rs-catalog.xml.

Only the base URI for each root resource in the WADL is updated; but this should be enough for most cases. (Would be interested to hear where people though this was limiting). This simple example redirects the client from a production service to a qa server.

<catalog xmlns="urn:oasis:names:tc:entity:xmlns:xml:catalog">
  <uri name="http://production.example.com/resource"
          uri="http://qa.example.com/resource"/>
</catalog>

If you want to play with this you are going to have to check out the tip of the WADL client project for the moment; but in the coming weeks it will be part of the 1.1.2 release. Feedback always welcome.