3

Here is the MySQL info:

mysql> show variables like 'innodb%flush%log%';
+--------------------------------+-------+
| Variable_name                  | Value |
+--------------------------------+-------+
| innodb_flush_log_at_timeout    | 2700  |
| innodb_flush_log_at_trx_commit | 0     |
+--------------------------------+-------+
2 rows in set (0.00 sec)

mysql> select version()
    -> ;
+-----------+
| version() |
+-----------+
| 5.6.14    |
+-----------+
1 row in set (0.00 sec)

Then I insert something:

mysql> insert into x select now();
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0

mysql> select * from x;
+---------------------+
| now()               |
+---------------------+
| 2014-08-20 18:59:09 |
+---------------------+
1 row in set (0.00 sec)

mysql>

I immediately kill mysqld to make it crash:

:/data/mysql_dbf # killall -9 mysqld
:/data/mysql_dbf # /usr/local/bin/mysqld_safe: line 166: 28859 Killed                  nohup /usr/local/mysql/bin/mysqld --basedir=/usr/local/mysql --datadir=/data/mysql_dbf --plugin-dir=/usr/local/mysql/lib/plugin --user=mysql --log-error=/data/mysql_dbf/.err --pid-file=/data/mysql_dbf/.pid < /dev/null >> /data/mysql_dbf/.err 2>&1 >> /data/mysql_dbf/.err 2>&1 >> /data/mysql_dbf/.err 2>&1 >> /data/mysql_dbf/.err 2>&1 >> /data/mysql_dbf/.err 2>&1 >> /data/mysql_dbf/.err 2>&1 >> /data/mysql_dbf/.err 2>&1
140820 18:59:22 mysqld_safe Number of processes running now: 0
140820 18:59:22 mysqld_safe mysqld restarted

Then I check it again:

mysql> select * from x;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> select * from x;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    1
Current database: test

+---------------------+
| now()               |
+---------------------+
| 2014-08-20 18:59:09 |
+---------------------+
1 row in set (0.02 sec)

No data was lost. Can someone explain why?

Edit 1

With the help of @jynus, we are going to test for sufficient data.

i=0;
while true;
do ./bin/mysql --defaults-file=my.cnf -umysql -pmysql test -e "insert into x select now()";
    if [ $i -eq 100 ];
    then killall -9 mysqld;
        sleep 3;
    fi;
    ./bin/mysql --defaults-file=my.cnf -umysql -pmysql test -e "select count(*) from x" >> trace.log;
    if [ $i -gt 110 ];
    then break;
    fi;
    ((++i));
done

And the output shows we are facing data loss

......
count(*)
99
count(*)
100
count(*)
101
count(*)
102
count(*)
103
count(*)
3
count(*)
4
count(*)
5
count(*)
6
......

1 Answer 1

7

With innodb_flush_log_at_trx_commit = 0 there is not a guaranteed data loss (such an option would be nonsense), but a non-guarantee that data will not be lost in the last innodb_flush_log_at_timeout seconds (between fsyncs).

To test how much data you are losing, you need to write several times per second and then kill mysqld just after some of those writes have been successfully committed in an automatic way. You will suffer between 0 and innodb_flush_log_at_timeout(maybe a bit more than that; innodb_flush_log_at_timeout is by default 1 second, 2700 in your example) seconds of lost transactions due to changing the durability options.

By the way, some of us prefer innodb_flush_log_at_trx_commit = 2 as it provides the same performance and durability promises, but it does the buffering at OS level, maybe minimising data loss in case of a MySQL-only crash.

Independently of the durability, you will never get corruption or end up in an inconsistent state thanks to the REDO log and the double write buffer, unless there is a hardware fault.

Edit: It seems that the why is not yet clear. Let me elaborate:

Every innodb_flush_log_at_timeout seconds mysql calls the OS function fsync(), which -except on those operating systems/virtual machines where it is implemented as a null operation (another funny story for other time)- it should makes sure that a particular file descriptor (the one for the transaction log) has everything which has been written to not on memory (the filesystem cache) but really on disk (or on hardware cache).

That doesn't take from MySQL or the operating system from writing really from writing to disk from the log buffer or the operating system cache from time to time (actually, they will want to do that to avoid I/O queuing). So fsync is only a limitation in terms of "everything should be written now", the log is actually written when IO is available (even if the transaction has not been commited!) to make everything more performant. If you want your data not to be durable, either do not commit your transactions (not recommended) or use a non-durable, memory-only engine, like HEAP.

10
  • Hi Jynus, I think the default flush timeout is 1 second, but I have changed the value to 2700, check the post, "kill mysqld immediately" means I did it before timeout which is 2700 triggered
    – http8086
    Commented Aug 20, 2014 at 11:54
  • @hylepo I didn't saw that, but the answer still stands. Between fsyncs, it is the OS that decides if it really goes to the disk or not, you have too little load to test it for real.
    – jynus
    Commented Aug 20, 2014 at 11:57
  • Hi Jynus, I think you can check innodb_flush_log_at_timeout | 2700, mysql documentation says this one controls the flush occasion.
    – http8086
    Commented Aug 20, 2014 at 12:00
  • @hylepo I have modified my answer to include innodb_flush_log_at_timeout the answer is equivalent, please reread it.
    – jynus
    Commented Aug 20, 2014 at 12:02
  • Your file system might be coming into play - check out this interesting blog post - basically (as @jynus points out) there's a lot going on between MySQL, the file system and the OS at any given time.
    – Vérace
    Commented Aug 20, 2014 at 12:10

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.