现象
做自动化重启的时候, 会检查相关日志信息, 发现停止从库时, 主库的日志里面有报错如下:
2025-04-15T06:48:37.968266Z 0 [ERROR] /soft/mysql_3308/mysqlbase/mysql/bin/mysqld: Got an error reading communication packets
分析 & 验证
通常Got an error reading communication packets信息我们是不需要分析的, 就是连接断开了而已, 但是这里被分类为ERROR了. 也就需要瞅瞅为啥了.
先看报错内容
先看报错内容: Got an error reading communication packets, 该信息为连接断开了, 比如我们把某个连接的进程给kill了(是kill的客户端连接进程,而非服务端连接) 比如:
但这个是属于[Note]啊, 和我们看到的[ERROR]不一样. 而且还多了一部分连接信息…
我们还可以使用telnet来模拟, 这样就没有连接信息了. -_-
但始终是NOTE级别.
能看到错误码MY-010914 是因为是8.0环境, 5.7是连报错码都没有的.
看看是谁输出的这个信息
那我们看看是哪个对象输出的这部分信息, 还是老方法, 在源码里面使用grep找. 先看对应的报错名字:
grep -r 'Got an error reading communication packets' sql/share/errmsg-utf8.txt -C 10
发现是叫 ER_NET_READ_ERROR , 还挺顾名思义的.
再看看是哪些地方有匹配的:
grep -r ER_NET_READ_ERROR
看起来最像的就是半同步那的问题了.
do {
net_clear(&net, 0);
len= my_net_read(&net);
if (likely(len != packet_error))
repl_semisync.reportReplyPacket(slave_obj.server_id,
net.read_pos, len);
else if (net.last_errno == ER_NET_READ_ERROR)
listener.clear_socket_info(i);
} while (net.vio->has_data(net.vio) && m_status == ST_UP);
具体的代码逻辑和怎么输出的内容我们就不看了.
日志输出并不在这里. 而是sql_print_error, 具体的可以看文末堆栈信息.
验证
我们直接来验证一下, 即存在半同步和不存在半同步时停止复制进程, error日志里面是否有输出.
存在半同步的情况
-- install plugin rpl_semi_sync_master soname 'semisync_master.so';
-- install plugin rpl_semi_sync_slave soname 'semisync_slave.so';
-- set global rpl_semi_sync_master_enabled = 1;
-- set global rpl_semi_sync_slave_enabled = 1;
-- 重启复制进程,半同步才生效.
stop slave;
start slave;
-- 停止从库复制进程,然后查看主库日志
stop slave;
确实复现了.
再看看没得半同步的情况
set global rpl_semi_sync_slave_enabled = 0;
stop slave;
start slave;
-- 停止从库复制进程,然后查看主库日志
stop slave;
主库日志没有任何记录, 就跟一个连接正常断开似的.
证明这部分ERROR信息确实是半同步插件输出的.
处理方法
- 忽略(假装没看到, 毕竟也不算啥问题.)
- 匹配日志的时候去掉
Got an error reading communication packets之类的信息. 这部分信息用处也不大.
机智的小伙伴会发现: 既然是半同步输出的这部分信息, 那么如果先停止半同步,然后停止复制进程,是否就不会产生这个报错呢? 理论上是, 但不停止复制线程, 咋个停止半同步呢…
rpl_semi_sync_slave_enabled启动复制进程时才会看.
其它
如果有兴趣的, 还可以看下ERROR日志堆栈信息 (我这是5.7环境的), 如下:
(gdb) break sql_print_error Breakpoint 1 at 0xc89a60: file /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/sql/log.cc, line 2147. (gdb) c Continuing. [Switching to Thread 0x7f6328837700 (LWP 16695)] Breakpoint 1, sql_print_error (format=0x14e82c4 "%s: %s") at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/sql/log.cc:2147 2147 /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/sql/log.cc: No such file or directory. (gdb) bt #0 sql_print_error (format=0x14e82c4 "%s: %s") at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/sql/log.cc:2147 #1 0x00000000007eeb64 in my_message_sql (error=1158, str=0x7f6328836310 "Got an error reading communication packets", MyFlags=<optimized out>) at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/sql/mysqld.cc:2293 #2 0x0000000000f78260 in my_error (nr=1158, MyFlags=0) at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/mysys/my_error.c:222 #3 0x0000000000c93b6c in net_read_raw_loop (net=0x7f6328836740, count=4) at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/sql/net_serv.cc:742 #4 0x0000000000c94508 in net_read_packet_header (net=0x7f6328836740) at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/sql/net_serv.cc:794 #5 net_read_packet (net=0x7f6328836740, complen=0x7f63288366b8) at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/sql/net_serv.cc:854 #6 0x0000000000c9468c in my_net_read (net=0x7f6328836740) at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/sql/net_serv.cc:931 #7 0x00007f634bf06377 in Ack_receiver::run (this=0x7f634c10aac0 <ack_receiver>) at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/plugin/semisync/semisync_master_ack_receiver.cc:279 #8 0x00007f634bf06699 in ack_receive_handler (arg=0x7f634c10aac0 <ack_receiver>) at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/plugin/semisync/semisync_master_ack_receiver.cc:42 #9 0x000000000143c2a4 in pfs_spawn_thread (arg=0x7f631801ad30) at /var/lib/pb2/sb_1-6473437-1647886122.65/mysql-5.7.38/storage/perfschema/pfs.cc:2197 #10 0x00007f63a335fea5 in start_thread () from /lib64/libpthread.so.0 #11 0x00007f63a1e1796d in clone () from /lib64/libc.so.6
从堆栈信息也是能看出来主库ack_receiver的时候(my_net_read没收到信息), 然后就打印error信息了.
我们这里还能看到报错码1158, 但是error log里面却没得这部分了… -_- 有兴趣的自己去研究吧.
