乐趣区

关于crash:故障分析-MySQL-slavecompressedprotocol-导致-crash

jiezi

作者：胡呈清

爱可生 DBA 团队成员，善于故障剖析、性能优化，集体博客：https://www.jianshu.com/u/a95…，欢送探讨。

本文起源：原创投稿

* 爱可生开源社区出品，原创内容未经受权不得随便应用，转载请分割小编并注明起源。

景象

MySQL 版本：8.0.18

create.sql：zabbix 初始化脚本，蕴含建表、插入数据语句，10M+ 大小

一个新客户，部署了一套我司的数据库治理平台，接管进来一主两从实例，其中一主一从在无锡机房，为半同步复制，另一个从库在北京机房，为异步复制。当在主库上 source create.sql 时，会 crash。但没接管进平台前，不会呈现 crash。

阐明：这里提到的治理平台，不会影响了解整篇文章。

排查过程

1. 在测试环境进行复现

为不便排查，须要在可控的环境下进行复现：

  • 与客户雷同的 my.cnf
  • 雷同的 MySQL 版本
  • 雷同的复制架构
  • 执行雷同的 create.sql

的确能够稳固复现 crash，error log 如下：

2020-04-28T17:51:47.441886+08:00 0 [ERROR] [MY-013129] [Server] A message intended for a client cannot be sent there as no client-session is attached. Therefore, we’re sending the information to the error-log instead: MY-001158 – Got an error reading communication packets

09:51:47 UTC – mysqld got signal 11 ;

Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.

Thread pointer: 0x0

Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong…

stack_bottom = 0 thread_stack 0x46000

2020-04-28T17:51:47.447907+08:00 218 [ERROR] [MY-011161] [Server] Semi-sync master failed on net_flush() before waiting for slave reply.

/opt/mysql/base/8.0.18/bin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x2e) [0x1ed6cce]
/opt/mysql/base/8.0.18/bin/mysqld(handle_fatal_signal+0x323) [0xfb2d23]
/lib64/libpthread.so.0(+0xf5f0) [0x7f3d781a75f0]

The manual page at http://dev.mysql.com/doc/mysq… contains
information that should help you find out what is causing the crash.

2. 排除治理平台的影响

因为接管到治理平台才会呈现 crash，治理平台对数据库最大的操作来自于高可用组件：

  • 提早检测（写操作：每 500ms 写入一个工夫戳）
  • 状态查问（读操作）

所以接下来停用高可用、提早检测进行测试，后果如下：

初步论断：提早检测敞开后，不会 crash。

3. 提早检测影响了什么，导致 crash？

在测试过程中，发现一个与 crash 伴生的景象：

  • 不停用提早检测，会 crash，然而执行 sql 的效率高一些（毫秒级）：
mysql> source /tmp/insert.sql
Query OK, 1 row affected (0.21 sec)
Query OK, 1 row affected (0.50 sec)
Query OK, 1 row affected (0.03 sec)
Query OK, 1 row affected (0.47 sec)
Query OK, 1 row affected (0.51 sec)
Query OK, 1 row affected (0.02 sec)
  • 而停用高可用检测，不会 crash，每个 sql 执行工夫都是 1s 多一点：
mysql> source /tmp/insert.sql                            
Query OK, 1 row affected (0.01 sec)
Query OK, 1 row affected (1.01 sec)
Query OK, 1 row affected (1.01 sec)
Query OK, 1 row affected (1.00 sec)
Query OK, 1 row affected (1.01 sec)
Query OK, 1 row affected (1.01 sec)

这个看起来很像是组提交机制导致的，然而并没有配置组提交参数：

mysql> show global variables like '%group_commit%';
+-----------------------------------------+-------+
| Variable_name                           | Value |
+-----------------------------------------+-------+
| binlog_group_commit_sync_delay          | 0     |
| binlog_group_commit_sync_no_delay_count | 0     |
+-----------------------------------------+-------+
2 rows in set (0.01 sec)

敞开半同步复制后，此景象也会隐没。猜想：是半同步和组提交联合在一起触发的问题。

4. longblob 大对象

在后面的测试中，每次复现 crash，解析 binlog 查看最初一个事务都有一个共性：都是对同一张表插入数据：

### INSERT INTO `zabbix`.`images`
### SET
###   @1=108 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @2=1 /* INT meta=0 nullable=0 is_null=0 */
###   @3='Rackmountable_3U_server_3D_(64)' /* VARSTRING(256) meta=256 nullable=0 is_null=0 */
###   @4=

查看表构造，发现有 lonngblob 大对象，插入的是图片，用的是二进制格局存储：

CREATE TABLE `images` (`imageid` bigint(20) unsigned NOT NULL,
  `imagetype` int(11) NOT NULL DEFAULT '0',
  `name` varchar(64) NOT NULL DEFAULT '0',
  `image` longblob NOT NULL,
  PRIMARY KEY (`imageid`),
  UNIQUE KEY `images_1` (`name`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci;

截取出 create.sql 中的 images 表的所有 insert 语句，接下来只执行这些 insert 语句，也能复现 crash 的问题：

sed -n '2031,2217p' create.sql > insert.sql

所以 crash 的第 2 个条件是：插入 longblob 大对象

5. slave_compressed_protocol

后面的剖析曾经找到 2 个触发 crash 的条件：

  • 插入数据时，存在 longblob 大对象
  • 半同步复制，并且在 insert longblob 大对象时随同有其余内部写入流量

然而实际上用数据库治理平台自带的规范装置的同样版本的 MySQL 环境，并不能复现 crash 问题。区别在于 my.cnf 不同，所以肯定还有某个参数作为触发条件。

通过一直的测试，每次批改一批参数 （留神后面曾经定位到跟半同步复制无关，所以肯定要同时批改主、从库的参数），一直放大范畴，最终定位到是从库设置 slave_compressed_protocol=on 的影响。

从库 slave_compressed_protocol=ON 时，还会导致从库 slave io thread 始终断开与主库的连贯，并一直重连，从库 error log 报错如下：

2020-04-29T10:34:42.361584+08:00 1998 [ERROR] [MY-010557] [Repl] Error reading packet from server for channel ”: Lost connection to MySQL server during query (server_errno=2013)

2020-04-29T10:34:42.361668+08:00 1998 [Warning] [MY-010897] [Repl] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the ‘START SLAVE Syntax’ in the MySQL Manual for more information.

主库 error log 报如下错：

2020-04-29T10:23:29.480529+08:00 0 [ERROR] [MY-013129] [Server] A message intended for a client cannot be sent there as no client-session is attached. Therefore, we’re sending the information to the error-log instead: MY-001158 – Got an error reading communication packets

2020-04-29T10:23:30.330242+08:00 1950 [ERROR] [MY-011161] [Server] Semi-sync master failed on net_flush() before waiting for slave reply.

相应的，因为从库 slave io 线程一直重连，能够察看到主库的 binlog dump 线程会一直重启，有时还能够察看到 2 个：

show processlist;select sleep (1);show processlist;
....
| 2131 | admin | 172.16.21.3:37926 | NULL | Binlog Dump GTID | 3 | Waiting to finalize termination | NULL |
| 2132 | admin | 172.16.21.3:37932 | NULL | Binlog Dump GTID | 1 | Sending binlog event to slave | NULL |
....
+-----------+
| sleep (1) |
+-----------+
| 0         |
+-----------+
...
| 2132 | admin | 172.16.21.3:37932 | NULL | Binlog Dump GTID | 2 | Sending binlog event to slave | NULL |
...

与之相干的 bug：
https://jira.percona.com/brow…
https://bugs.mysql.com/bug.ph…

论断

此次 crash 的触发条件有 3 个：

  1. 插入 longblob 大对象；
  2. 半同步复制，并且在 insert longblob 大对象时随同有其余内部写流量；
  3. slave_compressed_protocol=on .

为什么接管到平台之前没有产生过 crash？

因为这个库还没上线，在执行 create.sql 时没有其余写入流量（等同于敞开提早检测的成果）。

解决方案

set slave_compressed_protocol=OFF 即可，另外官网文档也阐明不要配置此参数，后续版本将会删除此参数：

As of MySQL 8.0.18, this system variable is deprecated. It will be removed in a future MySQL version.

后续

我司研发大神前面向官网提交了一个 bug：https://bugs.mysql.com/bug.ph…。

因为一些平安问题（更具体就不能走漏了），这个 bug 被官网设置成了私密 bug，截图如下，不过截止到明天（2021.12.28）官网还是没有修复：

退出移动版