一次不规范HTTP请求引发的nginx响应400问题分析与解决 - 及时 - JOYK Joy of Geek, Geek News, Link all geek

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

常见nginx 400原因

搜寻网上资料，发现一般可能有以下几个原因会导致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这一层认为请求格式是没问题的。

实际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
# 有空格
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的模块。要采用此种方法则只能：

要么重新编译整个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

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

常见nginx 400原因

实际nginx 400 log分析

HTTP请求规范格式

golang net/http解析HTTP代码分析

尝试三方HTTP golang库 gin && echo

nginx lua/perl脚本更改query参数

nginx 将log/report路由至可兼容空格未转码HTTP请求的server

Recommend

China Embracing The Power Of Blockchain.

GM boss confirms hybrid Corvette due in 2023

都天天亏钱了，你为什么还坚持在这个市场里玩呢？

注意，可转债刚开始跌，远没有见底

【链向FM】央视曝光百倍暴利“虚拟币”骗局，马斯克将以每股54.2美元的现金价格收购Twit...

How To Secure Apache with Let's Encrypt on Ubuntu 22.04

It’s happening: Elon Musk strikes deal to buy Twitter for $44 billion

国际羊毛局首次向中国企业授予“金羊毛标志”认证：江苏阳光、山东南山智尚、山东如意

Look Out For This Decentralized Play-to-earn Metaverse

Show HN: Caddy v2.5.0

About Joyk