We use spring boot (1.5) and integration to connect to Rabbit MQ as a service on PCF
Properties set - concurrency = 15 - maxConcurrency = 25 - default prefetch and txSize.
How the message are processed.
- The queue received 26 messages within less than 1 sec.
- 15 consumers started and completed with the next minute.
- Average time taken by each consumer is 30 secs approx.
- Few consumers took less than 15 secs.
- As each consumer acknowledged, new messages(16th, 17th message) from ready becomes unacknowledged on rabbit MQ.
So far as expected, since i assume new messages are being proccessed as old messages are acknowledged. But as new messages become unack'ed on rabbitMQ, they are not processed by any consumers. Consumers are stuck and idle.
- This continues and all ready state messages become unacknowledged and stay there without any activity.
- They all resume after approx 15mins.
I see this behavior always.
Any guidance ?
Here is the code that does wiring of rabbit MQ The MessageHandler in between has code that connects to big data and does some querying.
@Configuration
@EnableRabbit
public class RabbitMQ {
protected final Logger logger = LoggerFactory.getLogger(this.getClass());
@Value("${spring.rabbitmq.listener.concurrency:3}")
private int concurrentConsumers;
@Value("${spring.rabbitmq.listener.maxConcurrency:5}")
private int maxConcurrentConsumers;
@Value("${spring.rabbitmq.template.retry.max-attempts:3}")
private int maxAttempts;
@Value("${spring.rabbitmq.template.retry.initial-interval:2000}")
private int initialInterval;
@Value("${spring.rabbitmq.template.retry.multiplier:3}")
private int multiplier;
@Value("${spring.rabbitmq.template.retry.max-interval:10000}")
private int maxInterval;
@Autowired
private BotQueues botQueues;
@Autowired
private RetryFailLogger retryRecoverer;
@Bean
public StatefulRetryOperationsInterceptor statefulRetryOperationsInterceptor() {
return RetryInterceptorBuilder.stateful()
.backOffOptions(initialInterval, multiplier, maxInterval) // initialInterval, multiplier, maxInterval
.maxAttempts(maxAttempts)
.messageKeyGenerator(message -> message.getMessageProperties().getMessageId())
.recoverer(retryRecoverer)
.build();
}
@Bean
public Jackson2JsonMessageConverter defaultJsonMessageConverter() {
Jackson2JsonMessageConverter jsonConverter = new Jackson2JsonMessageConverter();
DefaultClassMapper classMapper = new DefaultClassMapper();
classMapper.setDefaultType(JobDetailInfo.class);
jsonConverter.setClassMapper(classMapper);
return jsonConverter;
}
@Bean
public SimpleMessageListenerContainer container(ConnectionFactory connectionFactory)
throws BeansException, ClassNotFoundException {
SimpleMessageListenerContainer container = new SimpleMessageListenerContainer(connectionFactory);
container.setQueues(botQueues.inputQueues());
container.setConcurrentConsumers(concurrentConsumers);
container.setMaxConcurrentConsumers(maxConcurrentConsumers);
container.setChannelTransacted(true);
container.setAdviceChain(new Advice[] {statefulRetryOperationsInterceptor()});
return container;
}
@Bean
public AmqpInboundChannelAdapter inbound(SimpleMessageListenerContainer container,
@Qualifier("commonInputChannel") MessageChannel amqpInputChannel) {
AmqpInboundChannelAdapter adapter = new AmqpInboundChannelAdapter(container);
adapter.setMessageConverter(defaultJsonMessageConverter());
adapter.setOutputChannel(amqpInputChannel);
return adapter;
}
@Bean
@ServiceActivator(inputChannel = "commonInputChannel", outputChannel = "commonOutputChannel")
public MessageHandler messageHandler() {
return new MessageHandler();
}
@Router(inputChannel = "commonOutputChannel")
public String resolveJobChannel(JobDetailInfo jobDetailInfo) {
String returnChannel = "";
if (jobDetailInfo != null) {
switch (jobDetailInfo.getJobStatus()) {
case Scheduled:
returnChannel = "collectorChannel";
break;
default:
break;
}
}
return returnChannel;
}
}
Thread Dump:
{"threadName":"container-14","threadId":40,"blockedTime":-1,"blockedCount":45,"waitedTime":-1,"waitedCount":66654,"lockName":"java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1b4302a9","lockOwnerId":-1,"lockOwnerName":null,"inNative":false,"suspended":false,"threadState":"TIMED_WAITING","stackTrace":[{"methodName":"park","fileName":"Unsafe.java","lineNumber":-2,"className":"sun.misc.Unsafe","nativeMethod":true},{"methodName":"parkNanos","fileName":"LockSupport.java","lineNumber":215,"className":"java.util.concurrent.locks.LockSupport","nativeMethod":false},{"methodName":"awaitNanos","fileName":"AbstractQueuedSynchronizer.java","lineNumber":2078,"className":"java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject","nativeMethod":false},{"methodName":"poll","fileName":"LinkedBlockingQueue.java","lineNumber":467,"className":"java.util.concurrent.LinkedBlockingQueue","nativeMethod":false},{"methodName":"nextMessage","fileName":"BlockingQueueConsumer.java","lineNumber":461,"className":"org.springframework.amqp.rabbit.listener.BlockingQueueConsumer","nativeMethod":false},{"methodName":"doReceiveAndExecute","fileName":"SimpleMessageListenerContainer.java","lineNumber":1214,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer","nativeMethod":false},{"methodName":"receiveAndExecute","fileName":"SimpleMessageListenerContainer.java","lineNumber":1189,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer","nativeMethod":false},{"methodName":"access$1500","fileName":"SimpleMessageListenerContainer.java","lineNumber":97,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer","nativeMethod":false},{"methodName":"run","fileName":"SimpleMessageListenerContainer.java","lineNumber":1421,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$AsyncMessageProcessingConsumer","nativeMethod":false},{"methodName":"run","fileName":"Thread.java","lineNumber":748,"className":"java.lang.Thread","nativeMethod":false}],"lockedMonitors":[],"lockedSynchronizers":[],"lockInfo":{"className":"java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject","identityHashCode":457376425}},
{"threadName":"container-13","threadId":39,"blockedTime":-1,"blockedCount":34,"waitedTime":-1,"waitedCount":66160,"lockName":null,"lockOwnerId":-1,"lockOwnerName":null,"inNative":true,"suspended":false,"threadState":"RUNNABLE","stackTrace":[{"methodName":"socketRead0","fileName":"SocketInputStream.java","lineNumber":-2,"className":"java.net.SocketInputStream","nativeMethod":true},{"methodName":"socketRead","fileName":"SocketInputStream.java","lineNumber":116,"className":"java.net.SocketInputStream","nativeMethod":false},{"methodName":"read","fileName":"SocketInputStream.java","lineNumber":171,"className":"java.net.SocketInputStream","nativeMethod":false},{"methodName":"read","fileName":"SocketInputStream.java","lineNumber":141,"className":"java.net.SocketInputStream","nativeMethod":false},{"methodName":"readMore","fileName":"VisibleBufferedInputStream.java","lineNumber":140,"className":"org.postgresql.core.VisibleBufferedInputStream","nativeMethod":false},{"methodName":"ensureBytes","fileName":"VisibleBufferedInputStream.java","lineNumber":109,"className":"org.postgresql.core.VisibleBufferedInputStream","nativeMethod":false},{"methodName":"read","fileName":"VisibleBufferedInputStream.java","lineNumber":67,"className":"org.postgresql.core.VisibleBufferedInputStream","nativeMethod":false},{"methodName":"receiveChar","fileName":"PGStream.java","lineNumber":280,"className":"org.postgresql.core.PGStream","nativeMethod":false},{"methodName":"processResults","fileName":"QueryExecutorImpl.java","lineNumber":1916,"className":"org.postgresql.core.v3.QueryExecutorImpl","nativeMethod":false},{"methodName":"execute","fileName":"QueryExecutorImpl.java","lineNumber":288,"className":"org.postgresql.core.v3.QueryExecutorImpl","nativeMethod":false},{"methodName":"executeInternal","fileName":"PgStatement.java","lineNumber":430,"className":"org.postgresql.jdbc.PgStatement","nativeMethod":false},{"methodName":"execute","fileName":"PgStatement.java","lineNumber":356,"className":"org.postgresql.jdbc.PgStatement","nativeMethod":false},{"methodName":"executeWithFlags","fileName":"PgStatement.java","lineNumber":303,"className":"org.postgresql.jdbc.PgStatement","nativeMethod":false},{"methodName":"executeCachedSql","fileName":"PgStatement.java","lineNumber":289,"className":"org.postgresql.jdbc.PgStatement","nativeMethod":false},{"methodName":"executeWithFlags","fileName":"PgStatement.java","lineNumber":266,"className":"org.postgresql.jdbc.PgStatement","nativeMethod":false},{"methodName":"execute","fileName":"PgStatement.java","lineNumber":262,"className":"org.postgresql.jdbc.PgStatement","nativeMethod":false},{"methodName":"validate","fileName":"PooledConnection.java","lineNumber":532,"className":"org.apache.tomcat.jdbc.pool.PooledConnection","nativeMethod":false},{"methodName":"validate","fileName":"PooledConnection.java","lineNumber":443,"className":"org.apache.tomcat.jdbc.pool.PooledConnection","nativeMethod":false},{"methodName":"borrowConnection","fileName":"ConnectionPool.java","lineNumber":802,"className":"org.apache.tomcat.jdbc.pool.ConnectionPool","nativeMethod":false},{"methodName":"borrowConnection","fileName":"ConnectionPool.java","lineNumber":651,"className":"org.apache.tomcat.jdbc.pool.ConnectionPool","nativeMethod":false},{"methodName":"getConnection","fileName":"ConnectionPool.java","lineNumber":198,"className":"org.apache.tomcat.jdbc.pool.ConnectionPool","nativeMethod":false},{"methodName":"getConnection","fileName":"DataSourceProxy.java","lineNumber":132,"className":"org.apache.tomcat.jdbc.pool.DataSourceProxy","nativeMethod":false},{"methodName":"getConnection","fileName":"DatasourceConnectionProviderImpl.java","lineNumber":122,"className":"org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl","nativeMethod":false},{"methodName":"obtainConnection","fileName":"NonContextualJdbcConnectionAccess.java","lineNumber":35,"className":"org.hibernate.internal.NonContextualJdbcConnectionAccess","nativeMethod":false},{"methodName":"acquireConnectionIfNeeded","fileName":"LogicalConnectionManagedImpl.java","lineNumber":99,"className":"org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl","nativeMethod":false},{"methodName":"getPhysicalConnection","fileName":"LogicalConnectionManagedImpl.java","lineNumber":129,"className":"org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl","nativeMethod":false},{"methodName":"getConnectionForTransactionManagement","fileName":"LogicalConnectionManagedImpl.java","lineNumber":247,"className":"org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl","nativeMethod":false},{"methodName":"begin","fileName":"LogicalConnectionManagedImpl.java","lineNumber":254,"className":"org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl","nativeMethod":false},{"methodName":"begin","fileName":"JdbcResourceLocalTransactionCoordinatorImpl.java","lineNumber":203,"className":"org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl","nativeMethod":false},{"methodName":"begin","fileName":"TransactionImpl.java","lineNumber":56,"className":"org.hibernate.engine.transaction.internal.TransactionImpl","nativeMethod":false},{"methodName":"beginTransaction","fileName":"HibernateJpaDialect.java","lineNumber":189,"className":"org.springframework.orm.jpa.vendor.HibernateJpaDialect","nativeMethod":false},{"methodName":"doBegin","fileName":"JpaTransactionManager.java","lineNumber":380,"className":"org.springframework.orm.jpa.JpaTransactionManager","nativeMethod":false},{"methodName":"getTransaction","fileName":"AbstractPlatformTransactionManager.java","lineNumber":373,"className":"org.springframework.transaction.support.AbstractPlatformTransactionManager","nativeMethod":false},{"methodName":"createTransactionIfNecessary","fileName":"TransactionAspectSupport.java","lineNumber":447,"className":"org.springframework.transaction.interceptor.TransactionAspectSupport","nativeMethod":false},{"methodName":"invokeWithinTransaction","fileName":"TransactionAspectSupport.java","lineNumber":277,"className":"org.springframework.transaction.interceptor.TransactionAspectSupport","nativeMethod":false},{"methodName":"invoke","fileName":"TransactionInterceptor.java","lineNumber":96,"className":"org.springframework.transaction.interceptor.TransactionInterceptor","nativeMethod":false},{"methodName":"proceed","fileName":"ReflectiveMethodInvocation.java","lineNumber":179,"className":"org.springframework.aop.framework.ReflectiveMethodInvocation","nativeMethod":false},{"methodName":"intercept","fileName":"CglibAopProxy.java","lineNumber":673,"className":"org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor","nativeMethod":false},{"methodName":"handleMessage","fileName":"","lineNumber":-1,"className":"message.handlers.MessageHandler$$EnhancerBySpringCGLIB$$cf53d23e","nativeMethod":false},{"methodName":"invoke","fileName":null,"lineNumber":-1,"className":"sun.reflect.GeneratedMethodAccessor145","nativeMethod":false},{"methodName":"invoke","fileName":"DelegatingMethodAccessorImpl.java","lineNumber":43,"className":"sun.reflect.DelegatingMethodAccessorImpl","nativeMethod":false},{"methodName":"invoke","fileName":"Method.java","lineNumber":498,"className":"java.lang.reflect.Method","nativeMethod":false},{"methodName":"execute","fileName":"ReflectiveMethodExecutor.java","lineNumber":113,"className":"org.springframework.expression.spel.support.ReflectiveMethodExecutor","nativeMethod":false},{"methodName":"getValueInternal","fileName":"MethodReference.java","lineNumber":102,"className":"org.springframework.expression.spel.ast.MethodReference","nativeMethod":false},{"methodName":"access$000","fileName":"MethodReference.java","lineNumber":49,"className":"org.springframework.expression.spel.ast.MethodReference","nativeMethod":false},{"methodName":"getValue","fileName":"MethodReference.java","lineNumber":347,"className":"org.springframework.expression.spel.ast.MethodReference$MethodValueRef","nativeMethod":false},{"methodName":"getValueInternal","fileName":"CompoundExpression.java","lineNumber":88,"className":"org.springframework.expression.spel.ast.CompoundExpression","nativeMethod":false},{"methodName":"getTypedValue","fileName":"SpelNodeImpl.java","lineNumber":131,"className":"org.springframework.expression.spel.ast.SpelNodeImpl","nativeMethod":false},{"methodName":"getValue","fileName":"SpelExpression.java","lineNumber":330,"className":"org.springframework.expression.spel.standard.SpelExpression","nativeMethod":false},{"methodName":"evaluateExpression","fileName":"AbstractExpressionEvaluator.java","lineNumber":169,"className":"org.springframework.integration.util.AbstractExpressionEvaluator","nativeMethod":false},{"methodName":"processInternal","fileName":"MessagingMethodInvokerHelper.java","lineNumber":319,"className":"org.springframework.integration.util.MessagingMethodInvokerHelper","nativeMethod":false},{"methodName":"process","fileName":"MessagingMethodInvokerHelper.java","lineNumber":155,"className":"org.springframework.integration.util.MessagingMethodInvokerHelper","nativeMethod":false},{"methodName":"processMessage","fileName":"MethodInvokingMessageProcessor.java","lineNumber":93,"className":"org.springframework.integration.handler.MethodInvokingMessageProcessor","nativeMethod":false},{"methodName":"handleRequestMessage","fileName":"ServiceActivatingHandler.java","lineNumber":89,"className":"org.springframework.integration.handler.ServiceActivatingHandler","nativeMethod":false},{"methodName":"handleMessageInternal","fileName":"AbstractReplyProducingMessageHandler.java","lineNumber":109,"className":"org.springframework.integration.handler.AbstractReplyProducingMessageHandler","nativeMethod":false},{"methodName":"handleMessage","fileName":"AbstractMessageHandler.java","lineNumber":127,"className":"org.springframework.integration.handler.AbstractMessageHandler","nativeMethod":false},{"methodName":"doDispatch","fileName":"UnicastingDispatcher.java","lineNumber":160,"className":"org.springframework.integration.dispatcher.UnicastingDispatcher","nativeMethod":false},{"methodName":"dispatch","fileName":"UnicastingDispatcher.java","lineNumber":121,"className":"org.springframework.integration.dispatcher.UnicastingDispatcher","nativeMethod":false},{"methodName":"doSend","fileName":"AbstractSubscribableChannel.java","lineNumber":89,"className":"org.springframework.integration.channel.AbstractSubscribableChannel","nativeMethod":false},{"methodName":"send","fileName":"AbstractMessageChannel.java","lineNumber":423,"className":"org.springframework.integration.channel.AbstractMessageChannel","nativeMethod":false},{"methodName":"send","fileName":"AbstractMessageChannel.java","lineNumber":373,"className":"org.springframework.integration.channel.AbstractMessageChannel","nativeMethod":false},{"methodName":"doSend","fileName":"GenericMessagingTemplate.java","lineNumber":115,"className":"org.springframework.messaging.core.GenericMessagingTemplate","nativeMethod":false},{"methodName":"doSend","fileName":"GenericMessagingTemplate.java","lineNumber":45,"className":"org.springframework.messaging.core.GenericMessagingTemplate","nativeMethod":false},{"methodName":"send","fileName":"AbstractMessageSendingTemplate.java","lineNumber":105,"className":"org.springframework.messaging.core.AbstractMessageSendingTemplate","nativeMethod":false},{"methodName":"sendMessage","fileName":"MessageProducerSupport.java","lineNumber":188,"className":"org.springframework.integration.endpoint.MessageProducerSupport","nativeMethod":false},{"methodName":"access$1100","fileName":"AmqpInboundChannelAdapter.java","lineNumber":56,"className":"org.springframework.integration.amqp.inbound.AmqpInboundChannelAdapter","nativeMethod":false},{"methodName":"processMessage","fileName":"AmqpInboundChannelAdapter.java","lineNumber":246,"className":"org.springframework.integration.amqp.inbound.AmqpInboundChannelAdapter$Listener","nativeMethod":false},{"methodName":"onMessage","fileName":"AmqpInboundChannelAdapter.java","lineNumber":203,"className":"org.springframework.integration.amqp.inbound.AmqpInboundChannelAdapter$Listener","nativeMethod":false},{"methodName":"doInvokeListener","fileName":"AbstractMessageListenerContainer.java","lineNumber":822,"className":"org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer","nativeMethod":false},{"methodName":"invokeListener","fileName":"AbstractMessageListenerContainer.java","lineNumber":745,"className":"org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer","nativeMethod":false},{"methodName":"access$001","fileName":"SimpleMessageListenerContainer.java","lineNumber":97,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer","nativeMethod":false},{"methodName":"invokeListener","fileName":"SimpleMessageListenerContainer.java","lineNumber":189,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$1","nativeMethod":false},{"methodName":"invoke","fileName":null,"lineNumber":-1,"className":"sun.reflect.GeneratedMethodAccessor112","nativeMethod":false},{"methodName":"invoke","fileName":"DelegatingMethodAccessorImpl.java","lineNumber":43,"className":"sun.reflect.DelegatingMethodAccessorImpl","nativeMethod":false},{"methodName":"invoke","fileName":"Method.java","lineNumber":498,"className":"java.lang.reflect.Method","nativeMethod":false},{"methodName":"invokeJoinpointUsingReflection","fileName":"AopUtils.java","lineNumber":333,"className":"org.springframework.aop.support.AopUtils","nativeMethod":false},{"methodName":"invokeJoinpoint","fileName":"ReflectiveMethodInvocation.java","lineNumber":190,"className":"org.springframework.aop.framework.ReflectiveMethodInvocation","nativeMethod":false},{"methodName":"proceed","fileName":"ReflectiveMethodInvocation.java","lineNumber":157,"className":"org.springframework.aop.framework.ReflectiveMethodInvocation","nativeMethod":false},{"methodName":"doWithRetry","fileName":"StatefulRetryOperationsInterceptor.java","lineNumber":229,"className":"org.springframework.retry.interceptor.StatefulRetryOperationsInterceptor$MethodInvocationRetryCallback","nativeMethod":false},{"methodName":"doExecute","fileName":"RetryTemplate.java","lineNumber":286,"className":"org.springframework.retry.support.RetryTemplate","nativeMethod":false},{"methodName":"execute","fileName":"RetryTemplate.java","lineNumber":210,"className":"org.springframework.retry.support.RetryTemplate","nativeMethod":false},{"methodName":"invoke","fileName":"StatefulRetryOperationsInterceptor.java","lineNumber":173,"className":"org.springframework.retry.interceptor.StatefulRetryOperationsInterceptor","nativeMethod":false},{"methodName":"proceed","fileName":"ReflectiveMethodInvocation.java","lineNumber":179,"className":"org.springframework.aop.framework.ReflectiveMethodInvocation","nativeMethod":false},{"methodName":"invoke","fileName":"JdkDynamicAopProxy.java","lineNumber":213,"className":"org.springframework.aop.framework.JdkDynamicAopProxy","nativeMethod":false},{"methodName":"invokeListener","fileName":null,"lineNumber":-1,"className":"com.sun.proxy.$Proxy137","nativeMethod":false},{"methodName":"invokeListener","fileName":"SimpleMessageListenerContainer.java","lineNumber":1276,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer","nativeMethod":false},{"methodName":"executeListener","fileName":"AbstractMessageListenerContainer.java","lineNumber":726,"className":"org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer","nativeMethod":false},{"methodName":"doReceiveAndExecute","fileName":"SimpleMessageListenerContainer.java","lineNumber":1219,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer","nativeMethod":false},{"methodName":"receiveAndExecute","fileName":"SimpleMessageListenerContainer.java","lineNumber":1189,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer","nativeMethod":false},{"methodName":"access$1500","fileName":"SimpleMessageListenerContainer.java","lineNumber":97,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer","nativeMethod":false},{"methodName":"run","fileName":"SimpleMessageListenerContainer.java","lineNumber":1421,"className":"org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$AsyncMessageProcessingConsumer","nativeMethod":false},{"methodName":"run","fileName":"Thread.java","lineNumber":748,"className":"java.lang.Thread","nativeMethod":false}],"lockedMonitors":[{"className":"org.postgresql.core.v3.QueryExecutorImpl","identityHashCode":1428002949,"lockedStackDepth":9,"lockedStackFrame":{"methodName":"execute","fileName":"QueryExecutorImpl.java","lineNumber":288,"className":"org.postgresql.core.v3.QueryExecutorImpl","nativeMethod":false}}],"lockedSynchronizers":[{"className":"java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync","identityHashCode":1110565932}],"lockInfo":null}
