Bug #67826 MySQL does not do background log flushing during the period when there is no use
Submitted: 6 Dec 2012 16:38 Modified: 7 Jan 2013 19:33
Reporter: Ovais Tariq Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:5.5.28 OS:Linux
Assigned to: CPU Architecture:Any

[6 Dec 2012 16:38] Ovais Tariq
Description:
When there is no activity from user threads then InnoDB does not do background flushing of log. This goes against fuzzy checkpointing behaviour and this documentation in the code:

srv0srv.c:
/* If i/os during the 10 second period were less than 200% of
        capacity, we assume that there is free disk i/o capacity
        available, and it makes sense to flush srv_io_capacity pages.

        Note that this is done regardless of the fraction of dirty
        pages relative to the max requested by the user. The one second
        loop above requests writes for that case. The writes done here
        are not required, and may be disabled. */

This can potentially mean that there can be stalls caused later on, which could have been avoided had background flushing being done even when there was no user activity.

I am seeing this behaviour on a server that has 340K dirty_pages:
mysql> show status like 'innodb_buffer_pool_pages%';
+-----------------------------------------+---------+
| Variable_name | Value |
+-----------------------------------------+---------+
| Innodb_buffer_pool_pages_data | 967406 |
| Innodb_buffer_pool_pages_dirty | 339275 |
| Innodb_buffer_pool_pages_flushed | 1376602 |
| Innodb_buffer_pool_pages_LRU_flushed | 0 |
| Innodb_buffer_pool_pages_free | 301309 |
| Innodb_buffer_pool_pages_made_not_young | 0 |
| Innodb_buffer_pool_pages_made_young | 1394 |
| Innodb_buffer_pool_pages_misc | 42004 |
| Innodb_buffer_pool_pages_old | 357088 |
| Innodb_buffer_pool_pages_total | 1310719 |
+-----------------------------------------+---------+

And the checkpoint age is nearly 70% of the combined log file size:
innodb_log_file_size=2G=2G
innodb_log_files_in_group=2

---
LOG
---
Log sequence number 55314538017
Log flushed up to 55314538017
Last checkpoint at 52270114659
Max checkpoint age 3478212404
Checkpoint age target 3369518267
Modified age 3039401137
Checkpoint age 3044423358

You can see that checkpoint age is nearly 2.8G.

The main thread is constantly in state but there is no flushing happening:
Main thread process no. 21389, id 140591422957312, state: flushing log

The server is completely idle, no IO etc.

How to repeat:
Start mysqld as follows:
mysqld --query_cache_size=0 --query_cache_type=0 --innodb_file_per_table=1 --innodb_log_file_size=2G --innodb_buffer_pool_size=20G --innodb_flush_method=O_DIRECT --innodb_flush_log_at_trx_commit=0

Prepare sysbench tables:
sysbench --test=./tests/db/oltp.lua --oltp-tables-count=8 --oltp-table-size=8000000 --mysql-table-engine=innodb --mysql-db=test prepare

Warmup the bufferpool:
for t in $(seq 1 8); do mysql -A test -e "select * from sbtest${t}" > /dev/null; done

Do multiple runs of sysbench as follows:
sysbench --test=/work/binaries/sysbench-0.5/sysbench/tests/db/oltp.lua --oltp-tables-count=8 --oltp-table-size=8000000 --mysql-table-engine=innodb --mysql-db=test --max-time=930 --num-threads=8 --max-requests=0 --report-interval=1 run

Once the sysbench run finishes, do nothing and wait.
[7 Dec 2012 18:43] Sveta Smirnova
Thank you for the report.

I can not repeat described behavior: InnoDB flushes pages in my case.

I also noticed status variable Innodb_buffer_pool_pages_LRU_flushed. Do you use Percona server? If yes, please try with Oracle MySQL distribution available at dev.mysql.com/downloads and inform us if problem still exists.
[7 Dec 2012 19:27] Ovais Tariq
Sveta,

Indeed I tried with Percona Server, but the part of logic that handles when to do background flushing is the same in both Percona Server and MySQL. I will repeat with MySQL server anyhow.
[7 Dec 2012 19:33] Sveta Smirnova
Ovais,

thank you for the feedback.

But comments says flushing would be done. Or I did not understand description of this bug report?

Anyway, please, try with Oracle MySQL and if problem still exists, send us your configuration file and output of SHOW STATUS and SHOW ENGINE INNODB STATUS taken right after test and after some time, so I am sure we are speaking about the same problem.
[8 Jan 2013 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".