Incorrectly getting error "Collapser method must have one argument" from CollapserMetaHolderFactory

[ppetrosyan]

I am having a strange issue. I have a method which is annotated with HystrixCommand

`
@OverRide
@HystrixCommand(fallbackMethod = "getDataFallback",
commandProperties = {
@HystrixProperty(name = "execution.isolation.thread.timeoutInMilliseconds", value = "60000"),
@HystrixProperty(name="execution.isolation.thread.interruptOnTimeout", value="TRUE"),
@HystrixProperty(name = "circuitBreaker.requestVolumeThreshold", value = "20"),
@HystrixProperty(name = "circuitBreaker.sleepWindowInMilliseconds", value = "10000"),
@HystrixProperty(name = "circuitBreaker.errorThresholdPercentage", value = "50")
},
threadPoolProperties = {
@HystrixProperty(name = "coreSize", value = "10")
})

public List getData(String id, Date date) {
return null;
}
`

it works most of the times, but rarely without changing anything I get the following exception

java.lang.IllegalStateException: Collapser method must have one argument: public java.util.List getData(String,Date)

I checked the code of Hystrix and found that the meta holder factory checks if the HystrixCommand annotation is present then it initializes CommandMetaHolderFactory, otherwise CollapserMetaHolderFactory. In my case, I have the HystrixCommand but it still tries to use CollapserMetaHolderFactory which complains about method not having 1 argument.

This happens rarely and it's possible no one has seen it yet, I was just wondering if there is a recent fix related to this issue. I am using hystrix 1.5.0.

Thanks in advance.

[mattrjacobs]

I haven't heard any reports of this yet. @dmgcodevil - any idea what this might be?

[ppetrosyan]

Just to add more info, I continued looking at the code of Hystrix and it seems unbelievable what I am seeing in the logs because I can see it uses Java reflection and checks if HystrixCommand is present.

return method.isAnnotationPresent(HystrixCommand.class) ? COMMAND : COLLAPSER;

but the fact is I got this error on 2 out of 5 servers running the exact same code. I restarted one of the failed servers and problem went away, still have the other server in "bad" state so I can reproduce the problem with every request but as soon as I restart it, the problem most likely will go away.

This is not the first time we see this problem, about 2 months ago I noticed the same thing but restarted and couldn't reproduce. It's really interesting what's going on there.

[dmgcodevil]

Hi, will take a look at all javanica issues on this weekend

[dmgcodevil]

@ppetrosyan it's really weird, agree. It might be anything: JIT optimization that causes that issue, code cached since previous deployment (unlikely), concurrency issue and etc. I wonder if Collapser annotation is present in the method at this point either. Please continue updating the issue with your findings, I'll do the best from my side.

[matterche]

I'm facing a similar issue with this code (Javanica 1.5.6, Spring Boot 1.4.2):

@HystrixCommand(
            threadPoolKey = "get-purchase-orders-thread-pool",
            ignoreExceptions = {IllegalArgumentException.class, ResourceNotFoundException.class},
            commandProperties = {
                    @HystrixProperty(name = "execution.isolation.thread.timeoutInMilliseconds", value = "10000")
            }, threadPoolProperties = {
            @HystrixProperty(name = "maxQueueSize", value = "100"),
            @HystrixProperty(name = "queueSizeRejectionThreshold", value = "100")
    }
    )
    public Future<Optional<PurchaseOrder>> getPurchaseOrderByCode(final String code) {
       ...
    }

We have several nodes running the application. All worked fine for several days. Today requests bound to the command failed on all nodes with

...
Caused by: java.lang.NullPointerException: null
at com.netflix.hystrix.contrib.javanica.aop.aspectj.HystrixCommandAspect$CollapserMetaHolderFactory.create(HystrixCommandAspect.java:169) ~[hystrix-javanica-1.5.6.jar!/:1.5.6]
at com.netflix.hystrix.contrib.javanica.aop.aspectj.HystrixCommandAspect$MetaHolderFactory.create(HystrixCommandAspect.java:144) ~[hystrix-javanica-1.5.6.jar!/:1.5.6]
at com.netflix.hystrix.contrib.javanica.aop.aspectj.HystrixCommandAspect.methodsAnnotatedWithHystrixCommand(HystrixCommandAspect.java:90) ~[hystrix-javanica-1.5.6.jar!/:1.5.6]
...

A restart solved the issue but I couldn't reproduce it.

As we don't use HystrixCollapser in our code my guess was that

return method.isAnnotationPresent(HystrixCommand.class) ? COMMAND : COLLAPSER;

doesn't find any annotation at all so that hystrixCollapser is null when getDeclaredMethod is called in:

 public MetaHolder create(Object proxy, Method collapserMethod, Object obj, Object[] args, final ProceedingJoinPoint joinPoint) {
            HystrixCollapser hystrixCollapser = collapserMethod.getAnnotation(HystrixCollapser.class);
            if (collapserMethod.getParameterTypes().length > 1 || collapserMethod.getParameterTypes().length == 0) {
                throw new IllegalStateException("Collapser method must have one argument: " + collapserMethod);
            }

            Method batchCommandMethod = getDeclaredMethod(obj.getClass(), hystrixCollapser.batchMethod(), List.class);

But I don't know how this could happen.

One additional detail: getPurchaseOrderByCode implements an interface method which is not annotated.

[matterche]

What do you think about adding a sanity check to get more insights:

  private enum HystrixPointcutType {
        COMMAND,
        COLLAPSER;

        static HystrixPointcutType of(Method method) {
            if(method.isAnnotationPresent(HystrixCommand.class)){
                return COMMAND;
            } else if(method.isAnnotationPresent(HystrixCollapser.class)){
                return COLLAPSER;
            } else {
                throw new IllegalStateException("no valid annotation found for ...");
            }            
        }
    }

[dmgcodevil]

@ppetrosyan, @matterche could you please provide a bit more information:

1. Java version + JVM parameters
2. Does a class with hystrix command implement a generic interface ?
3. What kind of proxy do you use in your project, e.g. :

@EnableAspectJAutoProxy(proxyTargetClass = true) - CGLIB proxy
@EnableAspectJAutoProxy(proxyTargetClass = false) - JDK proxy
5. How big a command method is : 5, 10 or 100 lines
6. Is a method executed concurrently under heavy load

the idea to add an extra info could help us but I want to reproduce the issue
Thanks

[matterche]

Java version + JVM parameters

openjdk:8u91-b14-1-22

Does a class with hystrix command implement a generic interface ?

It implements an interface but not a generic one

What kind of proxy do you use in your project, e.g. :

JDK proxy

How big a command method is : 5, 10 or 100 lines

~ 30 lines

Is a method executed concurrently under heavy load

The method is run concurrently

[dmgcodevil]

I gave up trying to reproduce the issue. I tried to analyze JIT compilation log but didn't find anything suspicious, tried different computation modes: parallel and sequential under heavy load, both are working fine. I added a sanity check to get more insights, it should help to find out the root cause in a next time.
PR

[matterche]

👍

[ppetrosyan]

Thanks for looking at this. During this time I encountered this problem couple more times but no solid clue was found because it was really rare and random. I changed the code to not use Hystrix until this problem is solved, so I won't have new updates for a while. Here is the info you requested from my side.

Java version + JVM parameters
java version "1.8.0_91"
Java(TM) SE Runtime Environment (build 1.8.0_91-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.91-b14, mixed mode)

Does a class with hystrix command implement a generic interface ?
It implements an interface but not a generic one

What kind of proxy do you use in your project, e.g. :
JDK proxy

How big a command method is : 5, 10 or 100 lines
The method itself is less than 5 lines, but it calls other methods which exceed 100+ lines

Is a method executed concurrently under heavy load
The method is run concurrently

Hope the logs you added will help to find this issue.

Thanks