一次不规范HTTP请求引发的nginx响应400问题分析与解决

背景

最近分析数据偶然发现nginx log中有一批用户所有的HTTP POST log上报请求均返回400，没有任何200成功记录，由于只占整体请求的不到0.5%，所以之前也一直没有触发监控报警，而且很奇怪的是只对于log上报的POST接口会存在这种特定用户全部400的情况，而对于其他接口无论POST还是GET均没有此类问题。
进一步分析log发现其实对某些地区的用户请求，这个比例甚至超过了10%，于是花时间跟进了一下，最终发现源于部分机型客户端发出的HTTP请求格式不规范导致，这里记录一下分析过程、原因以及最终解决方案。

问题分析

常见nginx 400原因

搜寻网上资料，发现一般可能有以下几个原因会导致nginx响应400：

1. request_uri 过长超过nginx配置大小
2. cookie或者header过大超过nginx配置大小
3. 空HOST头
4. content_length和body长度不一致

这些错误其实都是发生在nginx这一层，即nginx处理时认为客户端请求格式错误，于是直接返回400，不会向upstream server转发请求，因而upstream server对这些错误请求其实完全是无感知的。
而这次根据nginx log分析，可以看到nginx其实有向upstream server转发请求–upstream_addr已经是upstream server 有效地址，所以400实际应当是upstream server返回的，而不是nginx直接返回，这说明至少nginx这一层认为请求格式是没问题的。

实际nginx 400 log分析

截取部分线上部分用户的错误日志，其大体样式如下

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
&#x6709;&#x7A7A;&#x683C;
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…

golang net/http解析HTTP代码分析

负责日志上报的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上报数据的持续丢失，针对兼容考虑了以下几个方案

尝试三方HTTP golang库 gin && echo

由于日志服务由独立的golang server负责，其代码逻辑很简单：只是对log 的POST请求的body进行解压缩、解析、写入kafka，并无其他额外逻辑，改动成本较低，因此先考虑了替换net/http为其他三方库看是否能解决问题。
先后尝试了流行的gin和echo库发现都报400，忍不住又探究了其源码，结果发现这两个库内部其实都调用了net/http 的ListenAndServer 和 Serve方法，其前面的解析逻辑就是net/http对应代码负责的，因而自然也会报400。

nginx lua/perl脚本更改query参数

想到的另一个可能方法是在nginx层使用lua/perl脚本对传入的未urlencode的request_uri参数进行urlencode后再发给upstream server，但是发现线上nginx编译时并未集成lua、perl的模块。要采用此种方法则只能：

1. 要么重新编译整个nginx替换原nginx
2. 或者采用动态加载的方式单独编译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服务负责，主要是两个原因：

1. Pythono写的api主服务相对效率较低，对于频繁、大量的log上报可能耗费过多资源，速度也较慢
2. 避免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

Original: https://www.cnblogs.com/AcAc-t/p/nginx_400_problem_for_not_encode_http_request.html
Author: 及时
Title: 一次不规范HTTP请求引发的nginx响应400问题分析与解决