日期:2014-05-16 浏览次数:21288 次
以前项目中遇到的一个很诡异的问题,记录下来分享一下。
?
一个很老的项目的生产环境是采用Apache httpd + Tomcat?,使用mod_jk2的插件进行整合,其实这个插件早已停止更新了,反而是mod_jk(1.x)插件的生命周期还在维持。
?
具体问题的现象是,项目中有一些耗时较多的处理页面,例如一个创建新项目的业务画面,前台页面submit之后,后台要处理一系列的文件,还要登录数据库等,其实在设计阶段已经考虑到了重复提交的问题,所以画面上做了控制(提交之后画面按钮禁用,直到后台操作完成)。开发测试阶段没有出现过问题,然而到了客户的生产环境,在运行了一段时间之后,出现了几次数据重复提交的问题,客户提交给我们解决。
?
搭设测试环境后,尝试后发现提交按钮按下后,如果关闭浏览器或者通过地址栏输入其他URL并跳转后就会发生服务器端重复提交。经过反复的调查,首先确定了浏览器端没有任何问题,提交的请求只有一次;但是Tomcat中部署的服务程序确实在个别情况下接收到两次请求,与程序代码也没有关系;最后把注意力集中到了Apache的httpd上面。
?
先是怀疑httpd存在问题,但是google之后没有发现有类似的反馈,考虑到如果真的有问题应该会有很多用户发现的,所以最后怀疑到了mod_jk2上面,更换成了mod_jk(1.x)插件之后就没有问题了。
?
照理说事情到此就可以解决了,但是不幸的是项目的客户非常较真,认为更换mod_jk插件的话整个系统就需要重新测试才能上线,所以不同意,要求调查清楚原先为什么有问题,被逼无奈只好去查mod_jk2的源代码。
mod_jk2的代码可以从这里下载:http://archive.apache.org/dist/tomcat/tomcat-connectors/jk2/source/jakarta-tomcat-connectors-jk2-2.0.4-src.zip
?
因为对C不是很熟悉,所以从httpd的log入手,在出现重复提交问题的时候,log中能查到一条对应的记录:“ajp13.service() ajpGetReply recoverable error 3”,在代码中搜索可以找到是jk_worker_ajp13.c的line547输出的,分析其所在的函数jk2_worker_ajp13_forwardStream之后,发现问题的大致原理是:服务端处理完请求之后,发回响应消息,但是因为浏览器端已经被关闭或者迁移到其他页面,所以试图发回响应时会得到失败的消息,但是mod_jk2插件会试图恢复这一错误(但是这种情况显然无法恢复了),试图恢复的方式是再次向Tomcat发送一开始的请求,这就构成了第二次提交,而在浏览器和Tomcat服务器来看确实是没有任何问题的。(这个仅仅是个人的理解,因为对这方面不是很了解,所以可能理解的不对,不过对于解决问题影响不大)
?
出问题的函数代码片段如下,可以看到一开始定义了JK_RETRIES变量值为2,如果把这个值改为1就不会出现上面的问题了,但是显然客户是不会接受这一方案的,于是继续调查其他解决方法。
?
/** There is no point of trying multiple times - each channel may have built-in recovery mechanisms */ #define JK_RETRIES 2 static int JK_METHOD jk2_worker_ajp13_forwardStream(jk_env_t *env, jk_worker_t *worker, jk_ws_service_t *s, jk_endpoint_t *e) { int err = JK_OK; int attempt; int has_post_body = JK_FALSE; e->recoverable = JK_TRUE; s->is_recoverable_error = JK_TRUE; /* * Try to send the request on a valid endpoint. If one endpoint * fails, close the channel and try again ( maybe tomcat was restarted ) * * XXX JK_RETRIES could be replaced by the number of workers in * a load-balancing configuration */ for (attempt = 0; attempt < JK_RETRIES; attempt++) { if (e->sd == -1) { err = jk2_worker_ajp13_connect(env, e); if (err != JK_OK) { env->l->jkLog(env, env->l, JK_LOG_ERROR, "ajp13.service() failed to connect endpoint errno=%d %s\n", errno, strerror(errno)); e->worker->in_error_state = JK_TRUE; return err; } if (worker->mbean->debug > 0) env->l->jkLog(env, env->l, JK_LOG_DEBUG, "ajp13.service() connecting to endpoint \n"); } err = e->worker->channel->send(env, e->worker->channel, e, e->request); if (e->worker->mbean->debug > 10) e->request->dump(env, e->request, "Sent"); if (err != JK_OK) { /* Can't send - bad endpoint, try again */ env->l->jkLog(env, env->l, JK_LOG_ERROR, "ajp13.service() error sending, reconnect %s %d %d %s\n", e->worker->channelName, err, errno, strerror(errno)); jk2_close_endpoint(env, e); continue; } /* We should have a channel now, send the post data */ /* Prepare to send some post data ( ajp13 proto ). We do that after the request was sent ( we're receiving data from client, can be slow, no need to delay - we can do that in paralel. ( not very sure this is very usefull, and it brakes the protocol ) ! */ /* || s->is_chunked - this can't be done here. The