現(xiàn)象
業(yè)務(wù)中有個場景，接收到 HTTP 請求之后，根據(jù)條件可能修改某些參數(shù)杰扫，轉(zhuǎn)發(fā)請求，拿到結(jié)果之后稍作修改寫到 ServletResponse 中膘掰。
起初發(fā)現(xiàn)有的請求會返回 HTTP code 502章姓，但是多次復(fù)現(xiàn)之后發(fā)現(xiàn)經(jīng)過轉(zhuǎn)發(fā)的請求都會導(dǎo)致502，構(gòu)造參數(shù)直接訪問相應(yīng)的機器卻能夠正確返回识埋。
背景
我們的應(yīng)用容器是 tomcat凡伊，但是出問題的請求進入的原始機器和轉(zhuǎn)發(fā)后訪問的機器稍有不同，問題機器在 tomcat 前窒舟，同服務(wù)器還有個 nginx 系忙，所以有同事認為是這個多出來的 nginx 做了什么導(dǎo)致出錯。但是直覺上感覺不太可能惠豺，因為 nginx 作為一個標準組件银还，不會無故做這樣的攔截，一定是應(yīng)用代碼有什么問題耕腾。
過程
這里定義如下：
server A见剩，本機有 nginx ；
server B扫俺，本機無 nginx苍苞。
通過 cURL 訪問，能進一步將問題范圍縮小狼纬。
curl 'http://0.0.0.0:80/path?param=a' -H 'Host: www.xxx.com'
直接訪問 server A羹呵，構(gòu)造參數(shù)讓請求不進行轉(zhuǎn)發(fā)，此時能拿到正確的返回結(jié)果疗琉，HTTP code 200.
直接訪問 server B冈欢，也不進行轉(zhuǎn)發(fā)，此時也能拿到正確的結(jié)果盈简。
問題在于轉(zhuǎn)發(fā)的時候凑耻，server A 轉(zhuǎn)發(fā)到 server B太示，之后再返回給用戶，就一定會 502.
進一步加業(yè)務(wù)日志之后可以發(fā)現(xiàn)香浩，轉(zhuǎn)發(fā)到 server B 的請求类缤，在 server B 上的返回是正確的，HTTP code 200, body 也是正確的邻吭。
Empty reply
再構(gòu)造一個會進行轉(zhuǎn)發(fā)的請求餐弱，觀察 cURL 的輸出，發(fā)現(xiàn)如下：
* Empty reply from server
* Connection #0 to host www.xxx.com left intact
curl: (52) Empty reply from server
同時看到 nginx 的 access log 如下：
"GET /index.jsp HTTP/1.1" 200 0 "-" "curl/7.54.0" "-"
看 nginx 的 log-format囱晴，200 是 http status code膏蚓，后面的 0 是 body_bytes_sent, 也就是說 cURL 接收到的 body size 為 0.
于是開始懷疑，拿到請求轉(zhuǎn)發(fā)的 response 之后畸写，往回寫的時候出了什么問題導(dǎo)致 body 沒有寫驮瞧。
但是實際看了代碼之后，確認已經(jīng)往response.getOutputStream() 中寫入了 body枯芬，外層的 try-catch 也沒有捕捉到異常剧董，沒看到日志。
難不成 outputStream 里的數(shù)據(jù)還會被 tomcat 丟棄破停？
invalid chunked response
翻了下 nginx 的 error log，發(fā)現(xiàn)這個記錄：
[error] 18604#0: *9 upstream sent invalid chunked response while reading upstream, client: 127.0.0.1, server: localhost, request: "GET /index.jsp HTTP/1.1", upstream: "http://127.0.0.1:8080/index.jsp", host: "localhost"
日志中的 IP / host 信息都是本地模擬出來的尉剩，但是錯誤信息是一致的真慢。
于是就很有意思了，意思是 upstream 給 nginx 返回了一個 invalid chunked response理茎，也就是說 tomcat 回寫給 nginx 的數(shù)據(jù)分塊是無效的黑界。
tcpdump chunked data
只能靠 cURL 發(fā)請求來判斷兩端的請求、響應(yīng)數(shù)據(jù)皂林，不夠判定出問題的環(huán)節(jié)朗鸠，即使加上日志也還不夠。最好能夠拿到 tomcat 返回給 nginx 的數(shù)據(jù)础倍。想到了用 tcpdump烛占，直接抓取問題機器的 tcp 數(shù)據(jù)，然后本地用 wireshark 分析沟启。
命令如下：
tcpdump -vvv -i any 'port 8080 or port 80' -w request_to_80
意思是監(jiān)聽所有網(wǎng)卡（any）的數(shù)據(jù)忆家，并且指定 來源或者目標端口是 80 或者 8080 ，保存到文件
這里有兩個注意點：
- 需要注意權(quán)限問題德迹，可能需要 sudo 權(quán)限或者直接用 root 用戶
- 指定 any 網(wǎng)卡芽卿，
- 一般 80 端口沒有問題，請求從 80 端口進入胳搞，響應(yīng)從 80 端口發(fā)出
- 但是 nginx 和本機 tomcat 的數(shù)據(jù)通信是不經(jīng)過外部網(wǎng)絡(luò)的卸例，走的是虛擬網(wǎng)卡 loopback
端口的問題可以在本機實驗称杨，比如觀察到開發(fā)用的機器上需要監(jiān)聽這兩個網(wǎng)口：
en0
lo0
dump 下來，wireshark 通過 "Follow TCP Stream" 就能看到 HTTP 請求的響應(yīng)數(shù)據(jù)
發(fā)現(xiàn) tomcat 返回給 nginx 的數(shù)據(jù)類似如下：
GET /info?custom=12121 HTTP/1.0
Host: www.xxx.com
Connection: close
User-Agent: curl/7.54.0
Accept: */*
Cookie: xxx=yyy;
HTTP/1.1 200 OK
Set-Cookie: xxx=yyy
Transfer-Encoding: chunked
Connection: close
Vary: Accept-Encoding
Content-Language: zh-CN
Expires: Thu, 01 Jan 1970 00:00:00 GMT
Content-Type: application/json;charset=UTF-8
Date: Wed, 23 May 2018 06:55:42 GMT
Connection: close
{"code":200,"data":{...}}
乍一看沒什么問題筷转，再看正常返回 200 的請求：
ET /info?custom=12121 HTTP/1.1
Host: wwx.xxx.com
User-Agent: curl/7.54.0
Accept: */*
Cookie: xxx=yyy;
HTTP/1.1 200 OK
Set-Cookie: xxx=yyy
Transfer-Encoding: chunked
Connection: keep-alive
Keep-Alive: timeout=5
Vary: Accept-Encoding
Content-Language: zh-CN
Expires: Thu, 01 Jan 1970 00:00:00 GMT
Content-Type: application/json;charset=UTF-8
Transfer-Encoding: chunked
Date: Wed, 23 May 2018 06:55:07 GMT
526
{"code":200,"data":{...}}
0
再次看了異常請求的 header 和 body 之后姑原，發(fā)現(xiàn)異常請求的 body 開頭沒有數(shù)字。
查看這個 header 的作用及傳輸分塊的示例之后旦装，發(fā)現(xiàn)確實有問題：header 中指定了 chunked页衙，但是 body 并沒有分塊？結(jié)合正常的請求來看阴绢，按照正確的格式將數(shù)據(jù)分塊之后是能被 nginx 接受并處理的店乐。
那么接下來的疑問就是？為什么拿回來的數(shù)據(jù)呻袭，本來應(yīng)該是分塊的眨八，但是被解開了？
為什么正常的響應(yīng)一定是分塊的左电？因為如果不分塊廉侧，header 中不會被中間某個組件加 Transfer-Encoding: chunked這個頭。
接下來就是分析：請求返回過程中篓足，誰對 response body 中的內(nèi)容做了解分塊操作段誊。
HttpClient chunk
轉(zhuǎn)發(fā)的過程是使用 HttpClient 發(fā)起了一個新的 http 請求，拿到結(jié)果之后將 response copy 到 servletResponse 中栈拖，查看 copy response 的那部分代碼连舍，沒有發(fā)現(xiàn)問題。
于是懷疑起了 tomcat 和 HttpClient涩哟，先看 HttpClient索赏。
思路就是看 HttpClient 請求回來之后到輸出之前有沒有 dechunk
寫了個簡單的測試用例，拿到結(jié)果之后輸出：
String str = EntityUtils.toString(response.getEntity());
果然是明文贴彼，沒有分塊潜腻。
看源碼，來自：httpclient 4.3.2：
實際處理流程器仗，正向
org.apache.http.protocol.HttpRequestExecutor#doSendRequest
—> org.apache.http.impl.AbstractHttpClientConnection#receiveResponseEntity
—> org.apache.http.impl.entity.EntityDeserializer#deserialize
—> org.apache.http.impl.entity.EntityDeserializer#doDeserialize
// 準備 inputStream 的時候會判斷是否分塊
org.apache.http.impl.entity.LaxContentLengthStrategy#determineLength
// 可以看到：header 中出現(xiàn) Transfer-Encoding: chunked 的時候就會處理分塊
org.apache.http.impl.io.ChunkedInputStream#read(byte[], int, int) // 具體的融涣，ChunkedInputStream 會處理 CRLF 分隔符和chunk大小，重載了 read 方法青灼，也就是實際讀取 stream 的時候就會讀到一個 de-chunked 過的 buffer 數(shù)據(jù)
解決方案
最后是將 Transfer-Encoding: chunked這個頭從 response 中去掉暴心，又后續(xù)流程中的 nginx 決定是否去做分塊。在業(yè)務(wù)代碼里也就是不做分塊杂拨，也不提供錯誤信息专普，之前的 response 被 nginx 認為無效也是因為 header 暗示說分塊，但是實際的 body 沒有分塊導(dǎo)致的弹沽。
總結(jié)
這個問題隱藏確實比較深檀夹，前前后后排查了很長時間筋粗，從發(fā)現(xiàn)問題，到懷疑應(yīng)用部署結(jié)構(gòu)炸渡，到懷疑 nginx 娜亿，走了不少彎路。但是收獲也是巨大的蚌堵，對 tcpdump 的應(yīng)用买决，以及 HTTP 標準中的某些細節(jié)，HttpClient 對標準的實現(xiàn)吼畏，都有了一定的了解督赤。尤其 tcpdump，有了這個工具泻蚊，攔截到原始的 tcp 報文數(shù)據(jù)躲舌，排查問題就有了鐵證，剩下的就是怎么根據(jù)標準解讀協(xié)議了性雄。
