一次不規範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 '//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 '//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的請求消息格式如下:
image
如上圖所示,作為一種文本協議,對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 //test_log_stream;
            break;
        }
        include uwsgi_params;
        uwsgi_pass test_api_stream;
    }

即通過正則匹配query參數(args)中若不存在空格直接交由logsvc處理,存在空格則交由使用uwsgi協議的api主服務處理,由於此類異常請求僅佔整體請求的不到0.5%,之前考慮的拆分架構依然work,只是對於少量的異常請求先通過api主服務進行兼容處理。

轉載請註明出處,原文地址: //www.cnblogs.com/AcAc-t/p/nginx_400_problem_for_not_encode_http_request.html

參考

//www.cnblogs.com/ranyonsue/p/5984001.html
//www.920430.com/archives/4291504507.html
//blog.csdn.net/iamlihongwei/article/details/103611655
//dbaplus.cn/news-21-1129-1.html
//blog.51cto.com/leejia/1434564
//blog.csdn.net/kaosini/article/details/8433044