通过HornetQ实现的JMS偶现调用延时的情况，求高手解答！！

lovezhang123 2017-04-24 11:14:38

【背景介绍】
在我们的系统中，需要实现跨进程的消息通信能力，我们使用的JMS协议，底层通过HornetQ+Netty实现，HornetQ的版本为2.2.21.Final，Netty版本为3.9.4.Final。

部署的操作系统为Linux Suse11 SP3，采用KVM+OpenStack虚拟机，环境上存在一个固定IP10.xx.xx.55及一个浮动IP 10.xx.xx.85

部署形态如下：ProcessA中包含JMS Server和一个JMS Client A，两者部署在同一个进程中，ProcessB中包含另一个JMS Client B，两个进程部署在同一个机器上。Client A、Client B和JMS Server之间通过nio的NettyConnector进行连接。

【问题描述】
Client A和Client B通过JMS Server互相发送/接收消息，现已确认在Client A向JMS Server发消息（标红那条）时存在延时，但很奇怪，从JMS Server向Client A发送消息就没有问题。该问题并不是必现的，有时候会发生的比较频繁，有时候很久才出现，完全没有规律

调用关系有两种：
1）Client A作为请求发起方，通过JMS Server向Client B发起请求，Client B通过TemporaryQueue经过JMS Server向Client A回复响应。在Client A向JMS Server发出消息后，为了接收Client B的响应，此时需要创建一个Consumer，Client A会向JMS Server阻塞式的发出一条SESS_CREATECONSUMER的消息，该消息发出后会等待JMS Server端的一个确认消息，超时时间为30秒，所以该场景下，经常会出现如下异常：

Caused by:javax.jms.JMSException:Timed out waiting for response when sending packet 49

at org.hornetq.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:302)

at org.hornetq.core.client.impl.ClientSessionImpl.bindingQuery(ClientSessionImpl.java:399)

at org.hornetq.core.client.impl.DelegatingSession.bindingQuery(DelegatingSession.java:130)

at org.hornetq.jms.client.HornetQSession.createConsumer(HornnetQSession.java:530)

at org.hornetq.jms.client.HornetQSession.createConsumer(HornetQSession.java:383)

at org.hornetq.jms.client.HornetQSession.createConsumer(HornetQSession.java:358)

2）Client B作为请求的发起方，通过JMS Server向Client A发起请求，Client A通过TemporaryQueue经过JMS Server向Client B回复响应。在这个流程中，请求的发送是正常的，但往往收不到Client A发过来的响应导致超时，超时间为5分钟。表现为使用javax.jms.MessageConsumer.receive(long)方法在5分钟后返回null

在整个通信过程中，我们为每类请求创建了一个Queue，同一类请求的多次调用使用同一个Queue发起，使用同一个TemporaryQueue回复响应。在问题发生期间，所有的Queue从Client A向JMS Server发送消息均存在延迟。系统中也存在一些Topic，这些Topic消息也是有延迟的

【求助&怀疑点】
针对JMS Client A向JMS Server发送消息延迟的问题，一直未能找到确定的，我们在自己的环境上尝试加大请求调用的频率及响应的数据大小，问题均未能复现。
后面我们通过对比问题发生时的TCP报文及正常时的TCP报文，发现了一些异常，可能和该问题有关系：
如下是问题发生时的TCP报文，10.XX.XX.85代表JMS Server，使用的是32xx2端口，10.XX.XX.55代表JMS Client A，使用的是52xx3端口（随机端口）。从报文中可以看出：
1.JMS Server端滑动窗口大小为16389（环境使用lo回路，MTU为16436，16436=16389+7+40）
2.Client A向JMS Server下发了一个长度为16396的报文，但由于对方滑动窗口的限制被拆分为16389和7两个报文。但从时间上看，每两个16396报文之间间隔200MS左右。

在没有问题的报文中，10.XX.XX.85代表JMS Server，使用的是32XX2端口，10.XX.XX.55代表JMS Client A，使用的是42XX2端口（随机端口）。从报文中可以看出：
1.JMS Server的滑动窗口大小为16396，刚好同问题发生时报文未拆解大小一致（16389+7）
2.整个报文中长度大于10000的报文非常少，而在问题的报文中，非常多的16389报文
3.报文中没有出现两条报文间隔200MS的情况