openresty記錄響應body亂碼問題

最近新上了乙個功能，openresty通過syslog記錄請求日誌，然後由logstash推送至es。測試上線時未發現這個問題，在日常檢視日誌的過程中，發現logstash推送有錯誤日誌，錯誤內容為：error parsing json，導致此條請求日誌丟失。

1、在syslog中查詢出現rror parsing json的日誌，日誌內容為：

,
"api
": {},
"upstream_uri
": ""
,    
"response
": ,
"status
": 200
,        
"size
": "
1012"},
"started_at
": 1546407283066
}

大家可以看到response.body是亂碼，response.body記錄的是請求相應的內容把這一段json進行json校驗，也會發現有問題。

2、嘗試呼叫該介面，發現返回的是正常內容，但是記錄的確是亂碼，所以確定應該是openresty記錄日誌的時候出現了問題。目前我們是在openresty的log階段進行日誌記錄，且針對chunked編碼進行了處理（如果body大於1k則不進行記錄）。日誌記錄的**如下：

function
body_filter()
local headers =ngx.resp.get_headers()
if headers['
content-type
'] and
then
ifstring.find(headers['
content-type
'], "
") or
string.find(headers['
content-type
'], "
text/plain
") then
local chunk = ngx.arg[1] or
""if
string.len(ngx.ctx.response_temp or
"") < max_body_size then
ngx.ctx.response_temp = (ngx.ctx.response_temp or
"").. chunk
ngx.ctx.response_body =ngx.ctx.response_temp
else
ngx.ctx.response_body = ""
endend
endend

3、想通過在測試環境加一些日誌，然後呼叫線上的介面進行排查問題，由於線上的介面做了ip限制，測試環境調不通，此方法作罷。

4、讓介面方把線上的資料拷貝至測試環境，然後呼叫此介面，但是日誌記錄也是正常的，沒有出現亂碼。

5、由於不能重現問題，在測試環境排查很難繼續下去。最後沒辦法，只能獻出終極**，抓包。

通過我標紅的地方可以很清楚的看到，響應資料是通過gzip壓縮的，而我們日誌記錄中沒有任何解壓縮的處理，所以日誌記錄的時候就會出現上述的情況。

最後解決方式是如果響應body如果進行了壓縮，我們預設不記錄響應body。

這個問題從出現到最終解決前前後後經歷了兩三天，解決完了會發現這個問題其實很簡單，從最早的日誌裡其實也有蛛絲馬跡（如第乙個**片段中標紅的地方），但你其實想不到。所以也給了我很深的感悟：

1、一定要想方設法的重現問題，不然很多時候你可能就無從下手。

2、網路這一門技術確實太重要了，如果這次不進行抓包分析，可能還得絞盡腦汁想別的方法。記得上一次nginx的問題也是通過抓包分析問題的，所以這一利器一定要掌握。

寫這篇文章的主要目的是記錄一下自己的排查過程（很多細節可能描述的不是很清楚），通過這種方式讓自己不斷優化自己解決問題的思路，讓以後的日子裡沒有難解的bug。^_^

openresty記錄響應body亂碼問題

Openresty的同步輸出與流式響應

request響應碼記錄

Apache 記錄請求響應時間日誌

openresty記錄響應body亂碼問題

Openresty的同步輸出與流式響應

request響應碼記錄

Apache 記錄請求響應時間日誌

相關推薦