问题描述
这两天本来忙着新功能开发,结果之前的一个项目最近要上了,然后又在测试,然后就喜提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这类神器,大家一定要掌握,缩小问题边界、不同服务间问题甩锅啥的,就靠它了。