web应用出现400响应的分析
来源：岁月联盟
时间：2012-02-17
首先看日志，检查400请求的ip的其它请求是否正常，排除伪造请求的攻击行为。发现用户的User-Agent分布正常，ip分布正常。所有400请求的响应
内容都是226字节，说明服务器返回给用户的内容是固定的。
400错误是用户请求错误，用户请求格式错误的原因基本可以分为两种，一种是因为网络通讯造成数据残缺，一种是违反了约定和数据格式或长度。
如果是自定义客户端，对协议的各种情况覆盖不完整，违反数据格式或长度的情况可能比较多，但是对于用户正常的通过浏览器访问的情况，违反
数据格式或长度的情况几率非常小。我们考虑数据超长的情况最可能的就是cookie超长，于是模拟了一个超长的cookie进行测试，浏览器虽然返回了
400响应码，但是content-length却是很大，包括了cookie的内容长度(apache的bug,现在已经升级到2.2.22解决了这个bug)。
于是怀疑是超时产生数据残缺引起的。
查看400的记录平均处理时间：
cat cookie_log|grep 'HTTP/1.1 /" 400 '|awk '{print $12}'|awk 'BEGIN{total=0;count=0} {total+=$1;count++} END{ print total/count}'
得到平均耗时为6119.350ms.
查看前十万条记录平均耗时：
head -n100000 cookie_log|grep 'HTTP/1.1 /" 400 '|awk '{print $12}'|awk 'BEGIN{total=0;count=0} {total+=$1;count++} END{ print total/count}'
得到耗时为48.325ms
说明400时平均耗时是正常的120多倍。
程序验证：
out.write("GET /testpath HTTP/1.1/r/n".getBytes());
out.flush();
Thread.sleep(30*1000); // 模拟超时
out.write(("Host: testhost/r/nUser-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:10.0) Gecko/20100101 Firefox/10.0/r/nAccept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8/r/nAccept-Language: zh-cn,en-us;q=0.7,en;q=0.3/r/nAccept-Encoding: gzip, deflate/r/nConnection: keep-alive/r/nIf-Modified-Since: Thu, 27 Oct 2011 01:16:25 GMT/r/nCache-Control: max-age=0/r/n/r/n").getBytes());
out.flush();
得到如下响应：
HTTP/1.1 400 Bad Request
Date: Wed, 08 Feb 2012 08:36:52 GMT
Server: Apache
Content-Length: 226
Connection: close
Content-Type: text/html; charset=iso-8859-1
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head> <title>400 Bad Request</title> </head>
<body>
<h1>Bad Request</h1>
<p>Your browser sent a request that this server could not understand.<br /> </p>
</body>
</html>
这个结果与线上情况非常吻合，所以基本怀疑是某些客户端发送请求时时间太长引起的。apache的处理时间是从收到第一个头开始（GET /xxxx /r/n），
无论该头正确与否，都开始计算处理时间，后面的所有内容接收都计入处理时间。
诗剑书生的专栏
