MySQL慢查询日志出现commit释疑

 

在MySQL的慢查询日志中出现只有commit，但是没有任何其它SQL的这种现象到底是一个什么情况呢？如下截图所示（没有优化前的一个Zabbix数据库）

 

 

 

其实在慢查询日志中出现commit，就是因为事务提交（commit）的时间过长。至于为什么commit的时间过长，可能有下面一些原因：

 

 

    1：磁盘IO过载时或者发生故障的时候，因此在事务完成时进行刷新（flush）需要很长时间。

 

    2：二进制日志轮换（Rotate）时，在二进制日志轮换完成之前，无法提交其他任何事务。这个会引起事务提交出现短暂的停顿/卡顿。尤其当二进制日志过大或者IO性能差的时候，这个停顿可能更长。导致commit的时间超过参数long_query_time的值。从而commit语句出现在慢查询日志。

 

    3: MySQL的系统参数innodb_flush_log_at_trx_commit、sync_binlog、max_binlog_size的设置可能会引起这种现象。但是注意，并不是说设这些参数的某个设置就一定会引起这个现象。而是说在某种取值下，在磁盘IO过载，业务暴增等一系列的综合因素影响下，会增加这种现象出现的概率。

   

       举个例子，将MySQL配置为sync_binlog = 0的情况下，这可能导致操作系统缓存整个二进制日志，甚至使用最快的磁盘。默认情况下，最大二进制日志大小为1G，如果所有日志均已缓存，则需要一些时间才能写出。 在这种情况下，没有其他事务可以提交。那么就可能出现commit耗时变长的情况。而如果将max_binlog_size设置小一些，那么就缓解这种情况。

 

    4:事务过大，导致事务提交的时候，需要等候的时间过长，尤其是发生二进制日志轮换时。

 

    下面我们构造一个这样的例子，准备测试环境，如下所示，当然这个实验受数据量，表的结构，还有MySQL的参数等很多因素的影响。下面实验仅仅说明一个超大的事务可能出现这种现象。在你的测试环境中，根据实验情况进行调整。

 

create table test(id int auto_increment primary key, name varchar(32));

delimiter &&
drop procedure if exists prc_insert;

create procedure prc_insert(in  row_cnt int)
begin
declare i int;
set i=1;
while i < row_cnt do
    insert into test(name)
    SELECT CONCAT('KERRY', cast(i as char));

    set i = i+1;
end while;
end &&
delimiter ;

 

准备好上面的表以及存储过程后，然后我们在下面事务中执行下面脚本

 

mysql> set session autocommit=0;
Query OK, 0 rows affected (0.00 sec)

mysql> call prc_insert(10000000);
Query OK, 1 row affected (7 min 1.31 sec)

mysql> commit;
Query OK, 0 rows affected (32.24 sec)

mysql>

   

在上面SQL执行的时候，使用下面脚本一直观察慢查询日志，就会发现它会出现只有commit的这种现象。如下截图所示

 

# tail -60f /mysql_data/mysql/KerryDB-slow.log

 

 

 

对于这种现象，那么有什么解决方案吗？  像我维护的zabbix系统，通过使用分区表方案后，与那些大表相关的SQL性能变好，那么就很少出现这种现象。其实除了优化SQL外，还有一些解决方案，参考下面官方文档。

 

 

Commit Takes Too Long Time (Doc ID 1925395.1)

In this Document

	Symptoms
	Cause
	Solution
	References

 

APPLIES TO:

MySQL Server - Version 4.1 and later
Information in this document applies to any platform.
To guarantee durability of data InnoDB normally flushes log changes to disk at every transaction commit. This behavior may be changed by modification of parameter innodb_flush_log_at_trx_commit , but any configuration may be dangerous depending on OS and hardware configuration.
Additionally, if binary logging is enabled, MySQL Server may flush binary logs on every transaction commit depending on configuration of sync_binlog option.

SYMPTOMS

Following symptoms may be observed:

• COMMIT query appears in slow log
• PROCESSLIST shows some connections hanging in query_end state for several seconds
• INNODB STATUS shows some transactions are commiting data
• OS monitoring tools show high average time for processing disk request operations for disk partition where InnoDB logs or binary logs are located. (E.g. "await" column in output of `iostat -x` on UNIX-like platforms).

CAUSE

Disk is overloaded or malfunctioning, so flushing on transaction completion takes long time.

SOLUTION

- Address problem to Hardware Admins to confirm whether disk partition with InnoDB logs is overloaded or malfunctioning.

- Reduce load from physical disk partition, e.g. introducing fast dedicated physical disk for InnoDB logs or moving tmpdir to dedicated disk if it causes high load, etc.

- Consider reducing durability of data by implementing less safe configuration for innodb_flush_log_at_trx_commit and sync_binlog if that suits your system (i.e. data loss is not critical or will not happen because of hardware/OS configuration: e.g. if you may rely on your OS to always shutdown properly). In case if problem happens with sync_binlog=0, consider reducing max_binlog_size to decrease amount of flushed data during binlog rotation.

 

 

 

参考资料：

 

https://support.oracle.com/epmos/faces/DocumentDisplay?_afrLoop=430623618290439&parent=EXTERNAL_SEARCH&sourceId=PROBLEM&id=1925395.1&_afrWindowMode=0&_adf.ctrl-state=1008ex2pna_4