java.util.concurrent.TimeoutException problem of rabbitmq-java-client 3.5.3

[LargeSully]

rabbitmq-java-client 3.5.3    -> https://github.com/rabbitmq/rabbitmq-java-client/issues/65

I encounter this problem with amqp-client-4.1.0.jar.

On client side, I have changed the default connection timeout and heartbeat to a big enough number.

On server side, I have changed the handshake_timeout parameter in rabbitmq.conf to 600000, big enough I think. And I event changed tcp_keepalive_time tcp_keepalive_intvl tcp_keepalive_probes parameters.

Without luck, error still occurs:

Caused by: java.util.concurrent.TimeoutException

at com.rabbitmq.utility.BlockingCell.get(BlockingCell.java:77) ~[amqp-client-4.1.0.jar:4.1.0]

Do I miss some parameters or configurations? Any help and advice will be appreciated.

[Michael Klishin]

Would you mind posting the entire stack trace, a snippet of code where this happens and server logs?

It's not possible to give an informed answer with the amount of information provided. Please help others help you.

Timeouts in general cannot be avoided but it's very important to know what operation exactly times out.

"handshake_timeout" only matters for newly opened connections.

Heartbeats are only somewhat related to client side timeouts and a detected heartbeat will trigger a

connection shutdown sequence: http://www.rabbitmq.com/api-guide.html.

In fact, client operation timeout is usually lower than the heartbeat one, meaning the latter won't have

a chance to kick in

--
You received this message because you are subscribed to the Google Groups "rabbitmq-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

MK

Staff Software Engineer, Pivotal/RabbitMQ

[LargeSully]

When I used rabbitmq-java-client of version lower than 3.5.3, than the timeout error would not happen, but if I use the one of version >=3.5.3 than the timeout error would happen for most times.

Here is my error message on client side and server logs:

Client side error:

com.qingyunkj.kand.biz.mq.MQException: failed to get mq connection!!

at com.qingyunkj.kand.biz.mq.MQConnection.getConnection(MQConnection.java:28)

at com.qingyunkj.kand.biz.mq.MQConnection.createChannel(MQConnection.java:40)

at com.qingyunkj.kand.biz.service.EcAddProductService.updateAllProductStatisticsBuyAddressStatus(EcAddProductService.java:1710)

at com.qingyunkj.kand.biz.taskjob.action.EcTaskAction$EcTaskActionImpl.updateAllProductStatisticsBuyAddressStatus(EcTaskAction.java:923)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:498)

at jazmin.core.thread.ThreadWorker.run(ThreadWorker.java:83)

at jazmin.core.thread.Dispatcher.invokeInCaller(Dispatcher.java:282)

at jazmin.core.thread.DispatcherInvocationHandler.invoke(DispatcherInvocationHandler.java:22)

at com.sun.proxy.$Proxy55.updateAllProductStatisticsBuyAddressStatus(Unknown Source)

at com.kand.biz.KandSubSystem.main(KandSubSystem.java:304)

Caused by: java.util.concurrent.TimeoutException

at com.rabbitmq.utility.BlockingCell.get(BlockingCell.java:77)

at com.rabbitmq.utility.BlockingCell.uninterruptibleGet(BlockingCell.java:120)

at com.rabbitmq.utility.BlockingValueOrException.uninterruptibleGetValue(BlockingValueOrException.java:36)

at com.rabbitmq.client.impl.AMQChannel$BlockingRpcContinuation.getReply(AMQChannel.java:398)

at com.rabbitmq.client.impl.AMQConnection.start(AMQConnection.java:304)

at com.rabbitmq.client.impl.recovery.RecoveryAwareAMQConnectionFactory.newConnection(RecoveryAwareAMQConnectionFactory.java:62)

at com.rabbitmq.client.impl.recovery.AutorecoveringConnection.init(AutorecoveringConnection.java:99)

at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:911)

at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:870)

at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:828)

at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:966)

at com.qingyunkj.kand.biz.mq.MQConnection.getConnection(MQConnection.java:25)

... 12 more

server side error log:

=WARNING REPORT==== 7-Jun-2017::16:38:32 ===

closing AMQP connection <0.514.0> (192.168.1.43:2562 -> 192.168.1.20:5672):

client unexpectedly closed TCP connection

On Tuesday, June 6, 2017 at 7:26:52 PM UTC+8, Michael Klishin wrote:

Would you mind posting the entire stack trace, a snippet of code where this happens and server logs?

It's not possible to give an informed answer with the amount of information provided. Please help others help you.

Timeouts in general cannot be avoided but it's very important to know what operation exactly times out.

"handshake_timeout" only matters for newly opened connections.

Heartbeats are only somewhat related to client side timeouts and a detected heartbeat will trigger a

connection shutdown sequence: http://www.rabbitmq.com/api-guide.html.

In fact, client operation timeout is usually lower than the heartbeat one, meaning the latter won't have

a chance to kick in

On Tue, Jun 6, 2017 at 6:30 AM, LargeSully <huge...@gmail.com> wrote:

rabbitmq-java-client 3.5.3    -> https://github.com/rabbitmq/rabbitmq-java-client/issues/65

I encounter this problem with amqp-client-4.1.0.jar.

On client side, I have changed the default connection timeout and heartbeat to a big enough number.

On server side, I have changed the handshake_timeout parameter in rabbitmq.conf to 600000, big enough I think. And I event changed tcp_keepalive_time tcp_keepalive_intvl tcp_keepalive_probes parameters.

Without luck, error still occurs:

Caused by: java.util.concurrent.TimeoutException

at com.rabbitmq.utility.BlockingCell.get(BlockingCell.java:77) ~[amqp-client-4.1.0.jar:4.1.0]

Do I miss some parameters or configurations? Any help and advice will be appreciated.

--
You received this message because you are subscribed to the Google Groups "rabbitmq-users" group.

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-user...@googlegroups.com.
To post to this group, send email to rabbitm...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

[Michael Klishin]

So it's ConnectionFactory#newConnection that runs into it.

As far as the server is concerned the client connects and then closes TCP

connection without closing AMQP 0-9-1 connection.

What ConnectionFactory settings are used in your code?

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

[LargeSully]

Here is my settings, just basic settings, works well in rabbitmq-java-client 3.5.2:

ConnectionFactory factory = new ConnectionFactory();

factory.setHost(HOST);

factory.setPort(5672);

factory.setAutomaticRecoveryEnabled(true);

factory.setTopologyRecoveryEnabled( true );

connection = factory.newConnection();

((Recoverable) connection).addRecoveryListener( recoveryListener );

[Michael Klishin]

We are only aware of https://github.com/rabbitmq/rabbitmq-java-client/issues/262 (https://github.com/rabbitmq/rabbitmq-java-client/pull/270),

which requires multiple hosts to be set. However, if the value of HOST is a domain name (which we don't know),

it could be resolved to more than one address (and this is a new behavior in 4.x, see https://github.com/rabbitmq/rabbitmq-java-client/issues/283).

You can try a 4.0.3 RC from our Bintray milestones Maven repo and also switch to a different resolver:

https://groups.google.com/forum/#!searchin/rabbitmq-users/Java$20client$204.0.3%7Csort:relevance/rabbitmq-users/sqElB3ssRnM/yoL9vzivAwAJ

On Wed, Jun 7, 2017 at 4:09 AM, LargeSully <huge...@gmail.com> wrote:

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

[LargeSully]

Neither 4.0.3 RC nor 4.1.1.RC3 can deal with this connection problem. The HOST here is actually an ip address. By the way, we have tried python client, which doesn't have the connection error. I guess the poor performance of the NIC on the rabbitmq server, which we use for testing server,  affected the newer java client much more!

[Michael Klishin]

According to the server log the client closes TCP connection. I don't know if that's

what you mean by "poor NIC performance" but I'd investigate two more things:

 * How much time passes between the log entries about an accepted connection and the entry that says a client "unexpectedly closed TCP connection"

 * If there are any proxy or load balancers involved, what connection inactivity can they be using, or other settings

 * Disable automatic connection recovery, register a new shutdown listener and your connection and see the reason. If it's an I/O error then very likely

   something between the client and RabbitMQ causes TCP connection to be closed.

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

[Michael Klishin]

And, of course, my favourite recommendation on this list: take a traffic capture with tcpdump/Wireshark

and you will have a lot more information to work with:

https://www.rabbitmq.com/amqp-wireshark.html.

[LargeSully]

Problem has been solved! Thank you for your advice. 

I have found that client didn't send back any packet after server send a packet named 'Connection.Start' to it. Then I changed the handshake timeout, which is 10 seconds by default, to one minute, and everything works fine. 

I have checked that the DEFAULT_HANDSHAKE_TIMEOUT in rabbitmq-java-client of version lower than 3.5.3 is also 10 seconds, I guess that the handshaking failed in rabbitmq-java-client 4.1.0 within 10 seconds, and I don't know why.

[Michael Klishin]

AMQP 0-9-1 handshake takes a few round-trips but it shouldn't typically take

more than a second.

Are you connecting to a node on a different continent? :)

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

[Michael Klishin]

I wonder if it's a side effect of DNS resolution (which can time out)

in the resolver we use by default in 4.x.

Such issues are definitely not unheard of, in particular in developer environments

that use VPNs (that alter DNS server list without the user realising it).

[LargeSully]

The rabbitmq server node is in LAN. I have tried python client and nodejs client, and both works well, they may tolerate longer handshake time.I think the poor performance of the networking card leads to the timeout of handshake of java client.

[LargeSully]

I have tried use ip address directly, and the timeout of handshake still occur.

[Michael Klishin]

I honestly think that you are focussing too much on the handshake timeout. It might be a red herring.

Handshake over LAN should not take more than 10 seconds unless you intentionally increase

latency in your environment e.g. by using a traffic shaper.

Can you change the resolver [in the Java client, not OS] and see if that makes a difference?

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

[Michael Klishin]

OK, perhaps I need to slow down.

Java client 4.x has a new feature that controls how addresses are resolved to IP addresses:

https://github.com/rabbitmq/rabbitmq-java-client/blob/master/src/main/java/com/rabbitmq/client/AddressResolver.java

This implementation is what 3.6.x uses IIRC:

https://github.com/rabbitmq/rabbitmq-java-client/blob/master/src/main/java/com/rabbitmq/client/ListAddressResolver.java

This is what 4.x uses by default:

https://github.com/rabbitmq/rabbitmq-java-client/blob/master/src/main/java/com/rabbitmq/client/DnsRecordIpAddressResolver.java

the latter can run into DNS-based hostname resolution timeouts, depending on the setup.

It also can resolve two or more (including both IPv4 and IPv6 addresses) from an input.

So some connections time out, then 2nd, 3rd, and so on succeeds.

A traffic capture (with tcpdump or Wireshark directly) should provide enough information to confirms this.

You can move on from this, of course, but it is not typical for an AMQP 0-9-1 handshake to take more than 10 seconds

even when TLS is enabled.

To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-users+unsubscribe@googlegroups.com.
To post to this group, send email to rabbitmq-users@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.