XFJ 2013-10-14

1.描述

.日期:2013-10-12
.服务器:XFJ

.问题现象：

单据SCM1201310120001在发送方单据表中状态为100(表示已送达),发送方tb_0031对应的记录已被自动清理(在传输层已确认才会被清理).

然而,XFJ端确认没有接收到.

2.分析

取当天XFJ端的日志分析.
按"SCM1201310120001"搜索,没有查到内容.

基于前次经验,按"回路"搜索是否有丢弃的消息。发现多处下列内容：

[2013-10-12 02:00:18:554][线程3412][1][20][0][]CBBoxPlugin::HandleInput_i 处理消息8:808(source:3 0,dest:1 10068)...[2013-10-12 02:00:18:554][线程3412][5][20][0][]CAPBase::GetOrg orgid=10068,ret=-30988,错误:DB_NOTFOUND: No matching key/data pair found.[2013-10-12 02:00:18:554][线程3412][5][20][0][]CAPBase::GetOrg orgid=10068,ret=-30988,错误:DB_NOTFOUND: No matching key/data pair found.[2013-10-12 02:00:18:554][线程3412][5][20][0][]CBBoxPlugin::HandleInput_i 消息8:808(source:3 0,dest:1 10068)传输出现回路,丢弃此消息.

XFJ是专用服务器,如何有源为平台(3,0),目标为(1,10068)的消息呢？(10068是JJY)
平台把本该发送给JJY的消息发送到了XFJ!

想到了之前对HTX_Network::SendMsg函数的一个疑虑。代码如下:

intHTX_Network::SendMsg(HTX_SOCKET handle,CMsg *msg,int do_close,unsigned long cb_arg) {    DEBUG_LOG(HTX_LOGGER::instance(),(LO_STDOUT|LO_FILE,SEVERITY_DEBUG,"HTX_Network::SendMsg handle=%d,do_close=%d,cb_arg=%d...\n",handle,do_close,cb_arg));    HTX_Sock_Handler *handler = 0;    do {        ACE_READ_GUARD_RETURN(ACE_Thread_Mutex,m,HTX_Sock_Handler::handle_map_.mutex(),-1);        HTX_Sock_Handler::handle_map_.find(handle,handler);        if (handler==0) {            DEBUG_LOG(HTX_LOGGER::instance(),(LO_STDOUT|LO_FILE,SEVERITY_DEBUG,"HTX_Network::SendMsg失败,对应handle=%d的连接器已关闭.\n",handle));            msg->Release();            return -1;        }    }while(0);  ///< 根据不同的协议准备发送的的消息字节流,此过程可能比较耗时    ACE_Message_Block *mb = handler->prepare_send_message(msg);    msg->Release();    if (mb==0) {        DEBUG_LOG(HTX_LOGGER::instance(),(LO_STDOUT|LO_FILE,SEVERITY_ERROR,"HTX_Network::SendMsg prepare_send_message失败.\n"));        return -1;    }    ///< prepare_send_message比较耗时,为了减少handle_map_锁占用时间,prepare_send_message不在锁范围内执行.    ///< 这可能导致在prepare_send_message之后,handler_已经被关闭.    ///< 这是由于支持多协议造成的,否则可以先执行prepare_send_message.    handler->set_cb_arg(cb_arg);    ////< 如果阻塞在write_queue_.enqueue_tail,则由于占有handle_map_锁,导致在SockHandler::open时handle_map_.bind阻塞导致Proactor僵死---->通信功能僵死    int ret = handler->start_write(mb);      if (ret==-1||do_close) {        DEBUG_LOG(HTX_LOGGER::instance(),(LO_STDOUT|LO_FILE,SEVERITY_ERROR,"HTX_Network::SendMsg start_write失败,handle=%d,ret=%d,do_close=%d.\n",handle,ret,do_close));        handler->initiate_close();    }    DEBUG_LOG(HTX_LOGGER::instance(),(LO_STDOUT|LO_FILE,SEVERITY_DEBUG,"HTX_Network::SendMsg end.\n"));    return 0;}

其中的注释:

    ///< 这可能导致在prepare_send_message之后,handler_已经被关闭.    ///< 这是由于支持多协议造成的,否则可以先执行prepare_send_message.

考虑了偶发性情况.
但是,忽略了"这个连接器被其它服务器使用会怎样".

这是在支持多通信协议(支持mtp)后引入的问题.

出现此问题的一个场景是：

某个连接器先是被JJY使用,当执行到prepare_send_message准备发送消息时，由于某种原因导致网络连接断开后,该连接器被关闭并回收.

紧跟着XFJ服务器注册上来分配到了这个缓存的连接器.执行handler->start_write(mb).
这就造成了上述情况.

传输的定位键是mq_id,mq_db_id,object_id,其中,对于本地服务器是单实例,单存储的.差别就是object_id了.

在第一次传输失败后,在执行809询问时,消息在上述情况下被发送到了非预期的服务器上的SEMQ,则根据定位键消息接收方会得到肯定的回复。

这就有可能出现故障所描述的问题。

3.处理

代码更正如下,在handler->start_write(mb)前再次根据通道ID获取处理器(通道ID是不会重复的,即使两次连接使用同一个连接器).

    do {        ACE_READ_GUARD_RETURN(ACE_Thread_Mutex,m,HTX_Sock_Handler::handle_map_.mutex(),-1);        HTX_Sock_Handler::handle_map_.find(handle,handler);        if (handler==0) {            mb->release();            return -1;        }        handler->set_cb_arg(cb_arg);        int ret = handler->start_write(mb);          if (ret==-1||do_close) {            handler->initiate_close();        }    }while(0);

为避免通信因死锁而僵死,write_queue_需要足够大,默认没有限制.

    write_queue_.high_water_mark(HOTFOX::instance()->server_info_.conn_buffer_size_);    write_queue_.low_water_mark(HOTFOX::instance()->server_info_.conn_buffer_size_);