分享

JBOSS内容错乱的分析过程

 hh3755 2012-11-17

现象: 
    在线服务的应用在发布一个应用后突然出现用户账号串号现象,这个问题的严重性完全是重大事故级。 
对于商业网站简直是致命的,线上在出现问题的时马上进行了回滚。对出现问题的用户进行手工修正数据等善后工作。 
分析: 
    因为之前基本没有这个情况(说基本没有,是据说一年前出现过这样的一次情况,因为只出现过一次而且是一年前的,当时怀疑有可能是网络接入层的数据缓存)。就因为一个应用发布突然出现大量(对于商业网站,如果出现十几个,几十个用户账号错误,应该算是大量了),所以首先从新发布的应用查起。 
    有一个线索就是当出现串号时,有些页面的内容和状态码都发生错误,本来应该是302的却变成了200还有的页面内容明显不对,本来只有true和false输出,但却输出一段HTML。 
    虽然不相信公司的程序员会将Session变量定义在请求处理之外,但还是小心地扫描一遍,排除。 
    我们的应用中因为分布式应用的Session Store是自己实现的,所以对Request,Response,Session,Context都进行了拦截包装,如果某些罗辑导致没有提交Response,可能会造成脏数据。但是对所有代码进行逐行分析,没有发现这样的问题。 
    一个Servlet中只有一行代码:Response.sendReDirect("/path");这是为了将原来多个不同的URL转向同一请求的,理论上这个URL肯定返回302, 但却在发生串号时返回200.所以怀疑是否是在filter中某种条件下chain没有调用,直接返回了,请求没有到达servlet.结果对所有filter分析后没有这种情况。 
    有些束手无策了,搜索引擎能搜索到的内容的参考率为零。 
    从对业务层的怀疑转移到了容器环境。 
    一开始没有怀疑容器环境是因为之前没有出现这个问题,就是因为一个应用的发布而出现的,现在应用本身的业务代码基本排除问题,所以想象是否是容器环境以前存在问题,但因为条件没有达到而没有触发,这次应用发布后因为一个活动使访问量增加好几倍,是否是因为压力上升而导致原来隐藏的问题触发出来了? 
    公司其它的应用的容器环境已经成熟稳定多年,所以主要看这个应用的容器环境和其它应用环境的区别。 
    发现大多数应用都是apache2.0.3+jboss4.0.5+mod_jk1.2.28而这个应用是apache2.0.3+jboss4.2.3+mod_jk1.2.26. jk版本本来就是从1.2.26升级上去的,升级之前也没有发生过这种情况,所以先查jboss4.2.3。 
    搜索jboss4.2.3的BUG列表,终于发现一个靠普的问题。 
    jboss4.2.3使用的是jbossweb2.0.1,对于GA版本,2.0.x都存在一个BUG,会造成数据错乱: 
    org.apache.catalina.connector.Request.java中的parseParameters方法中,最后几行:

        byte[] formData = null; 
            if (len < CACHED_POST_LEN) { 
                if (postData == null) 
                    postData = new byte[CACHED_POST_LEN]; 
                formData = postData; 
            } else { 
                formData = new byte[len]; 
            } 
        try { 
                if (readPostBody(formData, len) != len) { 
                    return; 
                } 
            } catch (IOException e) { 
                // Client disconnect 
                if (context.getLogger().isDebugEnabled()) { 
                    context.getLogger().debug( 
                            sm.getString("coyoteRequest.parseParameters"), e); 
                } 
            } 
            parameters.processParameters(formData, 0, len);

    在Servlet引擎处理实际的客户端请求时,并不是每次请求生成一个Request对象,而是一个线程池绑定一个Request对象,在处理一个请求后进行清理然后重用。但是postData并没有清理。 
    如果客户端是一个POST请求,在从apache通过jk向jboss传送时,jk先告诉jboss本次传输的body长度是x, 而jboss在readPostBody时没有读到相应的长度,可能发生超时,虽然异常被捕获了,但却没有return,继续运行到了下面的 
    parameters.processParameters(formData, 0, len); 
    就会发生使用上一次请求的post的内容或部分上一次内容来进行processParameters.这必然会生产数据错乱。 
    为了重现这个问题,我在修改了mod_jk1.2.26的源码的common/jk_ajp_common.c中 ajp_send_request函数:

    postlen = op->post->len; 
    if (postlen > AJP_HEADER_LEN) { 
        …………….. 
    } 
    else if (s->reco_status == RECO_FILLED) { 
        …………….. 
    } 
    else{ 
        if(rand() % 3 == 0){ 
            jk_log(l, JK_LOG_ERROR,"it will sleep………………….."); 
            sleep(120); 
            jk_log(l, JK_LOG_ERROR,"end sleep………………………"); 
        } 
        ……………………. 
    }

    在进入post数据发送的时候sleep了120秒。这个时间要大于jk配置文件中connection_pool_timeout,而不是socket_timeout.connection_pool_timeout这个值和jboss中的Connector中connectionTimeOut是对应的。一般会设置很长。我们的应用设置成600s,为了调试超时我把它们改成60s,所以sleep(120)就肯定发生超时了。 
    然后用客户端程序进行测试,写一个HttpURLConnection,然后我在post参数中放入了一个mark=xxxxxxxxxx的随机串,一个jsp文件获取mark参数后打印出来。我从客户端再读这个值,应该和我传过去的是一样的。 
    因为有1/3的超时机会,所以我只用10次循环来运行这个客户端测试情况,果然在发生超时的时候,传回来的mark不是当前请求传过去的mar,而是上一次的mark. 完全验证了这个情况。 
    那么要发生串号的情况,就可以解释了。 
    1.是post请求。 
    2.servlet要处理Request,也就是要从中get内容,为了性能原因,客户端内容被tcp层接收(apache)后先缓存起来。如果servlet本身没有涉及对Request.getXXX的处理,Jboss就不会通过jk向apache请求这部分数据,apache直接把它抛弃。不会触发这个BUG。在调试的时候我就上过这个当,在把jsp改成servlet测试时,没有获取参数,结果没有触发,还想了好久才发现这个问题。 
    3.虽然发生异常后本次请求使用了上次的请求的部分数据或全部数据,从逻辑上说参数本身是错误的,但并不一定输出的结果也是错误的,有些内容不是根据请求参数输出的。 
    4.只有前一次请求数据中本身包含其它账号的信息,以此作为条件获取的输出结果中又包含账号信息返回给当前用户时才会看到串号现象。所以即使产生很多readPostBody异常也不一定产生串号结果,但串号结果是这样产生的。

解决:

      这个简单了,如果你觉得升级或降级其它版本都有风险,直接在上面的catch的最后加上return.然后编译替换原来的jar就行了。

    附注:这个BUG在jboss4.0.5中没有产生,4.0.5中使用的tomcat5.5, parameters.processParameters(formData, 0, len);方法中try块中调用的,而且加了readLen == contentLen的测试。而jbossweb2.10开始也修复了这个bug. 
    另外其它版本还有一个可能会产生数据错乱,就是jk和jboss之间的连接池,默认的实现中如果发生异常,连结会被关闭,但如果在connector中有对Connector进行拦截的handler中自己吃掉了这个异常,则异常不能被AjpConnectionHandler获取,则连接不能被关闭而放回连接池中,对于非阻塞IO的,这个SocketChannel中的残留数据就会被一次读取,这样的结果是不能接受的,所以如果要对输入输出流进行拦截处理不要捕获它们的异常,或者捕获处理后要立即抛出去。

   对于这个readPostBody异常,大多数是超时引起的,在jk配置中connection_pool_size不要设置太小,理论上不能低于apache处理请求的连接数,因为一个客户端请求数据在apache接收到以后可能被分多块通过jk发给jboss,另外connection_pool_timeout设置一定要与jboss的connectionTimeout匹配,否则一方超时断开另一方还在读或写肯定发生IO异常了。

    本站是提供个人知识管理的网络存储空间,所有内容均由用户发布,不代表本站观点。请注意甄别内容中的联系方式、诱导购买等信息,谨防诈骗。如发现有害或侵权内容,请点击一键举报。
    转藏 分享 献花(0

    0条评论

    发表

    请遵守用户 评论公约

    类似文章 更多