Bug Conspiracy

There is a burst of energy that happens upon finding the source of an elusive bug, which is driving me to write this post.

Programmer Morale


On a recent project, we used the Apache Wicket framework for the web interface. As the client also wanted a very simple REST API, we used the Wicket REST annotations library from the Wicket Stuff project.

The project had an abstract base class ResourceBase, inherited by all endpoints:

public abstract class ResourceBase<T extends IDTOFrontEnd> extendsAbstractRestResource<JsonWebSerialDeserial> {
    public ResourceBase(JsonWebSerialDeserial serialDeserial) {
        super(serialDeserial);
    }

    public abstract T submit();
}

Here's one of the endpoints:

public class LoginResource extends ResourceBase<IRestLoginDTO> {
  public LoginResource(JsonWebSerialDeserial serialDeserial) {
    super(serialDeserial);
  }

  @Override
  @MethodMapping(value = "/")
  public IRestLoginDTO submit() {
    return null;
  }
}

The IRestLoginDTO interface extends IDTOFrontEnd:

public interface IDTOFrontEnd extends IClusterable {
}

public interface IRestLoginDTO extends IDTOFrontEnd {
}

Everything worked OK in development, but when we deployed in pre-production, we suddenly got the following error when accessing the API:

Ambiguous methods mapped for the current request: URL 'api/common/login', HTTP method GET. Mapped methods: submit

Everything worked well in one of my colleagues' machine, but I was getting mixed results trying to reproduce the problem: sometimes it would work, and other times not, and I couldn't figure out why.

As I had recently squandered a great deal of time on an OpenJDK bug that did not exist on Oracle JDK, I thought it might be the same type of thing, but I didn't know what exactly was happening.

The error stemmed from a Wicket Stuff internal algorithm that tries to find the method which best matches a requested endpoint. When it finds two methods that match equally well, it throws an exception.

Here's some code that illustrates the problem:

public class Demo {
  public static void main(String[] args) {
    Method[] declaredMethods = LoginResource.class.getDeclaredMethods();
    for (Method method : declaredMethods) {
      System.err.println(method.getName());
      System.err.println(method.getAnnotation(MethodMapping.class));
      System.err.println("--------------------");
    }
  }
}

This generates the following output:

submit
@org.wicketstuff.rest.annotations.MethodMapping(produces=application/json, httpMethod=GET, consumes=application/json, value=/)
--------------------
submit
null
--------------------

The algorithm used by Wicket Stuff ignores the methods that didn't have the @MethodMapping annotation. The result above is the output on a machine where the application worked. On machines where it didn't, the second method would also list the annotation, which leads to the method matching ambiguity that Wicket Stuff complains about.

The first question is, why is getDeclaredMethods() returning two methods? Is it because we have a submit method in LoginResource overriding the submit method in ResourceBase? The documentation tells us that getDeclaredMethods() excludes such overrides:

"Returns an array containing Method objects reflecting all the declared methods of the class or interface represented by this Class object, including public, protected, default (package) access, and private methods, but excluding inherited methods."

If we alter the Demo class to also report the declaring class for each method, we have:

public class Demo {
  public static void main(String[] args) {
    Method[] declaredMethods = LoginResource.class.getDeclaredMethods();
    for (Method method : declaredMethods) {
      System.err.println(method.getName());
      System.err.println(method.getDeclaringClass().getName());
      System.err.println(method.getAnnotation(MethodMapping.class));
      System.err.println("--------------------");
    }
  }
}

And the output:

submit
LoginResource
@org.wicketstuff.rest.annotations.MethodMapping(produces=application/json, httpMethod=GET, consumes=application/json, value=/)
--------------------
submit
LoginResource
null
--------------------

The LoginResource class appears twice and the ResourceBase class does not appear at all. So, it does not appear to be related to inheritance. Or is it? We can alter both classes such that inheritance is no longer in the picture:

public abstract class ResourceBase<T extends IDTOFrontEnd> extends AbstractRestResource<JsonWebSerialDeserial> {
  public ResourceBase(JsonWebSerialDeserial serialDeserial) {
    super(serialDeserial);
  }
}

public class LoginResource extends ResourceBase<IRestLoginDTO> {
  public LoginResource(JsonWebSerialDeserial serialDeserial) {
    super(serialDeserial);
  }
  @MethodMapping(value = "/")
  public IRestLoginDTO submit() {
    return null;
  }
}

Running the Demo again:

submit
LoginResource
@org.wicketstuff.rest.annotations.MethodMapping(produces=application/json, httpMethod=GET, consumes=application/json, value=/)
--------------------

Humm, how about that? It turns out that inheritance does seem to affect the problem. Could it be related to the use of generics? We removed the generic type declaration on ResourceBase to test:

public abstract class ResourceBase extends AbstractRestResource<JsonWebSerialDeserial> {
  public ResourceBase(JsonWebSerialDeserial serialDeserial) {
    super(serialDeserial);
  }

  public abstract IDTOFrontEnd submit();
}

public class LoginResource extends ResourceBase {
  public LoginResource(JsonWebSerialDeserial serialDeserial) {
    super(serialDeserial);
  }

  @Override
  @MethodMapping(value = "/")
  public IRestLoginDTO submit() {
    return null;
  }
}

Running the Demo class again:

submit
LoginResource
@org.wicketstuff.rest.annotations.MethodMapping(produces=application/json, httpMethod=GET, consumes=application/json, value=/)
--------------------
submit
LoginResource
null
--------------------

So, the use of generics is not the problem. Do the IDTOFrontEnd and IRestLoginDTO interfaces have any influence on this? Changing LoginResource to:

public class LoginResource extends ResourceBase {
  public LoginResource(JsonWebSerialDeserial serialDeserial) {
    super(serialDeserial);
  }

  @Override
  @MethodMapping(value = "/")
  public IDTOFrontEnd submit() {
    return null;
  }
}

Running the Demo, we have a single result again:

submit
LoginResource
@org.wicketstuff.rest.annotations.MethodMapping(produces=application/json, httpMethod=GET, consumes=application/json, value=/)
--------------------

So, at this time, we know that inheritance is not supposed to be a problem but it is, and that the type of the return function is important.

I vaguely recalled reading about java's bizarre behavior regarding equal methods with different return types, so I did what experts do and turned to javap:

javap LoginResource.class

public class LoginResource extends ResourceBase<IRestLoginDTO> {
  public LoginResource(org.wicketstuff.rest.contenthandling.json.webserialdeserial.JsonWebSerialDeserial);
  public IRestLoginDTO submit();
  public IDTOFrontEnd submit();
}

It checks out: both methods exist with different return types. But why? And where is the @MethodMapping annotation, important for Wicket Stuff? We need the -verbose javap flag to see annotations:

javap -v LoginResource.class

Classfile LoginResource.class
  Last modified 11/dez/2018; size 1067 bytes
  MD5 checksum b0e8a2040ab48404657b894a4954f35a
  Compiled from "LoginResource.java"
public class LoginResource extends ResourceBase<IRestLoginDTO>
  minor version: 0
  major version: 52
  flags: ACC_PUBLIC, ACC_SUPER
Constant pool:
   #1 = Class              #2             // LoginResource
   #2 = Utf8               LoginResource
   #3 = Class              #4             // ResourceBase
   #4 = Utf8               ResourceBase
   #5 = Utf8               <init>
   #6 = Utf8               (Lorg/wicketstuff/rest/contenthandling/json/webserialdeserial/JsonWebSerialDeserial;)V
   #7 = Utf8               Code
   #8 = Methodref          #3.#9          // ResourceBase."<init>":(Lorg/wicketstuff/rest/contenthandling/json/webserialdeserial/JsonWebSerialDeserial;)V
   #9 = NameAndType        #5:#6          // "<init>":(Lorg/wicketstuff/rest/contenthandling/json/webserialdeserial/JsonWebSerialDeserial;)V
  #10 = Utf8               LineNumberTable
  #11 = Utf8               LocalVariableTable
  #12 = Utf8               this
  #13 = Utf8               LLoginResource;
  #14 = Utf8               serialDeserial
  #15 = Utf8               Lorg/wicketstuff/rest/contenthandling/json/webserialdeserial/JsonWebSerialDeserial;
  #16 = Utf8               submit
  #17 = Utf8               ()LIRestLoginDTO;
  #18 = Utf8               RuntimeVisibleAnnotations
  #19 = Utf8               Lorg/wicketstuff/rest/annotations/MethodMapping;
  #20 = Utf8               value
  #21 = Utf8               /
  #22 = Utf8               ()LIDTOFrontEnd;
  #23 = Methodref          #1.#24         // LoginResource.submit:()LIRestLoginDTO;
  #24 = NameAndType        #16:#17        // submit:()LIRestLoginDTO;
  #25 = Utf8               SourceFile
  #26 = Utf8               LoginResource.java
  #27 = Utf8               Signature
  #28 = Utf8               LResourceBase<LIRestLoginDTO;>;
{
  public LoginResource(org.wicketstuff.rest.contenthandling.json.webserialdeserial.JsonWebSerialDeserial);
    descriptor: (Lorg/wicketstuff/rest/contenthandling/json/webserialdeserial/JsonWebSerialDeserial;)V
    flags: ACC_PUBLIC
    Code:
      stack=2, locals=2, args_size=2
         0: aload_0
         1: aload_1
         2: invokespecial #8                  // Method ResourceBase."<init>":(Lorg/wicketstuff/rest/contenthandling/json/webserialdeserial/JsonWebSerialDeserial;)V
         5: return
      LineNumberTable:
        line 12: 0
        line 13: 5
      LocalVariableTable:
        Start  Length  Slot  Name   Signature
            0       6     0  this   LLoginResource;
            0       6     1 serialDeserial   Lorg/wicketstuff/rest/contenthandling/json/webserialdeserial/JsonWebSerialDeserial;

  public IRestLoginDTO submit();
    descriptor: ()LIRestLoginDTO;
    flags: ACC_PUBLIC
    RuntimeVisibleAnnotations:
      0: #19(#20=s#21)
    Code:
      stack=1, locals=1, args_size=1
         0: aconst_null
         1: areturn
      LineNumberTable:
        line 19: 0
      LocalVariableTable:
        Start  Length  Slot  Name   Signature
            0       2     0  this   LLoginResource;

  public IDTOFrontEnd submit();
    descriptor: ()LIDTOFrontEnd;
    flags: ACC_PUBLIC, ACC_BRIDGE, ACC_SYNTHETIC
    Code:
      stack=1, locals=1, args_size=1
         0: aload_0
         1: invokevirtual #23                 // Method submit:()LIRestLoginDTO;
         4: areturn
      LineNumberTable:
        line 1: 0
      LocalVariableTable:
        Start  Length  Slot  Name   Signature
}
SourceFile: "LoginResource.java"
Signature: #28                          // LResourceBase<LIRestLoginDTO;>;

The annotation shows up in the Constant pool with id #19. That same id appears in the RuntimeVisibleAnnotations section of method IRestLoginDTO.submit(). Method IDTOFrontEnd.submit() has no annotation section.

I could not yet explain why the compiler had created the second method, but the ACC_BRIDGE and ACC_SYNTHETIC flags looked interesting. Researching these flags is how I learned about synthetic methods and bridge methods. That link explains that the compiler creates additional methods with the necessary signatures so it can deal with type erasure.

It is also created when a class extends another class and the return type of the overriding method is a subclass of the return type of the overridden method.

Now we can finally explain why getDeclaredMethods() returns two entries.

What about the annotation, though? Why will this sometimes work on my machine, and other times not?

Still suspecting a compiler bug, after much searching, I found bug JDK-6695379 : Copy method annotations and parameter annotations to synthetic bridge methods. But, this bug was fixed in version 8b94, since 2015, and I'm in 2018 with version 8u191.

Had the bug returned?

Around that time, I realized that the code didn't work when compiled at the command line, but it worked when compiled from within Eclipse. My perplexity remained...

Why would .class files created by Eclipse be different from the ones created with the command line using either OpenJDK or Oracle JDK?

Eclipse has its own implementation of Git and its own implementation of Maven, could it also have its own compiler? Yep, Eclipse has its own compiler: JDT Core (also known as ECJ).

Does this compiler still suffer from the bug, which has been fixed on OpenJDK for several years? Yes, it does and the bug is reported: Bug 495396 - Inherited annotations are not visible on bridge methods (JDK 6695379).

Finally, everything fits! This explains why it worked when compiled with Eclipse, which does not copy the annotation to the synthetic method created by the compiler to deal with type erasure; but not when compiled with OpenJDK, which does copy the @MethodMapping annotation to the synthetic method and confuses Wicket Stuff.

A bug and subsequent pull request were reported on the Wicket Stuff project, to deal with synthetic methods correctly.

It's not every day that 3 bugs (Wicket Stuff, OpenJDK and JDT CORE) conspire against you.

An empty and long hall at Premium Minds' office. There's a small lounge, with couches and a small table with a plant on it, and multiple doors and windows to the various development teams' working areas.

You're welcome to drop by anytime!

Av. 5 de Outubro 125 Galerias 1050-052 Lisboa
Check on Google Maps
Premium Minds on Google Maps
Back to top