nginx日志里的400,408错误

发表于： 2021年7月22日 2021年7月22日
分类： Nginx
标签： 408错误, Nginx

今天看某群里有同学说做ssl卸载的nginx上有很多408错误日志。然后我也看了下我们服务器上果然有好多的，比例还不小，好几个百分点呢。HTTP状态码的还以可以简单参考http://en.wikipedia.org/wiki/List_of_HTTP_status_codes

400 Bad Request

The request cannot be fulfilled due to bad syntax

408 Request Timeout
The server timed out waiting for the request.[2] According to W3 HTTP specifications: “The client did not produce a request within the time that the server was prepared to wait. The client MAY repeat the request without modifications at any later time.”
408错误是由于由于client方在设置的时间内(client_header_timeout和client_body_timeout，nginx下默认都是60s)没有发送完请求造成的。

其实主要是因为现在的浏览器，比如chrome的话在打开页面是会并发开10个左右的请求，其实只有一个是实际会用的，其他的几个请求虽然用不上，但是浏览器也不管，最后会因为达到超时的时间被server短断掉。为此我专门抓包测试了一下。在自己的VPS上开2个窗口，一个用来抓包，另外一个观察日志。
抓包的时候过滤一下，只看SYN和FIN包的，然后chrome浏览器里打开自己的blog。

tcpdump -i venet0 host 218.109.58.145 and ‘tcp[tcpflags] & (tcp-syn|tcp-fin) !=0 ‘ -n
[text]
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on venet0, link-type LINUX_SLL (Linux cooked), capture size 65535 bytes
15:05:46.564166 IP 218.109.58.145.63349 > 184.82.227.17.443: Flags [S], seq 1769258416, win 8192, options [mss 1452,nop,nop,sackOK], length 0
15:05:46.564202 IP 184.82.227.17.443 > 218.109.58.145.63349: Flags [S.], seq 1090238511, ack 1769258417, win 5840, options [mss 1460,nop,nop,sackOK], length 0
15:05:46.579764 IP 218.109.58.145.63350 > 184.82.227.17.443: Flags [S], seq 2476535492, win 8192, options [mss 1452,nop,nop,sackOK], length 0
15:05:46.579790 IP 184.82.227.17.443 > 218.109.58.145.63350: Flags [S.], seq 1079878779, ack 2476535493, win 5840, options [mss 1460,nop,nop,sackOK], length 0
15:05:46.580418 IP 218.109.58.145.63351 > 184.82.227.17.443: Flags [S], seq 3924057720, win 8192, options [mss 1452,nop,nop,sackOK], length 0
15:05:46.580444 IP 184.82.227.17.443 > 218.109.58.145.63351: Flags [S.], seq 1076802158, ack 3924057721, win 5840, options [mss 1460,nop,nop,sackOK], length 0
15:05:46.583872 IP 218.109.58.145.63352 > 184.82.227.17.443: Flags [S], seq 1351188747, win 8192, options [mss 1452,nop,nop,sackOK], length 0
15:05:46.583897 IP 184.82.227.17.443 > 218.109.58.145.63352: Flags [S.], seq 1085259777, ack 1351188748, win 5840, options [mss 1460,nop,nop,sackOK], length 0
15:05:46.591067 IP 218.109.58.145.63353 > 184.82.227.17.443: Flags [S], seq 3937887977, win 8192, options [mss 1452,nop,nop,sackOK], length 0
15:05:46.591094 IP 184.82.227.17.443 > 218.109.58.145.63353: Flags [S.], seq 1089841397, ack 3937887978, win 5840, options [mss 1460,nop,nop,sackOK], length 0
15:05:46.592480 IP 218.109.58.145.63354 > 184.82.227.17.443: Flags [S], seq 1123849790, win 8192, options [mss 1452,nop,nop,sackOK], length 0
15:05:46.592504 IP 184.82.227.17.443 > 218.109.58.145.63354: Flags [S.], seq 1090612586, ack 1123849791, win 5840, options [mss 1460,nop,nop,sackOK], length 0
15:05:46.593123 IP 218.109.58.145.63355 > 184.82.227.17.443: Flags [S], seq 4065204445, win 8192, options [mss 1452,nop,nop,sackOK], length 0
15:05:46.593149 IP 184.82.227.17.443 > 218.109.58.145.63355: Flags [S.], seq 1080746021, ack 4065204446, win 5840, options [mss 1460,nop,nop,sackOK], length 0
15:05:46.831197 IP 218.109.58.145.63357 > 184.82.227.17.443: Flags [S], seq 3474172840, win 8192, options [mss 1452,nop,nop,sackOK], length 0
15:05:46.831235 IP 184.82.227.17.443 > 218.109.58.145.63357: Flags [S.], seq 1084428126, ack 3474172841, win 5840, options [mss 1460,nop,nop,sackOK], length 0
15:05:54.366066 IP 184.82.227.17.443 > 218.109.58.145.63349: Flags [F.], seq 22377, ack 810, win 8576, length 0
15:05:57.138228 IP 218.109.58.145.63357 > 184.82.227.17.443: Flags [F.], seq 1, ack 1, win 17520, length 0
15:05:57.138506 IP 184.82.227.17.443 > 218.109.58.145.63357: Flags [F.], seq 1, ack 2, win 5840, length 0
15:05:57.780671 IP 218.109.58.145.63349 > 184.82.227.17.443: Flags [F.], seq 810, ack 22378, win 17483, length 0
15:06:46.859866 IP 184.82.227.17.443 > 218.109.58.145.63350: Flags

nginx日志里:

– – 218.109.58.145:63185 – – [10/Mar/2013:15:03:40 +0000] gnuers.org "GET / HTTP/1.1" 200 15929 "-" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.17 (KHTML, like Gecko) Chrome/24.0.1312.52 Safari/537.17" "-" "unix:/var/run/php5-fpm.sock" 1.449 0.289
– – 218.109.58.145:63186 – – [10/Mar/2013:15:03:49 +0000] localhost "-" 400 0 "-" "-" "-" "-" 0.000 –
– – 218.109.58.145:63179 – – [10/Mar/2013:15:04:39 +0000] localhost "-" 408 0 "-" "-" "-" "-" 59.999 –
– – 218.109.58.145:63180 – – [10/Mar/2013:15:04:39 +0000] localhost "-" 408 0 "-" "-" "-" "-" 60.000 –
– – 218.109.58.145:63181 – – [10/Mar/2013:15:04:39 +0000] localhost "-" 408 0 "-" "-" "-" "-" 59.991 –
– – 218.109.58.145:63182 – – [10/Mar/2013:15:04:39 +0000] localhost "-" 408 0 "-" "-" "-" "-" 59.991 –
– – 218.109.58.145:63183 – – [10/Mar/2013:15:04:39 +0000] localhost "-" 408 0 "-" "-" "-" "-" 59.992 –
– – 218.109.58.145:63184 – – [10/Mar/2013:15:04:39 +0000] localhost "-" 408 0 "-" "-" "-" "-" 60.000 –
– – 218.109.58.145:63349 – – [10/Mar/2013:15:05:49 +0000] gnuers.org

从日志和抓包的记录可以看到，浏览器一起并发了9个请求，其中的大部分在1分钟后被nginx执行了主动关闭。这个问题其实是因为客户端的原因造成的。所以千万不要看到很多错误日志就觉得有大问题了。

PS：如果是用的tengine的话，可以加 log_empty_request off部记录这样的408请求。

参考文章：
http://forum.nginx.org/read.php?2,225349,225375
https://blog.xjpvictor.info/2012/11/nginx-log-400-408/

nginx日志里的400,408错误插图