MySQL Bugs: #72153: Documentation error.

Bug #72153	Documentation error.
Submitted:	28 Mar 2014 19:30	Modified:	31 Mar 2014 19:46
Reporter:	Martin Arrieta (OCA)	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: Documentation	Severity:	S3 (Non-critical)
Version:	5.6	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	innodb_flush_log_at_trx_commit

Description:
Wrong description for the value "2" in the innodb_flush_log_at_trx_commit configuration:

http://dev.mysql.com/doc/refman/5.6/en/innodb-parameters.html#sysvar_innodb_flush_log_at_t...

With a value of 2, any mysqld process crash can erase up to a second of transactions. The log buffer is written out to the log file at each commit. The flush to disk operation is performed on the log file once per second. Once-per-second flushing is not 100% guaranteed to happen every second, due to process scheduling issues.

If mysqld crash it will not erase any transaction, this will happen only if the host crash.

Regards, 

Martin.

How to repeat:
N/A

Suggested fix:
The 5.5 documentation is correct:

http://dev.mysql.com/doc/refman/5.5/en/innodb-parameters.html#sysvar_innodb_flush_log_at_t...

With a value of 2, an operating system crash or a power outage can erase the last second of commit records. The log buffer is written out to the file at each commit, but the flush to disk operation is not performed on it. However, the flushing on the log file takes place once per second also when the value is 2. Note that the once-per-second flushing is not 100% guaranteed to happen every second, due to process scheduling issues.

Thank you for the report.

Claim "If mysqld crash it will not erase any transaction, this will happen only if the host crash." is not correct. For example, if mysqld is killed with `kill -9` this means that not the host, but mysqld crashed. In this case it is possible that mysqld process crash can erase up to a second of transactions. Same thing could happen if mysqld process ended for other not expected reason, such as segfault of a bug.

Hi Sveta, 

So which one is correct? the documentation on 5.5 or 5.6? Is there any difference between this option on 5.5 and 5.6? 

Regards, 

Martin.

In version 5.6

It's a pretty simplistic test, but the test below involving the kill -9 seems to suggest that the 5.5 documentation is correct.  Is it just the case the wording has changed because there  are some edge cases where this is not true?

[root@mha2 ~]# cat test.sh
VAL=0
mysql -vvv -e "set global innodb_flush_log_at_trx_commit=$VAL"
mysql test -vvv -e "insert into t1 values (1,2,3), (4,5,6), (7,8,9)"
mysql test -vvv -e "select * from t1"
echo "`date '+%x %H:%M:%S:%N %Z'`: killing mysqld (`pidof mysqld`)"
kill -9 `pidof mysqld`
echo "sleeping 20 seconds for mysqld_safe"
sleep 20
echo "`date '+%x %H:%M:%S:%N %Z'`: new mysqld pid: `pidof mysqld`"
mysql test -vvv -e "select * from t1"
mysql test -vvv -e "truncate table t1;"

./test.sh
--------------
set global innodb_flush_log_at_trx_commit=0
--------------

Query OK, 0 rows affected (0.02 sec)

Bye
--------------
insert into t1 values (1,2,3), (4,5,6), (7,8,9)
--------------

Query OK, 3 rows affected (0.19 sec)
Records: 3  Duplicates: 0  Warnings: 0

Bye
--------------
select * from t1
--------------

+------+------+------+
| c1   | c2   | c3   |
+------+------+------+
|    1 |    2 |    3 |
|    4 |    5 |    6 |
|    7 |    8 |    9 |
+------+------+------+
3 rows in set (0.00 sec)

Bye
21/01/14 10:37:16:160757120 GMT: killing mysqld (806)
sleeping 20 seconds for mysqld_safe
21/01/14 10:37:36:367276984 GMT: new mysqld pid: 14690
--------------
select * from t1
--------------

Empty set (0.47 sec)

Bye
--------------
truncate table t1
--------------

Query OK, 0 rows affected (0.14 sec)

Bye

[root@mha2 ~]# cat test.sh
VAL=2
mysql -vvv -e "set global innodb_flush_log_at_trx_commit=$VAL"
mysql test -vvv -e "insert into t1 values (1,2,3), (4,5,6), (7,8,9)"
mysql test -vvv -e "select * from t1"
echo "`date '+%x %H:%M:%S:%N %Z'`: killing mysqld (`pidof mysqld`)"
kill -9 `pidof mysqld`
echo "sleeping 20 seconds for mysqld_safe"
sleep 20
echo "`date '+%x %H:%M:%S:%N %Z'`: new mysqld pid: `pidof mysqld`"
mysql test -vvv -e "select * from t1"
mysql test -vvv -e "truncate table t1;"

./test.sh
--------------
set global innodb_flush_log_at_trx_commit=2
--------------

Query OK, 0 rows affected (0.04 sec)

Bye
--------------
insert into t1 values (1,2,3), (4,5,6), (7,8,9)
--------------

Query OK, 3 rows affected (0.12 sec)
Records: 3  Duplicates: 0  Warnings: 0

Bye
--------------
select * from t1
--------------

+------+------+------+
| c1   | c2   | c3   |
+------+------+------+
|    1 |    2 |    3 |
|    4 |    5 |    6 |
|    7 |    8 |    9 |
+------+------+------+
3 rows in set (0.04 sec)

Bye
21/01/14 10:39:34:978996309 GMT: killing mysqld (14690)
sleeping 20 seconds for mysqld_safe
21/01/14 10:39:55:144376836 GMT: new mysqld pid: 28893
--------------
select * from t1
--------------

+------+------+------+
| c1   | c2   | c3   |
+------+------+------+
|    1 |    2 |    3 |
|    4 |    5 |    6 |
|    7 |    8 |    9 |
+------+------+------+
3 rows in set (0.32 sec)

Bye
--------------
truncate table t1
--------------

Query OK, 0 rows affected (0.21 sec)

Bye

Ben,

you cannot prove by issuing `kill -9` that transaction will be lost. This is just a matter of lack in this case. When you issue `kill -9` MySQL server does not perform all jobs, required for clean shutdown, therefore it cannot guarantee that all log files flushed to disk and things like this. You could get good results 1,000,000 times and break your data in 1,000,001 try. Same thing can happen in host failure: this is matter of luck.

Docs for 5.1 and all earlier versions states:
"With a value of 0, any mysqld process crash can erase the last second of transactions. With a value of 2, then only an operating system crash or a power outage can erase the last second of transactions."

Docs in 5.5 is not that specific as previous docs (the word "only" disappear), and state:
"With a value of 2, an operating system crash or a power outage can erase the last second of commit records."

So either this is a doc bug for 5.6 , or it is a doc bug for 5.5 and earlier : in any case there is one (or multiple) doc bug(s) that need to be addressed.

Did the doc lie about innodb_flush_log_trx_at_commit=2 for over a decade, or this changed in 5.6 ?