[QPID-8071] Java Qpid library does not report that session was closed

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Won't Fix
• Affects Version/s: qpid-java-6.1.5
• Component/s: JMS AMQP 0-x

Environment

slow network towards Qpid broker
for instance set this to the machine that is making connection towards qpid broker
sudo tc qdisc add dev enp0s8 root handle 1: tbf rate 16kbit latency 25ms burst 2k
reset the throttle with this
sudo tc qdisc del dev enp0s8 root

add those flags to shorten qpid.io_network_transport_timeout from 1min to 5 seconds
-Dqpid.sync_op_timeout=509000 -Dqpid.io_network_transport_timeout=5000

try to send 512kB long message. If qpid.io_network_transport_timeout is raised to 3 minutes it should take about 300 seconds to send the message (with 16kbit link) (the default 60s threshold is exceeded).

• Assignee: Unassigned
• Reporter: Alojzij Blatnik
• Created: 09/Jan/18 13:48
• Updated: 16/Jan/18 15:53
• Resolved: 16/Jan/18 15:53

Description

when qpid.io_network_transport_timeout is exceeded, qpid-java library does not throw exception, but the exception is just logged, hence the code, that is calling qpid-java library doesn't know that qpid message wasn't sent until it becomes obvious that connection is closed.

monkey patch:
{{diff --git a/common/src/main/java/org/apache/qpid/transport/Session.java b/common/src/main/java/org/apache/qpid/transport/Session.java
index 9568873..b1afd8d 100644
— a/common/src/main/java/org/apache/qpid/transport/Session.java
+++ b/common/src/main/java/org/apache/qpid/transport/Session.java
@@ -759,16 +759,7 @@ public class Session extends SessionInvoker
}
catch (SenderException e)
{

• if (!closing)
• { - // if we are not closing then this will happen - // again on resume - LOGGER.error("error sending command", e); - }
• else
• { - e.rethrow(); - }

  + e.rethrow();
  }
  if (autoSync)

  Unknown macro: {}}

Some logs:
{{
12585 [main] ERROR org.apache.qpid.transport.network.io.IoSender - write timed out for socket /172.21.0.2:50618-qpid-broker/192.168.80.1:5671: head -2147216975, tail -2147348047
12586 [main] ERROR org.apache.qpid.transport.Session - error sending command
org.apache.qpid.transport.SenderException: write timed out for socket /172.21.0.2:50618-qpid-broker/192.168.80.1:5671: head -2147216975, tail -2147348047
at org.apache.qpid.transport.network.io.IoSender.send(IoSender.java:172)
at org.apache.qpid.transport.network.security.ssl.SSLSender.doSend(SSLSender.java:215)
at org.apache.qpid.transport.network.security.ssl.SSLSender.flush(SSLSender.java:149)
at org.apache.qpid.transport.network.Disassembler.flush(Disassembler.java:88)
at org.apache.qpid.transport.Connection.flush(Connection.java:428)
at org.apache.qpid.transport.Session.send(Session.java:592)
at org.apache.qpid.transport.Session.invoke(Session.java:758)
at org.apache.qpid.transport.Session.invoke(Session.java:613)
at org.apache.qpid.transport.SessionInvoker.messageTransfer(SessionInvoker.java:93)
at org.apache.qpid.client.BasicMessageProducer_0_10.sendMessage(BasicMessageProducer_0_10.java:371)
at org.apache.qpid.client.BasicMessageProducer.sendImpl(BasicMessageProducer.java:549)
at org.apache.qpid.client.BasicMessageProducer.send(BasicMessageProducer.java:333)
at tld.domain.OurLibrary$SendLogic.sendLogic(OurLibrary.java:430)
at tld.domain.OurLibrary$SendLogic.run(OurLibrary.java:391)
at tld.domain.OurLibrary.reconnectCommonLogic(OurLibrary.java:497)
at tld.domain.OurLibrary.reconnectLogic(OurLibrary.java:483)
at tld.domain.OurLibrary.send(OurLibrary.java:373)
at tld.domain.Main.send(Main.java:476)
at tld.domain.MainAttict.tesSendMsg(MainAttict.java:285)
at tld.domain.MainAttict.main(MainAttict.java:368)
12589 [main] INFO tld.domain.MainAttict - message sent
12590 [IoRcvr-/172.21.0.2:50618-qpid-broker/192.168.80.1:5671] ERROR org.apache.qpid.client.AMQConnectionDelegate_0_10 - connection exception: conn:70d0de44
org.apache.qpid.transport.ConnectionException: connection aborted
at org.apache.qpid.transport.Connection.closed(Connection.java:574)
at org.apache.qpid.transport.network.Assembler.closed(Assembler.java:115)
at org.apache.qpid.transport.network.InputHandler.closed(InputHandler.java:221)
at org.apache.qpid.transport.network.security.ssl.SSLReceiver.closed(SSLReceiver.java:69)
at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:225)
at java.lang.Thread.run(Thread.java:745)
12590 [main] INFO tld.domain.OurLibrary - lock for qpid connection status is not defined, hence it won't be created. Status: connection lost
}}