Chasing reason for a deadlock in JDK

Last week I spent a couple of days on a strange deadlock issue revealed during JBossWS testsuite runs on my Husdon QA environment.

This kind of issues usually pops up through a test / section of the software that simply hangs without no evident reason. You don’t get continuous integration results for a day or such, then wonder what’s happening, go and check Hudson and start thinking and asking yourself what might have gone bad. In my case it was really “asking yourself” as of course this happened exactly when I was back from a vacation week and my colleagues that were working on the project were not online ;-)   (to be honest at the end it turned out not to be their fault at all)

OK, so you start by getting a thread dump to confirm you’re seeing a deadlock; that’s a simple “kill -3 pid” when running on Linux. Here is mine:

[junit] Found one Java-level deadlock:
[junit] =============================
[junit] "pool-1-thread-1":
[junit]   waiting to lock monitor 0x000000005d2c60c0 (object 0x00002aaadfb10fd8,
                                          a sun.net.www.protocol.file.Handler),
[junit]   which is held by "main"
[junit] "main":
[junit]   waiting to lock monitor 0x000000005cb02a58 (object 0x00002aaadfb10e38,
                                          a sun.misc.Launcher$AppClassLoader),
[junit]   which is held by "pool-1-thread-1"
[junit]
[junit] Java stack information for the threads listed above:
[junit] ===================================================
[junit] "pool-1-thread-1":
[junit] 	at java.net.URLStreamHandler.getHostAddress(URLStreamHandler.java:412)
[junit] 	- waiting to lock <0x00002aaadfb10fd8> (a sun.net.www.protocol.file.Handler)
[junit] 	at java.net.URLStreamHandler.hostsEqual(URLStreamHandler.java:439)
[junit] 	at sun.net.www.protocol.file.Handler.hostsEqual(Handler.java:117)
[junit] 	at java.net.URLStreamHandler.sameFile(URLStreamHandler.java:396)
[junit] 	at java.net.URLStreamHandler.equals(URLStreamHandler.java:316)
[junit] 	at java.net.URL.equals(URL.java:842)
[junit] 	at java.security.CodeSource.equals(CodeSource.java:135)
[junit] 	at java.util.HashMap.get(HashMap.java:305)
[junit] 	at java.security.SecureClassLoader.getProtectionDomain(SecureClassLoader.java:233)
[junit] 	- locked <0x00002aaadfb11120> (a java.util.HashMap)
[junit] 	at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:141)
[junit] 	at java.net.URLClassLoader.defineClass(URLClassLoader.java:283)
[junit] 	at java.net.URLClassLoader.access$000(URLClassLoader.java:58)
[junit] 	at java.net.URLClassLoader$1.run(URLClassLoader.java:197)
[junit] 	at java.security.AccessController.doPrivileged(Native Method)
[junit] 	at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
[junit] 	at java.lang.ClassLoader.loadClass(ClassLoader.java:307)
[junit] 	- locked <0x00002aaadfb10e38> (a sun.misc.Launcher$AppClassLoader)
[junit] 	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:301)
[junit] 	- locked <0x00002aaadfb10e38> (a sun.misc.Launcher$AppClassLoader)
[junit] 	at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
[junit] 	at org.xnio.nio.AbstractNioChannelThread.cancelKey(AbstractNioChannelThread.java:298)
[junit] 	at org.xnio.nio.NioHandle.cancelKey(NioHandle.java:56)
[junit] 	at org.xnio.nio.AbstractNioStreamChannel.cancelWriteKey(AbstractNioStreamChannel.java:241)
[junit] 	at org.xnio.nio.NioTcpChannel.shutdownWrites(NioTcpChannel.java:164)
[junit] 	at org.xnio.channels.TranslatingSuspendableChannel.shutdownWrites(TranslatingSuspendableChannel.java:358)
[junit] 	at org.xnio.channels.FramedMessageChannel.shutdownWrites(FramedMessageChannel.java:255)
[junit] 	- locked <0x00002aaadfb11978> (a org.xnio.ByteBufferSlicePool$PooledByteBuffer)
[junit] 	at org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener.send(RemoteConnection.java:267)
[junit] 	- locked <0x00002aaadfb119a0> (a org.jboss.remoting3.remote.RemoteConnection)
[junit] 	at org.jboss.remoting3.remote.RemoteConnection.sendCloseRequest(RemoteConnection.java:164)
[junit] 	at org.jboss.remoting3.remote.RemoteConnection.handleOutboundCloseRequest(RemoteConnection.java:149)
[junit] 	at org.jboss.remoting3.remote.RemoteConnectionHandler.closeAction(RemoteConnectionHandler.java:173)
[junit] 	at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync(AbstractHandleableCloseable.java:354)
[junit] 	at org.jboss.remoting3.ConnectionImpl.closeAction(ConnectionImpl.java:48)
[junit] 	at org.jboss.remoting3.spi.AbstractHandleableCloseable.close(AbstractHandleableCloseable.java:149)
[junit] 	at org.xnio.IoUtils.safeClose(IoUtils.java:134)
[junit] 	at org.jboss.as.protocol.ProtocolChannelClient.close(ProtocolChannelClient.java:176)
[junit] 	at org.xnio.IoUtils.safeClose(IoUtils.java:134)
[junit] 	at org.jboss.as.protocol.mgmt.ManagementClientChannelStrategy$Establishing.requestDone(ManagementClientChannelStrategy.java:138)
[junit] 	at org.jboss.as.protocol.mgmt.ManagementRequest$DelegatingResponseHandler.readResponse(ManagementRequest.java:178)
[junit] 	at org.jboss.as.protocol.mgmt.ManagementChannel$ResponseReceiver.handleResponse(ManagementChannel.java:375)
[junit] 	at org.jboss.as.protocol.mgmt.ManagementChannel$ResponseReceiver.access$400(ManagementChannel.java:357)
[junit] 	at org.jboss.as.protocol.mgmt.ManagementChannel.doHandle(ManagementChannel.java:120)
[junit] 	at org.jboss.as.protocol.ProtocolChannel.handleMessage(ProtocolChannel.java:158)
[junit] 	at org.jboss.remoting3.remote.RemoteConnectionChannel$4.run(RemoteConnectionChannel.java:224)
[junit] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[junit] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[junit] 	at java.lang.Thread.run(Thread.java:619)
[junit] "main":
[junit] 	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:293)
[junit] 	- waiting to lock <0x00002aaadfb10e38> (a sun.misc.Launcher$AppClassLoader)
[junit] 	at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
[junit] 	at java.net.URL.getURLStreamHandler(URL.java:1144)
[junit] 	at java.net.URL.<init>(URL.java:393)
[junit] 	at java.net.URL.<init>(URL.java:283)
[junit] 	at java.net.URL.<init>(URL.java:306)
[junit] 	at sun.net.www.protocol.file.Handler.openConnection(Handler.java:74)
[junit] 	- locked <0x00002aaadfb10fd8> (a sun.net.www.protocol.file.Handler)
[junit] 	at sun.net.www.protocol.file.Handler.openConnection(Handler.java:55)
[junit] 	- locked <0x00002aaadfb10fd8> (a sun.net.www.protocol.file.Handler)
[junit] 	at java.net.URL.openConnection(URL.java:945)
[junit] 	at sun.net.www.protocol.jar.JarURLConnection.<init>(JarURLConnection.java:66)
[junit] 	at sun.net.www.protocol.jar.Handler.openConnection(Handler.java:24)
[junit] 	at java.net.URL.openConnection(URL.java:945)
[junit] 	at org.apache.cxf.common.logging.JDKBugHacks.doHacks(JDKBugHacks.java:67)
[junit] 	at org.apache.cxf.common.logging.LogUtils.<clinit>(LogUtils.java:66)
[junit] 	at org.apache.cxf.jaxws.spi.ProviderImpl.<clinit>(ProviderImpl.java:61)
[junit] 	at java.lang.Class.forName0(Native Method)
[junit] 	at java.lang.Class.forName(Class.java:247)
[junit] 	at java.util.ServiceLoader$LazyIterator.next(ServiceLoader.java:345)
[junit] 	at java.util.ServiceLoader$1.next(ServiceLoader.java:421)
[junit] 	at javax.xml.ws.spi.Provider.getProviderUsingServiceLoader(Provider.java:146)
[junit] 	at javax.xml.ws.spi.Provider.provider(Provider.java:106)
[junit] 	at javax.xml.ws.Service.<init>(Service.java:57)
[junit] 	at javax.xml.ws.Service.create(Service.java:687)
[junit] 	at org.jboss.test.ws.jaxws.samples.exception.ExceptionEJB3Helper.getProxy(ExceptionEJB3Helper.java:48)
[junit] 	at org.jboss.test.ws.jaxws.samples.exception.ExceptionHelper.testRuntimeException(ExceptionHelper.java:81)
[junit] 	at org.jboss.test.ws.jaxws.samples.exception.ExceptionTestCase.testRuntimeException(ExceptionTestCase.java:45)
[junit] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] 	at java.lang.reflect.Method.invoke(Method.java:597)
[junit] 	at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] 	at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] 	at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] 	at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] 	at junit.framework.TestResult.run(TestResult.java:109)
[junit] 	at junit.framework.TestCase.run(TestCase.java:118)
[junit] 	at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] 	at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] 	at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
[junit] 	at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
[junit] 	at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] 	at junit.extensions.TestSetup.run(TestSetup.java:23)
[junit] 	at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] 	at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] 	at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit]
[junit] Found 1 deadlock.

Confirmed, it was really a deadlock. Not a straightforward one to solve, at least to me, given the blocking part were a bit deep into the JDK (1.6) sources.

A bit of background on what’s been developed here and which are the game “players”: JBossWS provides and integration layer for running Apache CXF on top of JBoss Application Server. The testcase being executed above (in thread “main”) is a simple standard JAX-WS client application that creates a java.xml.ws.Service instance for consuming an endpoint that’s deployed on JBoss AS. The “pool-1-thread-1″ thread should instead be spawned by the remote deployment request that’s issued by the testsuite to deploy a WS endpoint jar archive on JBoss AS before actually running the client test.

The problem was not easily and consistently reproducible locally, so I used a debugger to force the “evil” timing that causes the deadlock: you set a breakpoint on the code executed by both threads above, before each of them goes through one of the “- locked <…>” points. Then have each of them acquire the first lock and you’re done, sure deadlock when each thread later wants the other lock.

So, carefully analysing the problem I understood what was really happening. The deadlock above is between the system classloader and sun.net.www.protocol.file.Handler, due to their synchronized Classloader::loadClass() and Handler::openConnection()/Handler::getHostAddress() methods. During initialization, Apache CXF performs some hacks, including disabling url caching; to achieve that, it opens a new connection as JDK does not have a static method for setting that, despite the flag being actually static. The process of opening a connection goes through the Handler’s synchronized openConnection() method and in there ends up needing the system classloader for loading a class. Unfortunately, the lock on the system classloader might be taken by another thread invoking the synchronized loadClass() on it and also needing to use the CodeSource for locating the class to be loaded. That eventually ends up in needing the URLStreamHandler / Handler for comparing URL instances.

URLStreamHandler? For those not having experience here, Java comes with a configurable architecture for resolving URLs. Simplifying things a lot, the URLStreamHandler is created using the specified URLStreamHandlerFactory, which can be configured setting the java.protocol.handler.pkgs system property. Why is this relevant here? Basically because JBoss needs and uses this mechanism for installing his own handler to deal with vfs URLs. Looking at the code for the configured factory, the returned handler is basically a singleton. Hence the deadlock, regardless of the vfs-aware handler not being needed here.

How to solve the issue? While it might be arguable whether having singleton protocol handler is a good choice or not, I couldn’t change that quickly and easily, as it was “out of my area of action”. I ended up changing the Apache CXF code after having had a chat with Dan Kulp (CXF project lead): instead of actually opening a connection to get an handle to a URLConnection instance for the sake of disabling URL caching, we now simply create a concrete extension of the abstract URLConnection that is only used for setting the static member through its setDefaultUseCaches() non-static method.

The fix is effective for the specific issue I had and in general for reducing the chances of running into deadlock because of Apache CXF. However, few considerations / caveats are still valid:

  • be careful when designing and providing your own protocol handlers, as that can have really unexpected side effects
  • opening a connection can be time consuming even before URLConnection::connect() due to all the locking that’s required in there; obviously another reason for checking twice if you really need opening a connection before actually doing that
  • is JDK really well designed here? (non-static URLConnection.setDefaultUseCaches(..))

It’s been a nice debugging in any case :-) 

[junit] Found one Java-level deadlock:
    [junit] =============================
    [junit] "pool-1-thread-1":
    [junit]   waiting to lock monitor 0x000000005d2c60c0 (object 0x00002aaadfb10fd8, a sun.net.www.protocol.file.Handler),
    [junit]   which is held by "main"
    [junit] "main":
    [junit]   waiting to lock monitor 0x000000005cb02a58 (object 0x00002aaadfb10e38, a sun.misc.Launcher$AppClassLoader),
    [junit]   which is held by "pool-1-thread-1"
    [junit]
    [junit] Java stack information for the threads listed above:
    [junit] ===================================================
    [junit] "pool-1-thread-1":
    [junit] 	at java.net.URLStreamHandler.getHostAddress(URLStreamHandler.java:412)
    [junit] 	- waiting to lock <0x00002aaadfb10fd8> (a sun.net.www.protocol.file.Handler)
    [junit] 	at java.net.URLStreamHandler.hostsEqual(URLStreamHandler.java:439)
    [junit] 	at sun.net.www.protocol.file.Handler.hostsEqual(Handler.java:117)
    [junit] 	at java.net.URLStreamHandler.sameFile(URLStreamHandler.java:396)
    [junit] 	at java.net.URLStreamHandler.equals(URLStreamHandler.java:316)
    [junit] 	at java.net.URL.equals(URL.java:842)
    [junit] 	at java.security.CodeSource.equals(CodeSource.java:135)
    [junit] 	at java.util.HashMap.get(HashMap.java:305)
    [junit] 	at java.security.SecureClassLoader.getProtectionDomain(SecureClassLoader.java:233)
    [junit] 	- locked <0x00002aaadfb11120> (a java.util.HashMap)
    [junit] 	at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:141)
    [junit] 	at java.net.URLClassLoader.defineClass(URLClassLoader.java:283)
    [junit] 	at java.net.URLClassLoader.access$000(URLClassLoader.java:58)
    [junit] 	at java.net.URLClassLoader$1.run(URLClassLoader.java:197)
    [junit] 	at java.security.AccessController.doPrivileged(Native Method)
    [junit] 	at java.net.URLClassLoader.findClass(URLClassLoader.java:190)
    [junit] 	at java.lang.ClassLoader.loadClass(ClassLoader.java:307)
    [junit] 	- locked <0x00002aaadfb10e38> (a sun.misc.Launcher$AppClassLoader)
    [junit] 	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:301)
    [junit] 	- locked <0x00002aaadfb10e38> (a sun.misc.Launcher$AppClassLoader)
    [junit] 	at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
    [junit] 	at org.xnio.nio.AbstractNioChannelThread.cancelKey(AbstractNioChannelThread.java:298)
    [junit] 	at org.xnio.nio.NioHandle.cancelKey(NioHandle.java:56)
    [junit] 	at org.xnio.nio.AbstractNioStreamChannel.cancelWriteKey(AbstractNioStreamChannel.java:241)
    [junit] 	at org.xnio.nio.NioTcpChannel.shutdownWrites(NioTcpChannel.java:164)
    [junit] 	at org.xnio.channels.TranslatingSuspendableChannel.shutdownWrites(TranslatingSuspendableChannel.java:358)
    [junit] 	at org.xnio.channels.FramedMessageChannel.shutdownWrites(FramedMessageChannel.java:255)
    [junit] 	- locked <0x00002aaadfb11978> (a org.xnio.ByteBufferSlicePool$PooledByteBuffer)
    [junit] 	at org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener.send(RemoteConnection.java:267)
    [junit] 	- locked <0x00002aaadfb119a0> (a org.jboss.remoting3.remote.RemoteConnection)
    [junit] 	at org.jboss.remoting3.remote.RemoteConnection.sendCloseRequest(RemoteConnection.java:164)
    [junit] 	at org.jboss.remoting3.remote.RemoteConnection.handleOutboundCloseRequest(RemoteConnection.java:149)
    [junit] 	at org.jboss.remoting3.remote.RemoteConnectionHandler.closeAction(RemoteConnectionHandler.java:173)
    [junit] 	at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync(AbstractHandleableCloseable.java:354)
    [junit] 	at org.jboss.remoting3.ConnectionImpl.closeAction(ConnectionImpl.java:48)
    [junit] 	at org.jboss.remoting3.spi.AbstractHandleableCloseable.close(AbstractHandleableCloseable.java:149)
    [junit] 	at org.xnio.IoUtils.safeClose(IoUtils.java:134)
    [junit] 	at org.jboss.as.protocol.ProtocolChannelClient.close(ProtocolChannelClient.java:176)
    [junit] 	at org.xnio.IoUtils.safeClose(IoUtils.java:134)
    [junit] 	at org.jboss.as.protocol.mgmt.ManagementClientChannelStrategy$Establishing.requestDone(ManagementClientChannelStrategy.java:138)
    [junit] 	at org.jboss.as.protocol.mgmt.ManagementRequest$DelegatingResponseHandler.readResponse(ManagementRequest.java:178)
    [junit] 	at org.jboss.as.protocol.mgmt.ManagementChannel$ResponseReceiver.handleResponse(ManagementChannel.java:375)
    [junit] 	at org.jboss.as.protocol.mgmt.ManagementChannel$ResponseReceiver.access$400(ManagementChannel.java:357)
    [junit] 	at org.jboss.as.protocol.mgmt.ManagementChannel.doHandle(ManagementChannel.java:120)
    [junit] 	at org.jboss.as.protocol.ProtocolChannel.handleMessage(ProtocolChannel.java:158)
    [junit] 	at org.jboss.remoting3.remote.RemoteConnectionChannel$4.run(RemoteConnectionChannel.java:224)
    [junit] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    [junit] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] "main":
    [junit] 	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:293)
    [junit] 	- waiting to lock <0x00002aaadfb10e38> (a sun.misc.Launcher$AppClassLoader)
    [junit] 	at java.lang.ClassLoader.loadClass(ClassLoader.java:248)
    [junit] 	at java.net.URL.getURLStreamHandler(URL.java:1144)
    [junit] 	at java.net.URL.<init>(URL.java:393)
    [junit] 	at java.net.URL.<init>(URL.java:283)
    [junit] 	at java.net.URL.<init>(URL.java:306)
    [junit] 	at sun.net.www.protocol.file.Handler.openConnection(Handler.java:74)
    [junit] 	- locked <0x00002aaadfb10fd8> (a sun.net.www.protocol.file.Handler)
    [junit] 	at sun.net.www.protocol.file.Handler.openConnection(Handler.java:55)
    [junit] 	- locked <0x00002aaadfb10fd8> (a sun.net.www.protocol.file.Handler)
    [junit] 	at java.net.URL.openConnection(URL.java:945)
    [junit] 	at sun.net.www.protocol.jar.JarURLConnection.<init>(JarURLConnection.java:66)
    [junit] 	at sun.net.www.protocol.jar.Handler.openConnection(Handler.java:24)
    [junit] 	at java.net.URL.openConnection(URL.java:945)
    [junit] 	at org.apache.cxf.common.logging.JDKBugHacks.doHacks(JDKBugHacks.java:67)
    [junit] 	at org.apache.cxf.common.logging.LogUtils.<clinit>(LogUtils.java:66)
    [junit] 	at org.apache.cxf.jaxws.spi.ProviderImpl.<clinit>(ProviderImpl.java:61)
    [junit] 	at java.lang.Class.forName0(Native Method)
    [junit] 	at java.lang.Class.forName(Class.java:247)
    [junit] 	at java.util.ServiceLoader$LazyIterator.next(ServiceLoader.java:345)
    [junit] 	at java.util.ServiceLoader$1.next(ServiceLoader.java:421)
    [junit] 	at javax.xml.ws.spi.Provider.getProviderUsingServiceLoader(Provider.java:146)
    [junit] 	at javax.xml.ws.spi.Provider.provider(Provider.java:106)
    [junit] 	at javax.xml.ws.Service.<init>(Service.java:57)
    [junit] 	at javax.xml.ws.Service.create(Service.java:687)
    [junit] 	at org.jboss.test.ws.jaxws.samples.exception.ExceptionEJB3Helper.getProxy(ExceptionEJB3Helper.java:48)
    [junit] 	at org.jboss.test.ws.jaxws.samples.exception.ExceptionHelper.testRuntimeException(ExceptionHelper.java:81)
    [junit] 	at org.jboss.test.ws.jaxws.samples.exception.ExceptionTestCase.testRuntimeException(ExceptionTestCase.java:45)
    [junit] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    [junit] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    [junit] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    [junit] 	at java.lang.reflect.Method.invoke(Method.java:597)
    [junit] 	at junit.framework.TestCase.runTest(TestCase.java:154)
    [junit] 	at junit.framework.TestCase.runBare(TestCase.java:127)
    [junit] 	at junit.framework.TestResult$1.protect(TestResult.java:106)
    [junit] 	at junit.framework.TestResult.runProtected(TestResult.java:124)
    [junit] 	at junit.framework.TestResult.run(TestResult.java:109)
    [junit] 	at junit.framework.TestCase.run(TestCase.java:118)
    [junit] 	at junit.framework.TestSuite.runTest(TestSuite.java:208)
    [junit] 	at junit.framework.TestSuite.run(TestSuite.java:203)
    [junit] 	at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
    [junit] 	at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
    [junit] 	at junit.framework.TestResult.runProtected(TestResult.java:124)
    [junit] 	at junit.extensions.TestSetup.run(TestSetup.java:23)
    [junit] 	at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
    [junit] 	at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
    [junit] 	at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
    [junit]
    [junit] Found 1 deadlock.

Sibilla first release: experience a new approach to unit testing


abstract:

[...] collecting metadata set that represent links between classes under test and test classes (and eventually more fine grained links between methods) and using them for a lot of purposes. Metadata can be collected from different sources: annotations on classes under test, instrumentation of test classes during tests’ execution (in future perhaps even from a dedicated user interface). These metadata can be used for various goals: first of all it becomes possible to run only the tests that stress just a particular set of classes (for instance the classes changed since last compilation) [...] We have a Maven plugin, while Eclipse and Hudson ones are in our roadmap.

Full story:

A while ago I’ve written a post about a new approach to unit tests; it has been a quite read and discussed post and it gives the momentum for starting a new community discussing about the idea and working on a software project implementing this idea. The project was named TestedBy and hosted in google code.

That idea has evolved and changed and we have decided to change also the name of the project as a remark of these changes, calling it SibillaTest. Why Sibilla? Because, as you can read in this post and you can get trying our samples, Sibilla (italian name for Cumae Sybil) is always able to prophesy and predict which tests you need to run.

This post has been written to announce the release of a first beta version of SibillaTest and describe how our thoughts about the original idea have changed in these months and how they have been  implemented in SibillaTest.
I’m going to recall the main concepts of the original idea, If you haven’t read the original blog would be nice to take a look to it, to its numerous comments and also to the update I’ve posted few days after. If you are interested in all the genesis of the project you could also have a look to the discussions continued in our forum

Generally speaking what I’ve depicted in my old blog post was a system to keep annotations in classes under test pointing test classes (or in some case to specific test methods). Advantage of this approach were mainly 2:

• Design By Contract (viewing test as contract definition). The sugar here was the opportunity to put TestedBy annotation also on super classes (even if they are abstract or even interfaces) and inherit test annotations.
• Run only tests stressing a specific class. IOW run test stressing a class of your interest (i.e just compiled) giving you the confidence you aren’t breaking test suite without running the entire suite itself.

The main concerns about this approach was about code cluttering putting a lot of annotations in production code (of course you could have a lot of test stressing a class or even a method).

So we have changed a bit the focus from an annotation centric approach to a more general metadata
approach. The idea is to collect a set of metadata that represent link between classes under test and test classes (and eventually more fine grained links between methods) and use them for a lot of purposes.
The pluses of this approach are mainly two:

• Metadata can be collected from different sources: annotations , instrumentation of test during test execution, maybe in the future from a dedicated  user interface.
• Metadata can be serialized and/or used in a second step for various goals: run “right” tests of course will remain a central feature, but also
“graphical” representation, code navigation in IDE, more dynamic use of it

I’m trying to keep this post not too long trying to keep your attention focused on the usefulness of SibillaTest,  I’m going to describe in this the feature already implemented in SibillaTest. But, of course, we have a lot of ideas that will be developed in next future that we would like to discuss with the community and maybe have some contribution from the community. Here you have a mind map depicting a lot of these working areas to get you an idea. If you are interested in a more detailed description of them you  can find a page in our wiki describing it.

So, what is SibillaTest today?

aims at changing the point of view regarding test classes and classes under test. What we get is the focus being moved to the classes under test; from those classes, which of course are the most important ones of your projects, we obtain links to your test classes and test methods. In other words we define the classes and methods’ contract using tests, while also keeping track of tests that need to be run when a class/method under test has been modified. This is possible by collecting metadata sets that represent links between classes under test and test classes (and eventually more fine grained links between methods) and using them for a lot of purposes. Metadata can be collected from different sources: annotations on classes under test, instrumentation of test classes during tests’ execution (in future perhaps even from a dedicated user interface). These metadata can be used for various goals: first of all it becomes possible to run only the tests that stress just a particular set of classes (for instance the classes changed since last compilation), moreover a graphical representation of classes’ links can be derived. We have a Maven plugin, while Eclipse and Hudson ones are in our roadmap. Further cool idea around this is supporting generic tests to inject on existing production code (to verify commonly situation like don’t accept null parameters) and mock verification (are your mocks respecting the contract you have defined on mocked classes with your tests?)

Practically speaking in this beta release we have:

  • a core supporting both annotation based metadata definition and instrumentation of classes during test execution to collect metadata. With annotation we support metadata on test stressing a whole hierarchy of classes/interfaces: you can define tests to be run against all implementation of your interface and SibillaTest take care of it Instrumentation do the magic of knowing which test is stressing particular classes and run only tests needed to validate last changed classes (i.e just compiled)
  • a maven plugin (docs here) you can use to run test stressing only last changed classes.
  • support of Junit tests (not yet testng or other frameworks)

In our wiki you can find some documentation of how to include Sibilla into your maven project, how to run it and documentation about our annotations if you decide to give TestedBy design by contract approach a try. Here you can also find a small project with trivial classes under test and test classes using SibillaTest to run them. Check it out and give it a try…it’s the key to understand the idea and to say “wow it’s cool!” :)

Have a look and send us comment through this blog or, much better, through our issue tracker and/or our forum. We have also an IRC channel #sibilla active on FreeNode for discussions and suggestions.

Artifact are available on maven central repository, see the docs too.

Some other post with detailed descriptions of instrumentation and annotation based metadata and their use and plans for next versions will follow during next days. Moreover we will discuss on forum and post here also plans of integration with the very cool Arquillian (I had a very interesting discussion about that with Aslak at last JUDCon)….

….stay tuned.

Of course if anyone is interested to join us and help (especially for eclipse plugin) please write us.

Stay tuned, join us and show some love around on the net!

http://sibilla.javalinux.it

(Forum – IRC – GitHub – Sample(github) – Maven Plugin(github) – @SibillaTest on twitter – issues)

Small open source projects are difficult to keep alive. And what about Wise and TestedBy?

Hi all,
another time I have to say that a long time has passed since my last post :(

Well, I’ve been very very busy in last months driving (or at least help a lot to drive) a big change in my former company, leading a key project with more than fifty programmers involved distributed in various team, with a lot of biz analysts and so on. But it’s another story I’ll probably tell you at some point. But the important word in last sentence is former. Yep, who is following me on twitter (or have recently read about_us page or even is linked with me on linkedin) knows I’ve joined  Red Hat as Principal Software Engineer in JBoss division. That’s a cool interesting job (I’m working on IronJacamar project and AS7 development), but it’s making me very busy.

Anyway, back to the title of this post. It’s matter of fact that is very hard to keep alive open source projects in spare time. And maybe in last months some people thought that Wise is an almost dead project, and TestedBy a totally dead one. In fact we had very few time to  work on Wise and also on TestedBy for all the reasons stated above. But they aren’t dead and we are getting back on them (check last week commits for both!).

In particular Alessio is working on Wise to full support JBossWS-CXF container, while I’m planning to cleanup ESB module to support the last version (maybe after Alessio’s work). After that we will work on our object mapping subsystem needed to continue the implementation of our WebUI.

I’m refining in the mean time samples of TestedBy to make possible to release the first version of the project. BTW very probably we will leave “TestedBy” name and we will launch the first release of the project with a new cool name. I’ll keep you post here.

As said keeping open source project alive in spare time isn’t easy, and sometime it’s very very hard specially if contributors are very few and very busy. Would you be part of a cool open source project, with all the beauty of that? We would need in particular contributions for TestedBy in Eclipse area, but if you would land an hand in other area and/or in Wise we are fine with that too. Please contact us, your help could make the difference!

Last but not least Wise have a new very very cool logo. Thanks to Red Hat Design team and in particular to Cheynne for that! No link here…it merits a dedicated post!

As said a lot of cool stuffs are coming…stay tuned.