Bug #35366 setting innodb_flush_log_at_trx_commit=1 also flushes after each second

• Submitted: 18 Mar 2008 6:29
• Modified: 19 Mar 2008 9:59
• Reporter: Rizwan Maredia
• Status: Not a Bug
• Category: MySQL Server: Logging
• Severity: S3 (Non-critical)
• Version: 5.1.22
• OS: Windows
• CPU Architecture: Any
• Tags: innodb_flush_log_at_trx_commit

[18 Mar 2008 6:29] Rizwan Maredia

Description:
Setting innodb_flush_log_at_trx_commit=1 also flushes after each second. The documentation at http://dev.mysql.com/doc/refman/5.1/en/innodb-parameters.html says that:

When this value is 1 (the default), the log buffer is written out to the log file at each transaction commit and the flush to disk operation is performed on the log file.

How to repeat:
We can test this script using mysql testing framework

Sample Code: 

SET @@global.innodb_flush_log_at_trx_commit = 1;
CREATE TABLE t1(
a INT
)ENGINE=INNODB;

FLUSH LOGS;
FLUSH STATUS;

SET @@autocommit = 0;

let $value1= query_get_value(SHOW STATUS LIKE 'Innodb_log_writes', Value, 1);

START TRANSACTION;
INSERT INTO t1(a) VALUES (0);
--real_sleep 1
INSERT INTO t1(a) VALUES (1);
--real_sleep 1
COMMIT;

let $value2= query_get_value(SHOW STATUS LIKE 'Innodb_log_writes', Value, 1);
--disable_query_log
eval SET @diff =  $value2 - $value1;
--enable_query_log
SELECT @diff AS Innodb_log_writes;

Output:

SET @@global.innodb_flush_log_at_trx_commit = 1;
CREATE TABLE t1(
a INT
)ENGINE=INNODB;
FLUSH LOGS;
FLUSH STATUS;
SET @@autocommit = 0;
START TRANSACTION;
INSERT INTO t1(a) VALUES (0);
INSERT INTO t1(a) VALUES (1);
COMMIT;
SELECT @diff AS Innodb_log_writes;
Innodb_log_writes
3

Suggested fix:
The diff (innodb log writes) should have been only 1. If we remove the sleep statements then this value comes as 1.

[19 Mar 2008 9:59] Sveta Smirnova

Thank you for taking the time to write to us, but this is not a bug. Please double-check the documentation available at http://dev.mysql.com/doc/ and the instructions on
how to report a bug at http://bugs.mysql.com/how-to-report.php

According to http://dev.mysql.com/doc/refman/5.1/en/innodb-parameters.html#option_mysqld_innodb_flush_l...: "When this value is 1 (the default), the log buffer is written out to the log file at each transaction commit *and the flush to disk operation is performed on the log file.*" So it is expected to flush more often than transaction ends.

[19 Mar 2008 10:01] Sveta Smirnova

Thank you for taking the time to write to us, but this is not a bug. Please double-check the documentation available at http://dev.mysql.com/doc/ and the instructions on
how to report a bug at http://bugs.mysql.com/how-to-report.php

According to http://dev.mysql.com/doc/refman/5.1/en/innodb-parameters.html#option_mysqld_innodb_flush_l...: "When this value is 1 (the default), the log buffer is written out to the log file at each transaction commit *and the flush to disk operation is performed on the log file.*" So it is expected to flush more often than transaction ends.