Bug #71988 page_cleaner: aggressive background flushing
Submitted: 9 Mar 2014 21:32 Modified: 26 Mar 2014 21:40
Reporter: Inaam Rana (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.6 OS:Any
Assigned to: Assigned Account CPU Architecture:Any

[9 Mar 2014 21:32] Inaam Rana
Description:
I think I might have a plausible explanation of undesirable background flushing in the page_cleaner.

Consider a steady state on the server where:
* The workload is light or moderate (not relevant for heavy workloads)
* buffer pool is all filled up
* Number of dirty pages is very low compared to the buffer pool size

Following is code from MySQL-5.6.16, buf/buf0flu.cc:

2406         while (srv_shutdown_state == SRV_SHUTDOWN_NONE) {
2407
2408                 /* The page_cleaner skips sleep if the server is
2409                 idle and there are no pending IOs in the buffer pool
2410                 and there is work to do. */
2411                 if (srv_check_activity(last_activity)
2412                     || buf_get_n_pending_read_ios()
2413                     || n_flushed == 0) {
2414                         page_cleaner_sleep_if_needed(next_loop_time);
2415                 }
2416
2417                 next_loop_time = ut_time_ms() + 1000;
2418
2419                 if (srv_check_activity(last_activity)) {
2420                         last_activity = srv_get_activity_count();
2421
2422                         /* Flush pages from end of LRU if required */
2423                         n_flushed = buf_flush_LRU_tail();
2424
2425                         /* Flush pages from flush_list if required */
2426                         n_flushed += page_cleaner_flush_pages_if_needed();
2427                 } else {
2428                         n_flushed = page_cleaner_do_flush_batch(
2429                                                         PCT_IO(100),
2430                                                         LSN_MAX);

Things to watch out for:
* activity_count = roughly any DML operations within server since last call = srv_check_activity(last_activity)
* n_flushed = Whether or not we did any work in the last iteration

iteration 1:
Assume: activity_count > 0,
n_flushed not relevant right now
1) we sleep at if on 2411
1) we go into the if on 2419
2) update activity_count
3) Do LRU flush. Now LRU flush can cause flushing of pages (expensive) or eviction of pages (lightweight). As we assumed few dirty pages it is likely that we did only eviction which was quick enough to return before any server activity happened. Key result, n_flushed > 0 and activity_count = unchanged
4) Call adaptive flushing on 2426 but that returned right away because too few dirty pages and heuristics tell us no need to flush anything.

iteration 2:
We now have:
activity_count = 0
n_flushed > 0

1) if conditions on 2411 are not met hence we skip sleep!
2) if condition on 2419 not met, we branch to else
3) we do a full fledged background batch assuming that server has been idle for one second. The reality, however, is that we didn't sleep for one second.
4) Since actual flushing will eat up quite a bit of time it is likely that activity_count gets incremented during this. We now have activity_count > 0 and n_flushed > 0.

iteration 3:
activity_count > 0
n_flushed > 0 (not relevant though)

goto iteration 1

Net result will be we sleep in one iteration, we skip sleep for other iteration and we end up flushing PCT_IO(100) pages in background every second though we have server activity happening in any given second.

How to repeat:
see the code.

Suggested fix:
The fix that I am inclined to suggest is to completely get away with 'sleep-if-this-or-that' condition. Now that we have a reworked adaptive flushing algorithm in 5.6 we should be able to do whatever is required of us in single step. That means once we go through the hoops of LRU and adaptive flushing we should sleep if there is time left since last wakeup call. We don't have to tie our sleep with whether or not we did work in last iteration or whether or not server as active.
[10 Mar 2014 5:14] MySQL Verification Team
Hello Inaam,

Thank you for the bug report.

Thanks,
Umesh
[10 Mar 2014 12:51] Laurynas Biveinis
Related: bug 70500, and https://bugs.launchpad.net/percona-server/+bug/1238039 ("
Spurious innodb_io_capacity-sized flush list flushes on a loaded server"), which deals with the same end result, but was never reported for Oracle MySQL, because of different sleep heuristics (our way to bring back "furious flushing" for 5.6, see bug 68481).
[10 Mar 2014 12:57] Laurynas Biveinis
Since we keep 'sleep-if-this-or-that', our fix tracks the time of the last server activity read, and assumes inactive server only if no activity bump in at least one second. Can submit it by OCA if you wish.
[25 Mar 2014 13:53] Inaam Rana
One way to deal with this is to make background flushing more laid back. For example, do background flushing if server has been idle for, say, 10 seconds. Background flushing is not an urgent task and in some cases it may even not be a desirable task. We don't need to rush to background flushing whenever we notice a glimpse of idleness in server.
[26 Mar 2014 21:40] Inaam Rana
related bug#72137
[30 Oct 2014 8:46] Laurynas Biveinis
By code analysis 5.7.5 seems to be affected the same.
[30 Oct 2014 9:18] Laurynas Biveinis
No, it is not, sorry. New activity value is saved only if ret_sleep == OS_SYNC_TIME_EXCEEDED, meaning at least one second has passed since the last save, which handles the quick LRU evicting iterations fine.

If I'm not wrong then this bug is fixed in 5.7.