最近分析数据偶然发现nginx log中有一批用户所有的HTTP POST log上报请求均返回400，没有任何200成功记录，由于只占整体请求的不到0.5%，所以之前也一直没有触发监控报警，而且很奇怪的是只对于log上报的POST接口会存在这种特定用户全部400的情况，而对于其他接口无论POST还是GET均没有此类问题。
进一步分析log发现其实对某些地区的用户请求，这个比例甚至超过了10%，于是花时间跟进了一下，最终发现源于部分机型客户端发出的HTTP请求格式不规范导致，这里记录一下分析过程、原因以及最终解决方案。
搜寻网上资料，发现一般可能有以下几个原因会导致nginx响应400：
- request_uri 过长超过nginx配置大小
- cookie或者header过大超过nginx配置大小
- 空HOST头
- content_length和body长度不一致
这些错误其实都是发生在nginx这一层，即nginx处理时认为客户端请求格式错误，于是直接返回400，不会向upstream server转发请求，因而upstream server对这些错误请求其实完全是无感知的。
而这次根据nginx log分析，可以看到nginx其实有向upstream server转发请求--upstream_addr已经是upstream server 有效地址，所以400实际应当是upstream server返回的，而不是nginx直接返回，这说明至少nginx这一层认为请求格式是没问题的。
截取部分线上部分用户的错误日志，其大体样式如下
127.0.0.1:63646 - 24/Apr/2022:00:50:07 +0900 127.0.0.1:1080 0.000 0.000 POST /log/report?appd=abc.demo.android&appname=abcdemo&v=1.0&langes=zh-CN&phonetype=android&device_type=android&osn=Android OS 10 / API-29 (QKQ1.190825.002/V12.0.6.0.QFKCNXM)&channel=Google Play&build=Android OS 10 / API-29 (QKQ1.190825.002/V12.0.6.0.QFKCNXM)&resolution=1080x2340&ts=1650636192534 HTTP/1.1 400 50 - curl/7.52.1 - 0.000 0.000 127.0.0.1 1563 2021
日志分析可以发现大部分400请求都有一个问题：其query参数并未经过urlencode，比如可以很明显看到其参数channel=Google Play 中的空格并未转码成%20，直觉上推断这应该和400的原因有直接关系。
试错为了验证未转码query参数是否是导致400的直接原因，简单通过curl构造几个测试http请求：
# 无空格
curl -v 'http://127.0.0.1/log/report?appd=abc.demo.android&appname=abcdemo&v=1.0&langes=zh-CN&phonetype=android&channel=Google%20Play' -d @test.json
* Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 80 (#0)
> POST /log/report?appd=abc.demo.android&appname=abcdemo&v=1.0&langes=zh-CN&phonetype=android&channel=Google%20Play HTTP/1.1
> Host: 127.0.0.1
> User-Agent: curl/7.52.1
> Accept: */*
> Content-Length: 1563
> Content-Type: application/x-www-form-urlencoded
> Expect: 100-continue
>
< HTTP/1.1 100 Continue
* We are completely uploaded and fine
< HTTP/1.1 200 OK
< Server: nginx/1.16.1
< Date: Sat, 23 Apr 2022 15:54:53 GMT
< Content-Type: application/json
< Content-Length: 22
< Connection: keep-alive
<
* Curl_http_done: called premature == 0
* Connection #0 to host 127.0.0.1 left intact
# 有空格
curl -v 'http://127.0.0.1/log/report?appd=abc.demo.android&appname=abcdemo&v=1.0&langes=zh-CN&phonetype=android&channel=Google Play' -d @test.json
* Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 80 (#0)
> POST /log/report?appd=abc.demo.android&appname=abcdemo&v=1.0&langes=zh-CN&phonetype=android&channel=Google Play HTTP/1.1
> Host: 127.0.0.1
> User-Agent: curl/7.52.1
> Accept: */*
> Content-Length: 1563
> Content-Type: application/x-www-form-urlencoded
> Expect: 100-continue
>
< HTTP/1.1 100 Continue
* We are completely uploaded and fine
< HTTP/1.1 400 Bad Request
< Server: nginx/1.16.1
< Date: Sat, 23 Apr 2022 15:55:14 GMT
< Content-Type: text/plain; charset=utf-8
< Transfer-Encoding: chunked
< Connection: keep-alive
<
* Curl_http_done: called premature == 0
* Connection #0 to host 127.0.0.1 left intact
发现凡是带空格的请求upstream server均会直接返回400，这里可以推断query 参数未urlencode是400问题的直接原因了，但是为什么未转码会导致400呢？怎么从HTTP原理上解释这个现象？为了找到答案，需要回顾了一下HTTP协议标准。
HTTP请求规范格式HTTP的请求消息格式如下：
如上图所示，作为一种文本协议，对HTTP请求消息中不同部分的区别、拆分完全是基于空格 、回车符\r、换行符\n这些字符标记进行的，对于第一行的三个部分请求方法、URL和协议版本的拆分即是根据空格进行split。
分析查到的400 HTTP请求，可以发现由于query参数未urlencode，导致其中会出现空格，这时严格来说这个请求已经不符合HTTP规范了，因为此时第一行再根据空格可以split出超过3部分，无法与method、URL、version再一一对应，从语义上来说此时直接返回400是合理处理逻辑。
实际处理中，面对这种情况，有的组件能兼容处理--把split的首部和尾部分别作为method与version，而中间剩余部分统一作为URL，比如nginx即兼容了这种不规范格式，但是很多组件并不能兼容处理这种情况--毕竟这并不符合HTTP规范，比如charles抓包此种请求会出错、golang 的net/http库、Django的http模块收到这类请求都会报400...
负责日志上报的upstream server是golang实现的logsvc，其使用标准卡库net/http处理HTTP请求，进一步探究一下该标准库是怎么解析HTTP请求的，以确认错误原因。
根据golang源码，可以发现其HTTP请求解析的路径为 http.ListenAndServe => http.Serve => serve => readRequest.... 其解析HTTP请求头的逻辑即位于readRequest函数中。
readRequest部分代码如下：
// file: net/http/request.go
...
1009 func readRequest(b *bufio.Reader, deleteHostHeader bool) (req *Request, err error) {
1010 tp := newTextprotoReader(b)
1011 req = new(Request)
1012
1013 // First line: GET /index.html HTTP/1.0
1014 var s string
1015 if s, err = tp.ReadLine(); err != nil {
1016 return nil, err
1017 }
1018 defer func() {
1019 putTextprotoReader(tp)
1020 if err == io.EOF {
1021 err = io.ErrUnexpectedEOF
1022 }
1023 }()
1024
1025 var ok bool
1026 req.Method, req.RequestURI, req.Proto, ok = parseRequestLine(s)
1027 if !ok {
1028 return nil, &badStringError{"malformed HTTP request", s}
1029 }
1030 if !validMethod(req.Method) {
1031 return nil, &badStringError{"invalid method", req.Method}
1032 }
1033 rawurl := req.RequestURI
1034 if req.ProtoMajor, req.ProtoMinor, ok = ParseHTTPVersion(req.Proto); !ok {
1035 return nil, &badStringError{"malformed HTTP version", req.Proto}
1036 }
...
可以看到readRequest中先通过parseRequestLine解析出首行的method, URL与Proto三个字段，然后通过ParseHTTPVersion解析version是否正确，不正确则报错{"malformed HTTP version"， 最终会导致响应400。
parseRequestLine代码如下：
...
966 // parseRequestLine parses "GET /foo HTTP/1.1" into its three parts.
967 func parseRequestLine(line string) (method, requestURI, proto string, ok bool) {
968 s1 := strings.Index(line, " ")
969 s2 := strings.Index(line[s1+1:], " ")
970 if s1 < 0 || s2 < 0 {
971 return
972 }
973 s2 += s1 + 1
974 return line[:s1], line[s1+1 : s2], line[s2+1:], true
975 }
可以看到parseRequestLine的解析代码是通过查找第0个、第1个空格index，然后直接基于slice语法将其切成了method、requestURI、proto三部分，如果requestURI中包含额外空格，会导致proto取值实际变为第一个空格之后的所有字符，比如"POST abc/?x=o space d HTTP/1.1"会被解析为:method=POST, requestURI=abc/?x=0, proto=" space d HTTP/1.1"，这会导致下一步ParseHTTPVersion解析出错。
ParseHTTPVersion代码如下，可以发现之前parseRequestLine解析得到的version字段如果不合法，则会返回错误：
...
769 // ParseHTTPVersion parses an HTTP version string.
770 // "HTTP/1.0" returns (1, 0, true).
771 func ParseHTTPVersion(vers string) (major, minor int, ok bool) {
772 const Big = 1000000 // arbitrary upper bound
773 switch vers {
774 case "HTTP/1.1":
775 return 1, 1, true
776 case "HTTP/1.0":
777 return 1, 0, true
778 }
779 if !strings.HasPrefix(vers, "HTTP/") {
780 return 0, 0, false
781 }
782 dot := strings.Index(vers, ".")
783 if dot < 0 {
784 return 0, 0, false
785 }
786 major, err := strconv.Atoi(vers[5:dot])
787 if err != nil || major < 0 || major > Big {
788 return 0, 0, false
789 }
790 minor, err = strconv.Atoi(vers[dot+1:])
791 if err != nil || minor < 0 || minor > Big {
792 return 0, 0, false
793 }
794 return major, minor, true
795 }
首先要做的是先和客户端对齐问题，客户端确认部分机型上其调用unity的网络库方法未能对其query参数正常urlencode，新版本将在unity网络库之上增加额外代码保证所有参数必须urlencode，使其符合HTTP规范。
而后进一步考虑可否先临时兼容处理线上已有的异常请求，防止新版本覆盖修复前这部分异常用户log上报数据的持续丢失，针对兼容考虑了以下几个方案
由于日志服务由独立的golang server负责，其代码逻辑很简单：只是对log 的POST请求的body进行解压缩、解析、写入kafka，并无其他额外逻辑，改动成本较低，因此先考虑了替换net/http为其他三方库看是否能解决问题。
先后尝试了流行的gin和echo库发现都报400，忍不住又探究了其源码，结果发现这两个库内部其实都调用了net/http 的ListenAndServer 和 Serve方法，其前面的解析逻辑就是net/http对应代码负责的，因而自然也会报400。
想到的另一个可能方法是在nginx层使用lua/perl脚本对传入的未urlencode的request_uri参数进行urlencode后再发给upstream server，但是发现线上nginx编译时并未集成lua、perl的模块。要采用此种方法则只能：
- 要么重新编译整个nginx替换原nginx
- 或者采用动态加载的方式单独编译perl、lua模块后使用nginx动态加载
考虑到本人作为RD而非专业nginx OP人员，和对线上影响的风险不轻易尝试。
nginx 将log/report路由至可兼容空格未转码HTTP请求的server开头提到过对于待空格的异常请求，只有log上报POST接口会返回400，其他接口都返回正常，这其实是因为在nginx转发时对正常的业务接口和log接口进行了拆分，log/report接口会单独转发到独立的golang logsvc服务，而正常业务请求均会转发给python的主api服务。
回顾当初之所以会拆分一个单独的golang server负责app log上报的解析和写kafka，而不再和其他接口逻辑一样都由主api服务负责，主要是两个原因：
- Pythono写的api主服务相对效率较低，对于频繁、大量的log上报可能耗费过多资源，速度也较慢
- 避免log上报类请求影响其他正常的业务请求响应速度，将业务逻辑与日志上报两者解耦
当前logsvc无法处理的此种情况，使用uwsgi协议与nginx交互的api主服务却可以正常解析，因而在nginx添加如下临时配置：
location /log/report {
include proxy_params;
if ( $args !~ "^(.*) (.*)$" ) {
proxy_pass http://test_log_stream;
break;
}
include uwsgi_params;
uwsgi_pass test_api_stream;
}
即通过正则匹配query参数(args)中若不存在空格直接交由logsvc处理，存在空格则交由使用uwsgi协议的api主服务处理，由于此类异常请求仅占整体请求的不到0.5%，之前考虑的拆分架构依然work，只是对于少量的异常请求先通过api主服务进行兼容处理。
转载请注明出处，原文地址: https://www.cnblogs.com/AcAc-t/p/nginx_400_problem_for_not_encode_http_request.html
参考https://www.cnblogs.com/ranyonsue/p/5984001.html
https://www.920430.com/archives/4291504507.html
https://blog.csdn.net/iamlihongwei/article/details/103611655
https://dbaplus.cn/news-21-1129-1.html
https://blog.51cto.com/leejia/1434564
https://blog.csdn.net/kaosini/article/details/8433044