Cannot Connect (temporary queue server failure) prevents container start

[jrussell]

Hello all,

We have just started using Spring AMQP / Rabbit MQ within our project and have run into a problem that I am hoping there is a known solution for.

We have a consumer application using a pretty by-the-book <rabbit:listener-container/> configuration, and all works well when it is working. What we have run into is if there is a problem contacting the queue server(s) on startup, the entire container startup is failed.

This can be simulated on a linux consumer box by either pointing the consumer at a non-existant IP address, or using iptables to drop the outgoing request packets:

iptables -A OUTPUT -p tcp --destination-port 5672 -j DROP

- the problem is this means a transient connection issue during startup could cause complete startup failure.

I have looked through the code, and it is clear that it is coded just this way.. in
org.springframework.amqp.rabbit.listener.SimpleMes sageListenerContainer.AsyncMessageProcessingConsum er.getStartupException()

an exception is blindly thrown if the initialization does not complete by a timeout.

Our expectation would be that unable to connect should just retry, just as bad password or rejected connections do.

Any work around or potential solution short of writing a custom MessageListenerContainer?

Thanks
Russell

[Gary Russell]

What version(s) are you using?

I just ran a test where the broker is simply down, it keeps retrying...

11:07:56.579 WARN  [SimpleAsyncTaskExecutor-1][org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer] Consumer raised exception, processing can restart if the connection factory supports it. Exception summary: org.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection refused
11:08:01.608 WARN  [SimpleAsyncTaskExecutor-2][org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer] Consumer raised exception, processing can restart if the connection factory supports it. Exception summary: org.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection refused
11:08:06.633 WARN  [SimpleAsyncTaskExecutor-3][org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer] Consumer raised exception, processing can restart if the connection factory supports it. Exception summary: org.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection refused
11:08:11.657 WARN  [SimpleAsyncTaskExecutor-4][org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer] Consumer raised exception, processing can restart if the connection factory supports it. Exception summary: org.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection refused
11:08:16.682 WARN  [SimpleAsyncTaskExecutor-5][org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer] Consumer raised exception, processing can restart if the connection factory supports it. Exception summary: org.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection refused
11:08:21.709 WARN  [SimpleAsyncTaskExecutor-6][org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer] Consumer raised exception, processing can restart if the connection factory supports it. Exception summary: org.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection refused
11:08:26.735 WARN  [SimpleAsyncTaskExecutor-7][org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer] Consumer raised exception, processing can restart if the connection factory supports it. Exception summary: org.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection refused

I am on the road, so replies might be sporadic.

[jrussell]

What version(s) are you using?
I just ran a test where the broker is simply down, it keeps retrying...

We were using 1.1.1-RELEASE, and I just tested with 1.1.3-RELEASE.

I agree, Broker down does not cause the issue. The issue is caused by missing machines (no machine at at the target IP/crashed server) or network/firewall issues causing connectivity issues, specifically dropped packets.

It should be noted that windows vs linux behave differently on the missing server case - windows apparently gives some response that the container is happier with and it will go into the retry cycle. On linux missing server or any other cause of dropped packets will cause the below error. This can be simulated easily on a linux machine with

sudo iptables -A OUTPUT -p tcp --destination-port 5672 -j DROP

(adjusting port as necessary)

org.springframework.context.ApplicationContextException: Failed to start bean 'org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer#0'; nested exception is org.springframework.amqp.UncategorizedAmqpException: java.util.concurrent.TimeoutException: Timed out waiting for startup
	at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:170)
	at org.springframework.context.support.DefaultLifecycleProcessor.access$1(DefaultLifecycleProcessor.java:154)
	at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.start(DefaultLifecycleProcessor.java:339)
	at org.springframework.context.support.DefaultLifecycleProcessor.startBeans(DefaultLifecycleProcessor.java:143)
	at org.springframework.context.support.DefaultLifecycleProcessor.onRefresh(DefaultLifecycleProcessor.java:108)
	at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:926)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:467)
	at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:384)
	at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:283)
	at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:111)
	at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4205)
	at org.apache.catalina.core.StandardContext.start(StandardContext.java:4704)
	at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:799)
	at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:779)
	at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:601)
	at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:675)
	at org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:601)
	at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:502)
	at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1315)
	at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:324)
	at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:142)
	at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1061)
	at org.apache.catalina.core.StandardHost.start(StandardHost.java:840)
	at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053)
	at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:463)
	at org.apache.catalina.core.StandardService.start(StandardService.java:525)
	at org.apache.catalina.core.StandardServer.start(StandardServer.java:754)
	at org.apache.catalina.startup.Catalina.start(Catalina.java:595)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
	at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
Caused by: org.springframework.amqp.UncategorizedAmqpException: java.util.concurrent.TimeoutException: Timed out waiting for startup
	at org.springframework.amqp.rabbit.connection.RabbitUtils.convertRabbitAccessException(RabbitUtils.java:115)
	at org.springframework.amqp.rabbit.connection.RabbitAccessor.convertRabbitAccessException(RabbitAccessor.java:106)
	at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.start(AbstractMessageListenerContainer.java:362)
	at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:167)
	... 33 more
Caused by: java.util.concurrent.TimeoutException: Timed out waiting for startup
	at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$AsyncMessageProcessingConsumer.getStartupException(SimpleMessageListenerContainer.java:504)
	at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.doStart(SimpleMessageListenerContainer.java:331)
	at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.start(AbstractMessageListenerContainer.java:360)
	... 34 more

[jrussell]

Yikes, I replied a few days ago, but apparently the message board ate my message... In any case:

We are using 1.1.1.RELEASE, though I have also tested with 1.1.3.RELEASE with the same results.

No, broker down will not cause this issue, as in that case your server will simply REJECT the request, not drop the packets.

The scenario that causes this issue is when the server itself is not there, thus no response at all, or a network or firewall issue causes a non-response scenario. As I mentioned above, the quickest way to simulate the issue is
with an iptables rule to drop all packets being sent to the amqp port

iptables -A OUTPUT -p tcp --destination-port 5672 -j DROP

2012-12-14 12:00:58,097 ERROR tp-9180-21 ContextLoader - Context initialization failed
org.springframework.context.ApplicationContextException: Failed to start bean 'org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer#0'; nested exception is org.springframework.amqp.UncategorizedAmqpException: java.util.concurrent.TimeoutException: Timed out waiting for startup
	at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:170)
	at org.springframework.context.support.DefaultLifecycleProcessor.access$1(DefaultLifecycleProcessor.java:154)
	at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.start(DefaultLifecycleProcessor.java:339)
	at org.springframework.context.support.DefaultLifecycleProcessor.startBeans(DefaultLifecycleProcessor.java:143)
	at org.springframework.context.support.DefaultLifecycleProcessor.onRefresh(DefaultLifecycleProcessor.java:108)
	at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:926)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:467)
	at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:384)
	at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:283)
	at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:111)
	at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4205)
	at org.apache.catalina.core.StandardContext.start(StandardContext.java:4704)
	at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:799)
	at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:779)
	at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:601)
	at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:675)
	at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:559)
	at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1397)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.apache.tomcat.util.modeler.BaseModelMBean.invoke(BaseModelMBean.java:297)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:791)
	at org.apache.catalina.manager.ManagerServlet.check(ManagerServlet.java:1500)
	at org.apache.catalina.manager.ManagerServlet.deploy(ManagerServlet.java:849)
	at org.apache.catalina.manager.ManagerServlet.doGet(ManagerServlet.java:351)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:563)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
	at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:864)
	at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:579)
	at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1665)
	at java.lang.Thread.run(Thread.java:722)
Caused by: org.springframework.amqp.UncategorizedAmqpException: java.util.concurrent.TimeoutException: Timed out waiting for startup
	at org.springframework.amqp.rabbit.connection.RabbitUtils.convertRabbitAccessException(RabbitUtils.java:115)
	at org.springframework.amqp.rabbit.connection.RabbitAccessor.convertRabbitAccessException(RabbitAccessor.java:106)
	at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.start(AbstractMessageListenerContainer.java:362)
	at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:167)
	... 42 more
Caused by: java.util.concurrent.TimeoutException: Timed out waiting for startup
	at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$AsyncMessageProcessingConsumer.getStartupException(SimpleMessageListenerContainer.java:504)
	at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer.doStart(SimpleMessageListenerContainer.java:331)
	at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.start(AbstractMessageListenerContainer.java:360)
	... 43 more

[Gary Russell]

Please go ahead and open a JIRA issue, and I'll take a look at it...

https://jira.springsource.org/browse/AMQP

[jrussell]

Issue created
https://jira.springsource.org/browse/AMQP-287

My apologies for the delay, I was out on holiday break. Thank you for your attention on this!