问题描述

这两天本来忙着新功能开发,结果之前的一个项目最近要上了,然后又在测试,然后就喜提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)

还能说啥,直接上去改呗,于是连上数据库,打开表,查看表结构,发现好像没啥问题:

java 数据库字段超出长度报错 数据库字段长度不够_java 数据库字段超出长度报错

这不就是设置的2000吗,难道后面的字符集有问题吗,因为表是用的utf8mb4,难道有影响?然后改成了下面这样:

`feedback_content` varchar(2000) COLLATE utf8mb4_unicode_ci DEFAULT NULL COMMENT '反馈内容',

结果并没有用,果然不应该怀疑这个的,utf8 和 utf8mb4,差距也没那么大,这里又没有特殊字符。

另外就是,中途也试了直接用工具改表,好像没啥问题。

中途甚至怀疑连错库了,用命令查看了java进程(开发环境,java进程和数据库在同一台机器)的连接,确认库没连错。

netstat -ntp|grep 1279

java 数据库字段超出长度报错 数据库字段长度不够_sql_02

然后我尝试着用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中断抓包):

java 数据库字段超出长度报错 数据库字段长度不够_mysql_03

可以看到,确实是mysql 服务器报错了,和我们客户端没半毛钱关系。

但是,还是很奇怪,不知道为啥报错。

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

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

这里没指定-Ann了,因为我们这次是要保存下来,到test.pcap这个文件。

然后再去测了一下,然后回来ctrl c,可以看到如下信息:

java 数据库字段超出长度报错 数据库字段长度不够_java 数据库字段超出长度报错_04

(这里仅供演示,没再去测试了,我把下午抓的包给大家看)

wireshark分析

用wireshark打开该test.pcap,可以看到:

java 数据库字段超出长度报错 数据库字段长度不够_java_05

可以发现,wireshark直接内置了mysql的解析协议,很方便,我们这里隐去了一些表信息。大家学着用一下,很简单。

但是现在还没看出来问题,我仔细观察了一下,

java 数据库字段超出长度报错 数据库字段长度不够_mysql_06

上图中,我发现,每一列后,都会跟个逗号来分隔;但是,我们反馈内容那一列,前面怎么那么多个点呢?

然后基本可以肯定,是程序在里面加料了,然后去看了代码逻辑,果然,程序里,对前端传过来的内容,前面还拼了一些东西进去,然后基本就这样找到问题了。

实际上,我们也可以这样看,对着这个包,点右键,follow stream,就会把这个socket 四元组的通信都过滤出来。

java 数据库字段超出长度报错 数据库字段长度不够_java 数据库字段超出长度报错_07

注意,上图是asicc显示的,我们切换为utf8看一下,就很明显了。

java 数据库字段超出长度报错 数据库字段长度不够_java_08

总结

问题本身很简单,因为惯性思维,我也没有第一时间去看业务逻辑,本能地开始怀疑mysql那边的问题去了,其实还是应该先看看业务。

另外,tcpdump、wireshark这类神器,大家一定要掌握,缩小问题边界、不同服务间问题甩锅啥的,就靠它了。