推薦幾個我近期排查線上http接口偶發415時用到的工具

導讀：近期有一個業務部門的同窗反饋說他負責的C工程在小几率狀況下SpringMvc會返回415，經過輸出的日誌能夠肯定是SpringMvc找不到content-type這個頭了，具體爲何找不到了呢？請聽我娓娓道來。

 

關鍵詞：http 415，SpringMvc，nginx，lua，wireshark，jmeter

問題現象：

近期接到一個同窗的反饋說，他負責的C工程在小几率的狀況下SpringMvc會返回415，經過輸出的日誌發現請求頭裏面並無content-type了，因此才致使SpringMvc返回415，他猜想多是我在nginx這邊加的lua腳本給影響了（咱們用lua腳本作了一些灰度跳轉的邏輯），雖然我內心很清楚lua這塊並無修改請求頭的邏輯，可是沒辦法，嘴上說說並不能服衆，我須要拿出證據自證清白。

第一把斧亮相：

既然是說lua把請求頭給改了，那把content-type輸出來看看不就完事了。很簡單，直接修改nginx access日誌的log_format便可，在原有的基礎上增長$http_content_type。就這樣很快加完了，那就開始守株待兔吧，運氣還不錯，幾分鐘之後就命中一個415的請求，查看access日誌裏記錄的content-type值，一點問題沒有，就是咱們熟悉的那個「application/json」，這一刻內心竊喜「不是哥的問題，回郵件該幹啥幹啥了」。

第二把斧亮相：

半天事後負責Resin（一種web服務器，和Tomcat差很少）的同窗找到了我，猜想多是請求頭裏面有某些特殊字符致使請求頭的解析發生了問題，因此請求頭亂了，請看下面這張圖，仔細找找實際上是能找到content-type的。

 

 

 

 

 話到這裏我已經知道他要幹什麼了，給我幾分鐘我想一想辦法，既然懷疑是特殊字符致使那我就將全部的頭信息都打印出來，查了一下lua-nginx-module的使用手冊，有一個聲明叫log-by-lua可使用一下，它相似於一個過濾器同樣，若是配置了，nginx會在特定的階段觸發它，更具體的說nginx會在log階段且在記錄access log以前觸發。因此個人大概思路是這樣「若是請求後端服務器返回415那就輸出請求頭信息到日誌中」，具體的腳本寫出來就是這樣（我當時想是否是能夠用在服務的監控上）：

location  ~ \.do$ {

        proxy_pass http://$backend;

         log_by_lua_block {

          if tonumber(ngx.var.status) == 415 then

                ngx.log(ngx.ERR,"upstream reponse status is 415,please notice it,here are request headers:")

                local h, err = ngx.req.get_headers(100,true)

 

               if err == "truncated" then

                    ngx.log(ngx.ERR,"request headers beyond 100,will not return")

                else

                   local cjson = require("cjson")

                   ngx.log(ngx.ERR,cjson.encode(h))

              end

          end

        }

   }

和以前同樣，繼續開始守株待兔，運氣不錯，幾分鐘事後就出現了415，立馬將請求頭信息發給負責Resin的那個大哥，感受立刻要水落石出了，下樓抽根菸放鬆放鬆。

 

第三把斧亮相：

次日剛到工位我就詢問負責Resin那個大哥是否復現了問題，結果讓人很意外，拿着我給的請求頭信息竟然沒有復現問題，這太不科學了，你們在羣裏你一言我一嘴，感受有些黔驢技窮，有人說要review Resin的源代碼（線上出了問題，review我以爲真的是一種解決問題的下策），有人在那裏抱怨說早應該把Resin替換掉的（過後諸葛亮），最後我提了一個土辦法，應該能夠復現問題，要是還不能復現真的就不科學了。兄臺，tcpdump+wireshark瞭解一下，分幾步來講：

        1.在服務器上使用tcpdump抓一段時間的包，由於不肯定何時會出現，因此暫定10分鐘；

        2.將第一步中產生的抓包文件使用wireshark打開，過濾http狀態爲415的請求，http.response.code==415；

        

 

 

        3.選擇其中一條報文，右鍵「追蹤流-tcp流」；

        4.複製第三步產生的tcp報文；

        

      5.將第四步複製的tcp報文直接貼到jmeter裏面進行測試（我爲何選擇jmeter，由於能夠直接模擬發送tcp報文，不會像postman增長一些本身的頭）；

      6.成功復現結果；

      7.導出jmeter腳本給負責Resin的同窗修改bug；

 

問題緣由分析：

最終肯定是Resin出了問題，但這裏有個前提是咱們公司本身改造過的Resin，官方的Resin並無這個問題，至於爲何咱們改造過的Resin會出問題，這裏就很少說了，只是一些內部的技術債罷了，說了可能也不會明白，明白了可能也不會碰上。

工具串講：

首先我使用nginx的log_format直接輸出請求頭裏面的content_type，可是若是想輸出全部的請求頭時這種方式就行不通了，因此我藉助了lua-nginx-module中的log-by-lua在反向代理請求結束時輸出了請求頭，最後爲了完徹底全找到問題發生的場景，我使用tcpdump來抓取網絡包，而且藉助wireshark來找到發生了415的tcp報文，拿着tcp報文直接使用jmeter成功復現問題。

 

總結：

十一長假的第五天，此刻剛把孩子哄睡着，在牀邊當心翼翼的打開電腦整理一下上次排查問題的過程，上面提到的幾個工具是我想推薦給你們使用的，這裏拿本身經歷過的真實場景作一個拋轉引用，至於更深層次的使用網絡上不乏鋪天蓋地的介紹，我這裏就不囉嗦了，若是以爲有用，請你們點個推薦。最後，祝你們假期愉快。

參考資料：

https://github.com/openresty/lua-nginx-module#log_by_lua

http://jmeter.apache.org/usermanual/index.html

https://www.wireshark.org/docs/