- 1. 背景
- 2. 疑点
- 3. 问题分析
- 4. 问题定位
- 5. checking permissions的疑惑
- 6. 探索优化思路
- 7. 补充：关于几个timeout参数生效点
1. 背景
行内数据库备份在使用某备份软件，使用的数据库版本MySQL 8.0社区版，全备使用mysqldump进行，DBA早上巡检发现有一套数据库全备份失败，心里一疙瘩怎么回事呢？来看看如下报错
[mysqldump: Error: 'Lost connection to MySQL server during query' when trying to dump tablespaces mysqldump: couldn't execute 'SHOW VARIABLES LIKE 'ndbinfo'\_version' MySQL server has gone away (2006)]
肯定有同学有疑问？
- 为什么mysqldump会出现丢失连接？
- 为什么不使用xtrabackup呢？这需要另外章节来阐述了。
2. 疑点
为什么mysqldump会出现丢失连接？带着该问题进行以下分析：
- 1.检查备份软件工具负载情况
- 2.检查数据库中错误日志
- 3.数据库的负载情况
3. 问题分析
3.1 备份软件是否存在高负载、排队或超时配置导致响应超时？
对整个备份系统进行排查，虽然备份系统任务多，但并没有出现性能瓶颈导致数据库备份时超时，备份软件也没有设置备份超时时间自动断开的相关配置
3.2 检查数据库错误日志
2020-10-26T01:31:14.465387+08:00 149718 [Note] [MY-010914] [Server] Aborted connection 149718 to db: 'unconnected' user: 'root' host: 'localhost' (Got an error reading communication packets).
通过数据库错误日志发现同备份软件报错一样，对于这个错误，MOS上有一个比较好的解释如下：
不管怎么样我们后面先来看备份软件触发了些什么语句。
3.3 检查数据库负载情况，备份期间cpu、io均比较正常
4. 问题定位
从上述检查来看，报错处是Got an error reading而不是timeout，关于timeout的触发方式我们最后总结。首先从备份软件架构，备份软件在数据库中部署agent，所以连接属于交互式连接受到参数interactive_timeout的影响，那么为什么导致的超时丢失连接的呢？我们可以进行问题复现，使用备份软件对数据库发起重新备份，对数据库进行监控
4.1 通过备份软件发起备份，可以看到会发起4个本地备份连接，3个处于sleep状态，一个线程处于执行状态下，如下：
SQL语句：
SELECT LOGFILE_GROUP_NAME, FILE_NAME, TOTAL_EXTENTS, INITIAL_SIZE, ENGINE, EXTRA FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'UNDO LOG' AND FILE_NAME IS NOT NULL AND LOGFILE_GROUP_NAME IS NOT NULL AND LOGFILE_GROUP_NAME IN (SELECT DISTINCT LOGFILE_GROUP_NAME FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'DATAFILE' AND TABLESPACE_NAME IN (SELECT DISTINCT TABLESPACE_NAME FROM INFORMATION_SCHEMA.PARTITIONS WHERE TABLE_SCHEMA IN ('xxx'))) GROUP BY LOGFILE_GROUP_NAME, FILE_NAME, ENGINE, TOTAL_EXTENTS, INITIAL_SIZE ORDER BY LOGFILE_GROUP_NAME
注意这里的状态为checking permissions，并且这个语句长期处于这个状态。我们以前理解的这个就是在鉴权，我们一般的认知是下面一些顺序：
- starting:lex+yacc 语法语义解析,得到解析树
- checking permissions：根据解析后的解析树，对需要访问的表进行鉴权
- opening tables：打开访问的表，建立内部访问表的属性（表和字段信息），建立好和Innodb的关联，同时加上表锁（MDL LOCK）
- optimizing/statistics/preparing：这3个状态处于语句的物理和逻辑优化阶段，之后建立好执行计划
- Sending data（ 8.0为executing）：select语句MySQL层和Innodb层进行数据交互，遇到这个状态通常考虑语句是否足够优化
- Update：同上insert语句，如果遇到行锁会处于这个状态下。
- Updating：同上delete/update语句，如果遇到行锁会处于这个状态下。
- query end（waiting for handler commit 8.0）：语句的提交过程包含在这个状态下，遇到这个问题，主要考虑是否大事务的存在。
- closing tables：和opening tables对应，释放表的内部访问版本放入缓存共下次使用，同时也包含语句的错误回滚也在这个状态下
- freeing items：释放解析树
我们能够看到，鉴权实际上在比较靠前的位置，是不是说这里语句还没真正的开始执行呢？我们先放一放。
4.2 通过执行show processlist发现上述SQL一直处于运行状态，于是终止备份，手工运行该SQL
由此可以推测发现，备份软件在发起备份时会发起4个连接，而其中一个连接执行SQL比较久，而另外3个sleep连接在超过interactive_timeout后断开，导致agent整体退出关闭所有的数据库连接，执行的SQL也终止，所以报错Got an error reading。但是奇怪的是我们在日志并没有找到Got timeout reading communication packets的日志。
