关于一次导入数据提示的MySQL server has gone away

  • 来源: MySQLOPS 数据库与运维自动化技术分享 文:张琳娟   2013-12-17/10:54
  • 背景

    这个问题由一个同事问到的一次导入数据引发。一个很常见的操作,将数据从一个表中dump出来,在用mysql < a.sql的方式导入到另一个库的一个表中。

    在执行导入的时候,提示 MySQL server has gone away。在追查的时候突然想到会不会是因为max_allowed_packet太小导致的。将max_allowed_packet改大,确实解决了问题。

    本文基于在此之后想到的两个问题:

    1、              MySQL server has gone away这个提示很不友好,是不是所有的包超过大小都是报这个?

    2、              对于出现这种不友好的错误提示,有什么方法定位原因(而不是靠“突然想到”)?

    追查1

    步骤:a) 把max_allowed_packet设置为一个比较小的值, set global max_allowed_packet=16384

    b) 写一个简单的语句 insert into tb values(xxx),(xxx),(xxx)……(xxx) 让这个文件足够大,比如我测试使用 a.sql大小为37318

    c) 执行导入语句,提示 ER2ROR 1153 (08S01) at line 1: Got a packet bigger than ‘max_allowed_packet’ bytes

    初步结论是并不是所有的语句太大都会导致直接显示gone away。如果都是后面这个提示就好了,一目了然,用户自然会去修改max_allowed_packet。

    因此我们的问题就变成:为什么会有不同的提示?

    分析1

     我们将报gone away的称为场景1,另外一个称为场景2.

    场景1执行的sql语句大小是16554913

    实际上场景2的返回信息是由MySQL服务端返回的,因为服务端才能判断得到包大小超过。那么场景1为什么不是相同的提示呢?是不是压根儿请求就没有发到服务端?

    照这个思路查到下面代码(clent/mysql.cc)

    其中场景1执行到2785行return了,而场景2是在调用2786行的put_error中输出上述信息的。

    这证实了上面的结论,场景1是在调用请求的时候提示的失败,还没有到服务端判断包大小的环节。但是问题又来了,发送失败为什么要提示gone away?我们最常见到的gone away,是执行期间MySQL重启了,但这个case里面mysql并没有重启(这个很容易确认)。

    分析1-2

    进到mysql_real_query里面看看。发现执行路径差别在此(sql-common/client.c)

    场景1调用net_write_command失败,会执行到行854,场景2调用成功。就是说场景2里面,整个语句是都发给服务端成功的,因此服务端可以做后续的判断(包大小)。而场景1由于发命令失败,执行到mysql_reconnect.。但进入mysql_reconnect发现没有必要重发(我们是普通的客户端),然后发现一处hard code。

    这里就是罪魁祸首了。因为mysql->reconnect为空,说明这里不需要重新连接。于是就直接在set_mysql_error中传入 CR_SERVER_GONE_ERROR, 输出在客户端就是gone away。

    至于为什么场景1发送会失败,关键就是内容太大,tcp都不让它发了(write调用失败)

    追查2

    其实笔者觉得这个问题反而比较有意义,gone away这种错误提示不友好,会导致追查很难下手。有一个固定的步骤来查,避免抓瞎。

    从上面的分析知道,由于之前的调用失败,客户端试图进行“重连”,但是由于mysql->reconnect为0导致返回gone away。可以从这里下手。获取在执行mysql_reconnect之前的那个错误号。

    一个debug命令文件

    [dingqi.lxb@rds064076 master]$ cat x.debug

    set args   -Srun/mysql.sock -uroot   test < b.sql

    b mysql_reconnect

    r

    c

    f 1

    p mysql->net.last_errno

    在shell执行 gdb mysql  -x x.debug

    $1 = 1160

    这个1160就是我们要的了,

    ./include/mysqld_ername.h:{ “ER_NET_ERROR_ON_WRITE”, 1160, “Got an error writing communication packets” },

    表明了真正的错误是交互时发包失败。

    小结

    都是包太大,只是一个大过头了,导致在失败在客户端发生,又由于重连时的hard code,导致了一个不友好的提示 gone away。

    神马?你也碰到这种情况但不是max_allowed_packet 的问题,但是你的mysql没有debug信息?载一个源码安装。或者可以将你的复现步骤发给我。#异常gone away收集中#


    评论 {{userinfo.comments}}

    {{money}}

    {{question.question}}

    A {{question.A}}
    B {{question.B}}
    C {{question.C}}
    D {{question.D}}
    提交

    驱动号 更多