曹工改bug--本來以為很簡單的資料庫欄位長度不足的問題,最後竟然靠抓包才解決

三國夢迴發表於2020-07-14

問題描述

這兩天本來忙著新功能開發,結果之前的一個專案最近要上了,然後又在測試,然後就喜提bug一枚(not mine),看bug描述,很簡單,而且本地環境也重現了,只要輸入2000個英文字元就可以復現。

核心就是:

當任務描述輸入最大字元2000時,報未知異常

問題定位

這種字元數限制的,一般就是資料庫的欄位長度短了,於是我直接找到ssh,找到對應的日誌看了一下,果然是這個問題。

com.mysql.jdbc.MysqlDataTruncation: Data truncation: Data too long for column 'feedback_content' at row 1
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3931)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3869)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2524)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2675)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2465)

還能說啥,直接上去改唄,於是連上資料庫,開啟表,檢視錶結構,發現好像沒啥問題:

這不就是設定的2000嗎,難道後面的字符集有問題嗎,因為表是用的utf8mb4,難道有影響?然後改成了下面這樣:

  `feedback_content` varchar(2000) COLLATE utf8mb4_unicode_ci DEFAULT NULL COMMENT '反饋內容',

結果並沒有用,果然不應該懷疑這個的,utf8 和 utf8mb4,差距也沒那麼大,這裡又沒有特殊字元。

另外就是,中途也試了直接用工具改表,好像沒啥問題。

中途甚至懷疑連錯庫了,用命令檢視了java程式(開發環境,java程式和資料庫在同一臺機器)的連線,確認庫沒連錯。

netstat -ntp|grep 1279

然後我嘗試著用1999、1998字元去驗證,還是有問題,想著哥見過的bug多了,還能栽在這兒嗎,實在不行就開idea,本地debug一下吧。

這樣想著,到了午飯時間,就去吃飯了。

再次定位

吃完飯後,中午並沒有看bug,不過有個大概思路準備試一下。

思路就是,伺服器上用tcpdump抓應用程式和mysql之間的包,然後看看情況,看看到底是哪裡有問題吧。

然後下午空了一會,就在伺服器上開了抓包:

tcpdump -i lo tcp port 3306  -Ann

  • -i 抓環回網路卡,因為我java服務和mysql在一臺上
  • tcp port 3306 這個是捕獲表示式,意思是,抓的包,其埠(不管是source還是destination,其埠需要是3306)
  • -A Print each packet (minus its link level header) in ASCII. Handy for capturing web pages. 意為直接asicc列印包的內容,因為mysql不是完全看不懂的二進位制協議,所以可以直接列印
  • -nn Don't convert protocol and port numbers etc. to names either. 埠顯示數字就好,不用把知名埠轉換為可讀的文字

開了抓包後,然後馬上去操作了一把,然後這邊馬上看到,包已經列印出來了(包如果很多,記得趕快ctrl c中斷抓包):

可以看到,確實是mysql 伺服器報錯了,和我們客戶端沒半毛錢關係。

但是,還是很奇怪,不知道為啥報錯。

於是,我重新抓了一次包。

tcpdump -i lo tcp port 3306  -w test.pcap

這裡沒指定-Ann了,因為我們這次是要儲存下來,到test.pcap這個檔案。

然後再去測了一下,然後回來ctrl c,可以看到如下資訊:

(這裡僅供演示,沒再去測試了,我把下午抓的包給大家看)

wireshark分析

用wireshark開啟該test.pcap,可以看到:

可以發現,wireshark直接內建了mysql的解析協議,很方便,我們這裡隱去了一些表資訊。大家學著用一下,很簡單。

但是現在還沒看出來問題,我仔細觀察了一下,

上圖中,我發現,每一列後,都會跟個逗號來分隔;但是,我們反饋內容那一列,前面怎麼那麼多個點呢?

然後基本可以肯定,是程式在裡面加料了,然後去看了程式碼邏輯,果然,程式裡,對前端傳過來的內容,前面還拼了一些東西進去,然後基本就這樣找到問題了。

實際上,我們也可以這樣看,對著這個包,點右鍵,follow stream,就會把這個socket 四元組的通訊都過濾出來。

注意,上圖是asicc顯示的,我們切換為utf8看一下,就很明顯了。

總結

問題本身很簡單,因為慣性思維,我也沒有第一時間去看業務邏輯,本能地開始懷疑mysql那邊的問題去了,其實還是應該先看看業務。

另外,tcpdump、wireshark這類神器,大家一定要掌握,縮小問題邊界、不同服務間問題甩鍋啥的,就靠它了。

對了,這裡分享下最近畫的JVM腦圖一張,有用的話,大家給腦圖點個贊哈。
https://www.processon.com/view/link/5f0ad405f346fb3fdc66a153

相關文章