一次不規范HTTP請求引發的nginx回應400問題分析與解決-有解無憂

背景

最近分析資料偶然發現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

簽名：擁抱開源，擁抱自由

轉載請註明出處，本文鏈接：https://www.uj5u.com/houduan/464973.html

標籤：Go

上一篇：muduo原始碼分析之回呼模塊

下一篇：TCP/IP 協議竟然有這么多漏洞？