Commit d1ab8903 authored by Marko Mäkelä's avatar Marko Mäkelä

MDEV-13670/MDEV-14550 Error log flood : "InnoDB: page_cleaner: 1000ms...

MDEV-13670/MDEV-14550 Error log flood :  "InnoDB: page_cleaner: 1000ms intended loop took N ms. The settings might not be optimal."

Silence the error log output that was introduced in MySQL 5.7
(MariaDB 10.2.2) if log_warnings=2 or less.

We should still figure out what these messages really indicate
and how to solve the problems.

pc_sleep_if_needed(): Add a parameter for the current time,
so that there will be fewer successive calls to ut_time_ms()
with no I/O between them.

buf_flush_page_cleaner_coordinator(): Exit the first loop
whenever shutdown has been requested. At the start of the loop,
call ut_time_ms() only once. Do not display the message if
log_warnings=2 or less.
parent 8be75480
...@@ -28,6 +28,7 @@ Created 11/11/1995 Heikki Tuuri ...@@ -28,6 +28,7 @@ Created 11/11/1995 Heikki Tuuri
#include "ha_prototypes.h" #include "ha_prototypes.h"
#include <mysql/service_thd_wait.h> #include <mysql/service_thd_wait.h>
#include <my_dbug.h> #include <my_dbug.h>
#include <sql_class.h>
#include "buf0flu.h" #include "buf0flu.h"
#include "buf0buf.h" #include "buf0buf.h"
...@@ -2690,21 +2691,21 @@ than a second ...@@ -2690,21 +2691,21 @@ than a second
@retval OS_SYNC_TIME_EXCEEDED if timeout was exceeded @retval OS_SYNC_TIME_EXCEEDED if timeout was exceeded
@param next_loop_time time when next loop iteration should start @param next_loop_time time when next loop iteration should start
@param sig_count zero or the value returned by previous call of @param sig_count zero or the value returned by previous call of
os_event_reset() */ os_event_reset()
@param cur_time current time as in ut_time_ms() */
static static
ulint ulint
pc_sleep_if_needed( pc_sleep_if_needed(
/*===============*/ /*===============*/
ulint next_loop_time, ulint next_loop_time,
int64_t sig_count) int64_t sig_count,
ulint cur_time)
{ {
/* No sleep if we are cleaning the buffer pool during the shutdown /* No sleep if we are cleaning the buffer pool during the shutdown
with everything else finished */ with everything else finished */
if (srv_shutdown_state == SRV_SHUTDOWN_FLUSH_PHASE) if (srv_shutdown_state == SRV_SHUTDOWN_FLUSH_PHASE)
return OS_SYNC_TIME_EXCEEDED; return OS_SYNC_TIME_EXCEEDED;
ulint cur_time = ut_time_ms();
if (next_loop_time > cur_time) { if (next_loop_time > cur_time) {
/* Get sleep interval in micro seconds. We use /* Get sleep interval in micro seconds. We use
ut_min() to avoid long sleep in case of wrap around. */ ut_min() to avoid long sleep in case of wrap around. */
...@@ -3200,6 +3201,7 @@ DECLARE_THREAD(buf_flush_page_cleaner_coordinator)(void*) ...@@ -3200,6 +3201,7 @@ DECLARE_THREAD(buf_flush_page_cleaner_coordinator)(void*)
ulint last_pages = 0; ulint last_pages = 0;
while (srv_shutdown_state == SRV_SHUTDOWN_NONE) { while (srv_shutdown_state == SRV_SHUTDOWN_NONE) {
ulint curr_time = ut_time_ms();
/* The page_cleaner skips sleep if the server is /* The page_cleaner skips sleep if the server is
idle and there are no pending IOs in the buffer pool idle and there are no pending IOs in the buffer pool
...@@ -3209,23 +3211,22 @@ DECLARE_THREAD(buf_flush_page_cleaner_coordinator)(void*) ...@@ -3209,23 +3211,22 @@ DECLARE_THREAD(buf_flush_page_cleaner_coordinator)(void*)
|| n_flushed == 0) { || n_flushed == 0) {
ret_sleep = pc_sleep_if_needed( ret_sleep = pc_sleep_if_needed(
next_loop_time, sig_count); next_loop_time, sig_count, curr_time);
} else if (curr_time > next_loop_time) {
if (srv_shutdown_state != SRV_SHUTDOWN_NONE) {
break;
}
} else if (ut_time_ms() > next_loop_time) {
ret_sleep = OS_SYNC_TIME_EXCEEDED; ret_sleep = OS_SYNC_TIME_EXCEEDED;
} else { } else {
ret_sleep = 0; ret_sleep = 0;
} }
if (srv_shutdown_state != SRV_SHUTDOWN_NONE) {
break;
}
sig_count = os_event_reset(buf_flush_event); sig_count = os_event_reset(buf_flush_event);
if (ret_sleep == OS_SYNC_TIME_EXCEEDED) { if (ret_sleep == OS_SYNC_TIME_EXCEEDED) {
ulint curr_time = ut_time_ms(); if (global_system_variables.log_warnings > 2
&& curr_time > next_loop_time + 3000
if (curr_time > next_loop_time + 3000
&& !(test_flags & TEST_SIGINT)) { && !(test_flags & TEST_SIGINT)) {
if (warn_count == 0) { if (warn_count == 0) {
ib::info() << "page_cleaner: 1000ms" ib::info() << "page_cleaner: 1000ms"
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment