Groovy testing: 3 lessons from 1 test case

As Groovy Core developer involved in compiler and language runtime I am always worried for broken tests in the trunk. Especially when it happened after my commit. But even if it is not a case I have big problem with broken trunk because to test any of my changes in the local copy I need to re-run whole Groovy test suite.

So when after update this morning I found that one test is broken I decided to have a look what’s going on. Especially strange was the fact that test was broken on Windows build server but passed well on Linux one. We had such problem recently, which was probably caused by different default stack size on different VMs and forced me to improve compiler a bit. So I start to look on the test.

It is relatively simple

class Groovy1759_Bug extends GroovyTestCase {
   void testInterception() {
      def benchmarkInterceptor = new BenchmarkInterceptor()
      def proxy = ProxyMetaClass.getInstance(A.class)
      proxy.setInterceptor(benchmarkInterceptor)
      proxy.use {
         def a = new A()
         a.a()
         a.b()
      }

      def actual = benchmarkInterceptor.statistic()
      def expected = [['b', 2, 0],['ctor', 1, 0],['a', 1, 0]]
      assert expected == actual
   }
}

class A{
   void a(){ b() }
   void b(){}
}

We test BenchmarkInterceptor, which records all calls to different methods and record number of executions and accumulated time spent inside methods. Then we compare actual results with our expectations.

Here is piece of code, which actually does the job:

def actual = benchmarkInterceptor.statistic()
def expected = [['b', 2, 0],['ctor', 1, 0],['a', 1, 0]]
assert expected == actual

But it was failing with following not very helpful message:
java.lang.AssertionError: Expression: (expected == actual). Values: expected = [[b, 2, 0], [ctor, 1, 0], [a, 1, 0]], actual = [[Ljava.lang.Object;@cc06e0, [Ljava.lang.Object;@d7643a, [Ljava.lang.Object;@f52a1d]

Lesson 1: If you provide diagnostic try to provide useful one.

I had quick look to compiler and immediately found that instead of call to stringBuffer.append(obj) during generation of assert statement it would be much better better to use stringBuffer.append(InvokerHelper.toString(obj)). Fast check and … voila! It works and I have much better error message:

java.lang.AssertionError: Expression: (expected == actual). Values: expected = [[b, 2, 0], [ctor, 1, 0], [a, 1, 0]], actual = [[ctor, 1, 0], [a, 1, 0], [b, 2, 0]]

OK, content of expected and actual lists are the same but the order of elements is wrong. Fortunately, I had this lesson many times before

Lesson 2: Never expect any particular order of elements in a hash map. Or either sort or use linked one if you need an order.

What hash map one can ask? Really, I had no idea but I could imagine that BenchmarkInterceptor use internal one to record calls. And it is was exactly the case – method names as keys and list of current time before and after the call as values.
So the fix was almost trivial – replace HashMap by LinkedHashMap in BenchmarkInterceptor and put expected values in order how calls happen


def expected = [['ctor', 1, 0],['a', 1, 0],['b', 2, 0]]
assert expected == actual

At that point I run clean build, checked that all tests passed and commited my changes. In fact before commit I also run remote build on TeamCity, where test failure was reported from. In two minutes I had beautiful surprise from build server. Test was failing!

It took me another 5 or 6 local runs tio reproduce failure on my environment. Some time execution time was 1 instead of 0.

Lesson 3: Never expect particular execution time of piece of code

Do I need to explain? Probably not.

Thanks to Groovy here is final code snippet.

      def actual = benchmarkInterceptor.statistic().collect{ [ it[0], it[1] ] }
      def expected = [['ctor', 1],['a', 1],['b', 2]]
      assert expected == actual

And it works much better.

Bonus Lesson: Analize your tests we have a lot to learn from our failures

Advertisements

Leave a Reply

Please log in using one of these methods to post your comment:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: