Veit Guna opened SPR-17026 and commented

Hi.

We're running a high load REST service using Oracle JDK 1.8.0_162, Tomcat 7.0.85, RabbitMQ 3.6.10, Newrelic Agent 4.0.0, Prometheus Agent 0.9, Spring 4.3.14 and  spring-rabbit 1.7.6 on a AWS EC2/ECS cluster.

The service works with RabbitMQ queues where we listen for messages in several listeners. Lately we encountered that one of the listeners started to throw exceptions like the one below. As you can see in the Stacktrace, there's no sign of our code involved. Just JDK and Spring classes. It seems to die by looking up a method on the listener Class. It started on one of our nodes, then some days/deploys later on other nodes as well - leading to massive errors (~150k) per day.

The listener has several queue binding methods and the error was thrown by different methods on this class.

Googling showed a similar problem here: #17516

There it was about some JVM crashing/JDK bug (what doesn't happen for us) and some sign of NewRelic Agent might being involved. But both "bugs" have been solved years ago.

So I'm wondering if you guys have encountered similar problems in the past with a similar setup.

Listener:

@Component
public class Listener {

    @Autowired
    private RabbitOperations rabbitOperations;

    @RabbitListener(bindings = {
            @QueueBinding(
                    exchange = @Exchange(value = MessageA.EXCHANGE, type = ExchangeTypes.TOPIC, durable = "true"),
                    value = @Queue(
                            value = Queues.IN_NEW_QUEUE, durable = "true",
                            arguments = @Argument(name = "x-expires", value = Queues.Q_EXPIRES, type = "java.lang.Long")
                            ),
                    key = "#")
    })
    public void someMethod(@Payload @Valid MessageA message) {
        ...
    }

    @RabbitListener(bindings = {
            @QueueBinding(
                    exchange = @Exchange(value = MessageB.EXCHANGE, type = ExchangeTypes.TOPIC, durable = "true"),
                    value = @Queue(
                            value = Queues.IN_STATE_CHANGE_QUEUE, durable = "true",
                            arguments = @Argument(name = "x-expires", value = Queues.Q_EXPIRES, type = "java.lang.Long")
                            ),
                    key = Message.TOPIC_PLATFORM + "#"),
            @QueueBinding(
                    exchange = @Exchange(value = MessageB.EXCHANGE, type = ExchangeTypes.TOPIC, durable = "true"),
                    value = @Queue(
                            value = Queues.IN_STATE_CHANGE_QUEUE, durable = "true",
                            arguments = @Argument(name = "x-expires", value = Queues.Q_EXPIRES, type = "java.lang.Long")
                            ),
                    key = Message.TOPIC_TEST + ".#")})
    public void someMethodB(@Payload @Valid MessageB message) {
        ...
    }

    @RabbitListener(bindings = {
            @QueueBinding(
                    exchange = @Exchange(value = MessageC.EXCHANGE, type = ExchangeTypes.TOPIC, durable = "true"),
                    value = @Queue(
                            value = Queues.IN_TRACKING_CHANGE_QUEUE, durable = "true",
                            arguments = @Argument(name = "x-expires", value = Queues.Q_EXPIRES, type = "java.lang.Long")
                            ),
                    key = Message.TOPIC_PLATFORM + "#"),
            @QueueBinding(
                    exchange = @Exchange(value = MessageC.EXCHANGE, type = ExchangeTypes.TOPIC, durable = "true"),
                    value = @Queue(
                            value = Queues.IN_TRACKING_CHANGE_QUEUE, durable = "true",
                            arguments = @Argument(name = "x-expires", value = Queues.Q_EXPIRES, type = "java.lang.Long")
                            ),
                    key = Message.TOPIC_TEST + ".#")})
    public void someMethodC(@Payload @Valid MessageC message) {
        ...
    }

    ...
}

Exception that was thrown:

2018-07-06 10:50:09,478 [ERROR]  pool-14-thread-9     c.n.messaging.RabbitErrorHandler - Too many errors in Rabbit message listeners; message rejected.
org.springframework.amqp.rabbit.listener.exception.ListenerExecutionFailedException: Listener method 'public void com.acme.Listener.someMethod(com.acme.Message)' threw exception
    at org.springframework.amqp.rabbit.listener.adapter.MessagingMessageListenerAdapter.invokeHandler(MessagingMessageListenerAdapter.java:140)
    at org.springframework.amqp.rabbit.listener.adapter.MessagingMessageListenerAdapter.onMessage(MessagingMessageListenerAdapter.java:106)
    at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.doInvokeListener(AbstractMessageListenerContainer.java:856)
    at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.invokeListener(AbstractMessageListenerContainer.java:779)
    at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.access$001(SimpleMessageListenerContainer.java:105)
    at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$1.invokeListener(SimpleMessageListenerContainer.java:208)
    at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.invokeListener(SimpleMessageListenerContainer.java:1349)
    at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.executeListener(AbstractMessageListenerContainer.java:760)
    at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.doReceiveAndExecute(SimpleMessageListenerContainer.java:1292)
    at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.receiveAndExecute(SimpleMessageListenerContainer.java:1262)
    at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.access$1800(SimpleMessageListenerContainer.java:105)
    at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$AsyncMessageProcessingConsumer.run(SimpleMessageListenerContainer.java:1518)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NegativeArraySizeException: null
    at java.lang.Class.getDeclaredMethods0(Native Method)
    at java.lang.Class.privateGetDeclaredMethods(Class.java:2701)
    at java.lang.Class.getDeclaredMethod(Class.java:2128)
    at org.springframework.core.LocalVariableTableParameterNameDiscoverer$LocalVariableTableVisitor.resolveMember(LocalVariableTableParameterNameDiscoverer.java:245)
    at org.springframework.core.LocalVariableTableParameterNameDiscoverer$LocalVariableTableVisitor.visitEnd(LocalVariableTableParameterNameDiscoverer.java:231)
    at org.springframework.asm.ClassReader.readMethod(ClassReader.java:1172)
    at org.springframework.asm.ClassReader.accept(ClassReader.java:729)
    at org.springframework.asm.ClassReader.accept(ClassReader.java:527)
    at org.springframework.core.LocalVariableTableParameterNameDiscoverer.inspectClass(LocalVariableTableParameterNameDiscoverer.java:114)
    at org.springframework.core.LocalVariableTableParameterNameDiscoverer.getParameterNames(LocalVariableTableParameterNameDiscoverer.java:73)
    at org.springframework.core.PrioritizedParameterNameDiscoverer.getParameterNames(PrioritizedParameterNameDiscoverer.java:53)
    at org.springframework.core.MethodParameter.getParameterName(MethodParameter.java:553)
    at org.springframework.messaging.handler.annotation.support.PayloadArgumentResolver.getParameterName(PayloadArgumentResolver.java:150)
    at org.springframework.messaging.handler.annotation.support.PayloadArgumentResolver.validate(PayloadArgumentResolver.java:193)
    at org.springframework.messaging.handler.annotation.support.PayloadArgumentResolver.resolveArgument(PayloadArgumentResolver.java:129)
    at org.springframework.messaging.handler.invocation.HandlerMethodArgumentResolverComposite.resolveArgument(HandlerMethodArgumentResolverComposite.java:112)
    at org.springframework.messaging.handler.invocation.InvocableHandlerMethod.getMethodArgumentValues(InvocableHandlerMethod.java:135)
    at org.springframework.messaging.handler.invocation.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:107)
    at org.springframework.amqp.rabbit.listener.adapter.HandlerAdapter.invoke(HandlerAdapter.java:49)
    at org.springframework.amqp.rabbit.listener.adapter.MessagingMessageListenerAdapter.invokeHandler(MessagingMessageListenerAdapter.java:126)
    ... 14 common frames omitted


Affects: 4.3.14

Comment From: xiaohenry

What was the resolution for this?

Comment From: snicoll

@xiaohenry perhaps you're looking at this page on a phone? The issue is opened and has not been fixed yet.

Comment From: snicoll

This really looks like a duplicate of #17516 and the exception is consistent with the side effect an agent could do. If you can replicate the issue without the agent, please raise an issue with the Spring AMQP project.