War Stories: The elusive Service

Martin Häusler - Apr 16 '19 - - Dev Community

If you like "war stories", tales which are told among developers who ran into really obscure issues and felt like going crazy before finally finding a solution - read on, this is one of them.

Once upon a time...

I was writing a new REST endpoint in a Spring Boot application - nothing I haven't done a hundred times before. What could possibly go wrong. As I really enjoy coding in Kotlin lately, I decided to give it a shot. Here's what the controller looked like:

@RestController
open class MyRestController{

    @Autowired
    private lateinit var service: MyService

    @ResponseBody
    @RequestMapping(method = HttpMethod.GET, path = "/yadda-yadda")
    fun getSomeData(): MyDTO{
        val data = this.service.produceData()
        return MyDTO(data)
    }

}

It's a simple REST endpoint - it grabs some data from a service, wraps it in a DTO and sends it as the response. There weren't even database transactions involved here, it was as basic as it gets.

Regardless, I decided to write a small test for it:

class MyTest {

   @Test
   fun canGetDataViaREST(){
       val mvc = ... // spring mock MVC setup, not important here
       val objectMapper = ... // Jackson setup, not important here
       val responseJson = mvc.perform(
           get("/yadda-yadda")
       ).andExpect(status().isOk)
        .andReturn().response.bodyAsString
       val dto = objectMapper.readValue<MyDTO>(responseJson)
       assertNotNull(dto)
   }

}

So the test is fairly simple: it uses Spring MockMVC to simulate a REST call to our new endpoint, fetches the result as JSON and deserializes it with a Jackson object mapper. Nothing fancy there, like at all. This is Spring REST 101. And yet, sure enough, the test failed.

The Failure

The test failed. Not with an assertion error, as you might expect. Or some JSON serialization or deserialization issue, no. It was a NullPointerException. Strangely enough, since those things are really hard to produce in Kotlin. This is the line indicated by the exception:

val data = this.service.produceData() // NullPointerException: lateinit var 'service' is not initialized!

That was odd. Very odd. Failing to @Autowire something usually indicated a missing spring bean, or something else along these lines. However, as the Spring users among you will know, if Spring fails to set up something it fails, and it fails loudly, you get like 7 Kilometers worth of stack traces. Nope, not in this particular case. Spring said everything's fine. Yet my @Autowired didn't work.

Can you spot where I went wrong? I didn't. And I spent a good nerve-wrecking hour searching for the cause.

Down the rabbit hole

Taken aback by this behaviour, I started investigating. I checked all the annotations on all related classes, I checked the configuration, everything seemed fine. I had dozens of similar scenarios in the project and they all worked flawlessly. Yet this one failed for inexplicable reasons.

Then I began suspecting Kotlin as the culprit, since it was the primary differentiator between this case (which failed) and all the other cases (which worked). I looked at the generated bytecode and decompiled it into Java, and cleaned it up a little, which gave me this:

@RestController
public class MyRestController{

    @Autowired
    private MyService service;

    @ResponseBody
    @RequestMapping(method = HttpMethod.GET, path = "/yadda-yadda")
    public final MyDTO getSomeData() {
        Data data = this.service.produceData();
        return new MyDTO(data);
    }

}

That looked like the other thousand rest endpoints I had written so far. Yet, even in Java, the error was still there: NullPointerException when attempting to access the @Autowired service field. Holy shit.

I finally started the debugger and created a @PostConstruct block in the REST controller:

@PostConstruct
private void init(){
    System.out.println("Test!");
}

I put a breakpoint on the println statement. Sure enough, it was reached when executing the test. I inspected the this object, and lo and behold, the service field was populated with a value! The service was assigned, just as I had intended. Everything seemed fine. I continued the execution. The test failed. The definition of insanity is doing the same thing over and over again, hoping for a different result...

I inserted an additional breakpoint at the line which produced the exception. this.service was properly populated in the init method... but the field was null in getSomeData(). I had to grab a cup of coffee at this point.

When I came back and did another run, I noticed something: at the second breakpoint, this was referring to a different object ID than at the first one. But more importantly: it was also referring to another class: MyRestController$$_EnhancerByCGLIB_$$.

As a quick detour: Spring not only makes extensive use of JDK Dynamic Proxies to get its job done, but also uses CGLib to subclass your classes at runtime, generating the bytecode and inserting further lines of code on the fly. I talked about it with a coworker, when the root cause of the problem struck me right into the face.

The Solution

Look carefully what Kotlin generated:

public final MyDTO getSomeData() { ... }

Look again. See it? final. Kotlin, by design, declares everything as final implicitly, unless you declare it as open. This is exactly the inverse of what Java does, where everything is overridable unless declared as final. Having worked with frameworks like Hibernate before, I knew that final and CGLib do not play well together - at all.

So I removed the final modifier.

The test worked.

What the f*** happened?

Spring generated a subclass of MyRestController. This subclass was the one which was actually used. By default, Spring overrides each and every REST endpoint method. Except that in this case, it wasn't able to do so, because of the final modifier. The result was that getSomeData() was called on the base class (the one I had written by hand), but the @Autowired field value was only available in the sub class (yep, those fields are replicated too by Spring/CGLib). Which is why the (non-final) init method could see the field value, and getSomeData() could not.

Lessons Learned

There are some take-aways from this:

1) Be super extra careful when using Kotlin with Spring. Declare everything and its grandmother as open.
2) If in doubt when working with Kotlin, look at the generated Java code.
3) While Spring catches a lot of issues, some unintended mischief can slip through without warning.
4) It can be as simple as it gets, if it isn't tested, it is going to break at some point. No exceptions.
5) Always be on guard, never get over-confident when coding, even during routine tasks. A thing you did correctly 100 times might go wrong at the 101st attempt. Or the 103rd. But eventually it will.

On a related note, I still fundamentally disagree with the design decision of the open keyword in Kotlin. This is just another example why this was a bad idea to begin with.

If a Spring developer happens to read this: please print a big fat warning if a method cannot be overridden by CGLib for some reason (in this case, the reason being the final keyword).

Here's hoping that this will help other people to not repeat my mistake. I do not intend any offense against Spring, Kotlin or any other mentioned technology - I enjoy working with them. Just sometimes, they don't quite agree. And then things like this happen.

I hope that you enjoyed reading along!

. . . . . . . . . . . . . . . . . . . . . .