对于JMS分发服务超时的问题,在前面经过多次诊断,后续也对OSB Server,JMS Server进行了Domain主域的拆分,但是对于JMS分发服务仍然存在超时的情况。
对于JMS分发服务超时,在前面我们已经进行过详细的分析,即主要还是在我们超JMS Topic主题里面写消息的时候出现了超时,而这个超时具体跟踪错误日志,包括我们自己写程序验证,主要还是发生在从Jini Factory连接工厂中获取连接和创建Session的时候花费很长的时间,而实际SendMessage过程很快。
一开始我们始终分析的重点都放在对于目标系统对JMS消息主体的订阅,由于启用了XA模式,在这种模式下的订阅由于目标系统事务处理耗时很长导致了大量的问题。而实际上目标系统接收到订阅消息后也只是做了最简单的写库操作而没有做任何额外逻辑处理。
在假设目标系统订阅JMS消息对JMS分发造成影响,初步的逻辑思考是对于目标系统对JMS消息订阅和JMS消息的分发和发送是使用了同一个JMS Factory连接工厂。由于JMS订阅出现异常或问题,可能导致有出错或脏连接进入到JMS Pool连接池,而在分发服务的时候取到这些连接导致出现异常。
基于这个假设,我们将目标系统的订阅和JMS消息分发分开为独立的两个不同的JMS Factory再进行验证。但是今天仍然发现在进行JMS消息分发测试的时候出现超时的情况,对于目标系统侧也出现了超时EJB订阅超时引起的回滚异常。
在目标系统修改了Factory后,我们JMS Server没有进行重启,是否和这个有关系?其次目标系统侧配置了域名地址,是否需要在Host里面增加了IP和域名信息的映射,中午对这两点进行修改后重新部署。准备再进行进一步的观察。如果还出现错误,那么说明前面所有的假设都不对。
而我们队JMS分发服务进行观察,仍然还是发现对于OSB Server调用Remote JMS Server的时候才会出现大量的超时情况,而如果两个Server都在同一台虚拟机上,基本所有的调用都正常。同时我们也看到并不是目标系统写库事务长耗时导致的异常,那么异常原因究竟出在哪里?
不管是JMS服务将消息写入到JMS Server还是说目标系统从JMS Server订阅消息,可以看到的还是都是典型的跨域访问问题,关键点还是回到了跨域安全上面。在最近几周,由于JMS Server的日志中没有报前面跨域安全的Securiy异常,我们的问题分析精力没有再放在跨域安全上面,而实际上所有的异常分析,最终跟踪的结果仍然还是可能是跨域安全引起的访问访问耗时长的原因。
我们来看下具体的进一步日志分析:
首先看下对于目标系统订阅端记录到的关键异常日志如下:
BEA-010026 Exception occurred during commit of transaction Name
Status=Rolled back
javax.transaction.SystemException: Timeout during commit processing
at weblogic.rjvm.ResponseImpl.unmarshalReturn(ResponseImpl.
at weblogic.rmi.internal.BasicRemoteRef.invoke(BasicRemoteRef.
基于这个日志,我们根据最关键的BEA-010026和Timeout during commit信息进行相关搜索。最类似的找到一篇文章Weblogic EJB can not commit XA transaction when use Foreign JNDI to call remote EJB,具体地址如下:
这篇文章主要还是指出是由于跨越访问导致了这种JMS消息订阅超时。具体修改方法仍然是设置Weblogic的跨域互信。具体如下:
You have three options and your should decide which one is best depending on your non-functional requirements (e.g. security etc):
对于企业跨域互信,我们原来进行设置过,但是当时由于目标系统出现环境问题,同时由于在JMS Server的log中没有再报Secutiry的异常错误,导致后面没有再去设置。而对于第三种方式提到的将域互操作性修改为性能模式,没有尝试过,这种模式下可以匿名方式访问本身可能存在安全性隐患。
而对于JMS Server服务器日志,同样我们可以跟踪到具体的超时和回滚日志,具体关键信息如下:
BEA-110412
'weblogic.kernel.Default (self-tuning)'> <<anonymous>>
.MessageDrivenEJBBean.onMessage(],Status=Rolled back
[Reason=Unknown],HeuristicErrorCode=XA_HEURMIX
这个JMS异常日志报错和目标系统的日志报错相互之间是匹配的,从这里我们也可以看到当前跨越是走的匿名访问方式进行。从这个日志看到的关键信息仍然是JMS Server对事务进行了回滚,基本的原因应该也是在事务处理超过了设置的超时时间仍然没有响应后,JMS Server对该事务进行了回滚。
对于该异常,我们实际在Support知识库中没有搜索到相当类似的问题和解决方案。
而对于OSB Server朝JMS Server中发送消息,再次将注意力转移到OSB Server的错误日志记录中,对于该日志中有相关的异常记录如下:
weblogic.jms.common.JMSException: weblogic.messaging.dispatcher.DispatcherException:
weblogic.rjvm.PeerGoneException: ; nested exception is:
java.io.EOFException.
对于这个异常日志,原来也一直在报错,在网上也有大量的问题和描述。从异常日志的内容来看,仍然是JMS 连接池中的一个连接被关闭了,原因是发生了JMS异常。即PeerGoneException和.EOFException。
根据这个异常信息,我们进一步搜索。
1. 修改超时设置,现在不合理,这个JMS分发服务基本不耗时,也不存在大数据量。
2. OSB服务器本身设置了域名,而在JMS服务器没有配置域名,不存在这个情况,两边都没有启用域名。
3. 启用隧道功能,enable tunneling设置打开,这个我们打开过,感觉没起作用,后来关闭了。从该设置本身的业务含义来看,也不是应该由该设置影响。
对于169805错误本身,官网的根源描述为:The JMS server is unavailable, or there is some other problem with it that makes it impossible to send or receive messages,但是具体什么原因引起并没有说。
https://support.oracle.com/epmos/faces/DocumentDisplay?_afrLoop=359691044990147&id=1333681.1&displayIndex=1&_afrWindowMode=0&_adf.ctrl-state=g6qqs922n_291#SYMPTOM
根据一篇文章的说明,再次出现该问题,可以考虑将JMS Server的Debug全部打开,具体如下:
-Dweblogic.log.StdoutSeverity=Debug
-Dweblogic.log.LogSeverity=Debug
-Dweblogic.log.LoggerSeverity=Debug
-Dweblogic.kernel.debug=true
-Dweblogic.debug.DebugMuxer=true
-Dweblogic.debug.DebugMuxerDetail=true
-Dweblogic.debug.DebugMuxerTimeout=true
-Dweblogic.debug.DebugMuxerConnection=true
-Dweblogic.debug.DebugMuxerException=true
截止到现在暂时没有找到该问题的确切原因,但是最有可能仍然是跨越信任的问题。可以尝试的是对于跨域操作模式采用性能模式,即允许匿名访问。如果再出现问题该点可以试验下。