Spring-cloud-aws: Bug? Duplicated error logs when throwing exception inside SQS listener

Created on 3 Dec 2018 · 8Comments · Source: spring-cloud/spring-cloud-aws

So I'm not sure if this is indeed a but or expected behavior, but let me describe what is happening.

I have a simple SQS listener dealing with some messages (the SQS config is just a simple SimpleMessageListenerContainer and QueueMessageHandler with amazon client configuration):

@SqsListener(value = "${my.cool.queue}", deletionPolicy = SqsMessageDeletionPolicy.ON_SUCCESS)
public void messageReceived(final Object object) {
    // some code that might throw an exception
}

This listener works as intended, but has what I consider a weird behavior when dealing with exceptions. Since I'm using a deletion policy ON_SUCCESS, this means if something goes wrong during the processing I throw an exception. This works, but what I end up with is two error logs.

One comes from SimpleMessageListenerContainer's:
https://github.com/spring-cloud/spring-cloud-aws/blob/3bfd3a537192cf38a14c7a0c8df16876511db42a/spring-cloud-aws-messaging/src/main/java/org/springframework/cloud/aws/messaging/listener/SimpleMessageListenerContainer.java#L362

Which makes since, this is why the message is not deleted. However I also get another error log from:
https://github.com/spring-cloud/spring-cloud-aws/blob/64ec6d15c67e98c3372ab88c9e5b31d5a89a68f8/spring-cloud-aws-messaging/src/main/java/org/springframework/cloud/aws/messaging/listener/QueueMessageHandler.java#L213
This eventually hits spring-message processHandlerMethodException, which then logs an error if it is an unhandled exception.

And, well, this seems correct. It is indeed an unhanded exception, however it's an unhanded exception because that is how the SqsListener knows the message was not successful (and there is already a log of this error from the message container).

So the thing here is that I'm not sure if this is expected, if two errors should be logged from this behavior.

sqs waiting-for-triage enhancement

Source

fvcaputo

👍1

Most helpful comment

Also, just as a heads up if anyone is trying to deal with this "problem", you can have just one error log if you do something like:

@Component
public class MessageConsumer {
    private static final Logger LOGGER = LoggerFactory.getLogger(MessageConsumer.class);

    // ....

    @MessageExceptionHandler(Exception.class)
    public void exceptionHandler(Exception e) {
        LOGGER.info("MessageConsumer error", e);
    }

    @SqsListener(value = "${my.cool.queue}", deletionPolicy = SqsMessageDeletionPolicy.ON_SUCCESS)
    public void messageReceived(final Object object) {
        // some code that might throw an exception
    }
}

With this config the MessageExceptionHandler will just get any exception thrown from the listener and simply log it as info, so you get only one error log from spring (or you could also just ignore it and not log anything, just have an empty function).

fvcaputo on 5 Dec 2018

👍3

All 8 comments

I was also looking at this today (what a coincidence) . I think it should not get duplicated. Not only this I also notice a behavior where if I have a @Trasactional annotation on the listener method and runtime error is thrown and caught in the method.

@SqsListener(value = "${my.cool.queue}", deletionPolicy = SqsMessageDeletionPolicy.ON_SUCCESS)
@Transactional
public void messageReceived(final Object object) {
    try{
// some code that might throw an exception
     }catch(Exception e){
//handle error here
    }

}

Even we catch the exception the message is goes back to the SQS queue resulting message loop in my case. Can someone tell me how @Trasacational and queue message behave in this case please. ?

tmnuwan12 on 3 Dec 2018

Also, just as a heads up if anyone is trying to deal with this "problem", you can have just one error log if you do something like:

@Component
public class MessageConsumer {
    private static final Logger LOGGER = LoggerFactory.getLogger(MessageConsumer.class);

    // ....

    @MessageExceptionHandler(Exception.class)
    public void exceptionHandler(Exception e) {
        LOGGER.info("MessageConsumer error", e);
    }

    @SqsListener(value = "${my.cool.queue}", deletionPolicy = SqsMessageDeletionPolicy.ON_SUCCESS)
    public void messageReceived(final Object object) {
        // some code that might throw an exception
    }
}

fvcaputo on 5 Dec 2018

👍3

PRs welcome