From 934b2d605ec15322f2a5052ebb90e116bce8aaaa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marko=20M=C3=A4kel=C3=A4?= Date: Tue, 22 Feb 2022 18:56:21 +0200 Subject: [PATCH] MDEV-27917 Some redo log diagnostics is always reported as 0 The InnoDB monitor counter log_sys.n_log_ios was almost removed in commit 685d958e38b825ad9829be311f26729cccf37c46 (MDEV-14425). This counter was rather meaningless already since commit 30ea63b7d2077883713e63cbf4e661ba0345bf68 introduced a redo log group commit mechanism, and on the persistent memory interface there are no file system calls that could be counted. The only case when log_sys.n_log_ios was updated is when the log file was being read during crash recovery. Some related output in log_print() as well as the information_schema.innodb_metrics counter log_num_log_io are best removed. --- .../r/innodb_skip_innodb_is_tables.result | 1 - mysql-test/suite/innodb/r/monitor.result | 1 - storage/innobase/include/log0log.h | 15 ------- storage/innobase/include/srv0mon.h | 1 - storage/innobase/log/log0log.cc | 39 ------------------- storage/innobase/log/log0recv.cc | 1 - storage/innobase/srv/srv0mon.cc | 9 ----- storage/innobase/srv/srv0srv.cc | 2 - .../r/innodb_i_s_tables_disabled.result | 1 - 9 files changed, 70 deletions(-) diff --git a/mysql-test/suite/innodb/r/innodb_skip_innodb_is_tables.result b/mysql-test/suite/innodb/r/innodb_skip_innodb_is_tables.result index 2bbe990d7f1..5e4946bf793 100644 --- a/mysql-test/suite/innodb/r/innodb_skip_innodb_is_tables.result +++ b/mysql-test/suite/innodb/r/innodb_skip_innodb_is_tables.result @@ -180,7 +180,6 @@ log_lsn_current recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 log_lsn_checkpoint_age recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 value Current LSN value minus LSN at last checkpoint log_lsn_buf_pool_oldest recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 value The oldest modified block LSN in the buffer pool log_max_modified_age_async recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 value Maximum LSN difference; when exceeded, start asynchronous preflush -log_num_log_io recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 value Number of log I/Os log_waits recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 status_counter Number of log waits due to small log buffer (innodb_log_waits) log_write_requests recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 status_counter Number of log write requests (innodb_log_write_requests) log_writes recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 status_counter Number of log writes (innodb_log_writes) diff --git a/mysql-test/suite/innodb/r/monitor.result b/mysql-test/suite/innodb/r/monitor.result index 0424ea51238..ce10aceb51b 100644 --- a/mysql-test/suite/innodb/r/monitor.result +++ b/mysql-test/suite/innodb/r/monitor.result @@ -146,7 +146,6 @@ log_lsn_current disabled log_lsn_checkpoint_age disabled log_lsn_buf_pool_oldest disabled log_max_modified_age_async disabled -log_num_log_io disabled log_waits disabled log_write_requests disabled log_writes disabled diff --git a/storage/innobase/include/log0log.h b/storage/innobase/include/log0log.h index e2a8fbf7605..7f8526d1523 100644 --- a/storage/innobase/include/log0log.h +++ b/storage/innobase/include/log0log.h @@ -99,11 +99,6 @@ void log_print( /*======*/ FILE* file); /*!< in: file where to print */ -/**********************************************************************//** -Refreshes the statistics used to print per-second averages. */ -void -log_refresh_stats(void); -/*===================*/ /** Offsets of a log file header */ /* @{ */ @@ -240,16 +235,6 @@ public: /** Log file */ log_file_t log; - /** The fields involved in the log buffer flush @{ */ - - ulint n_log_ios; /*!< number of log i/os initiated thus - far */ - ulint n_log_ios_old; /*!< number of log i/o's at the - previous printout */ - time_t last_printout_time;/*!< when log_print was last time - called */ - /* @} */ - /** Fields involved in checkpoints @{ */ lsn_t log_capacity; /*!< capacity of the log; if the checkpoint age exceeds this, it is diff --git a/storage/innobase/include/srv0mon.h b/storage/innobase/include/srv0mon.h index af990e52e46..3fc9c743cc6 100644 --- a/storage/innobase/include/srv0mon.h +++ b/storage/innobase/include/srv0mon.h @@ -304,7 +304,6 @@ enum monitor_id_t { MONITOR_LSN_CHECKPOINT_AGE, MONITOR_OVLD_BUF_OLDEST_LSN, MONITOR_OVLD_MAX_AGE_ASYNC, - MONITOR_LOG_IO, MONITOR_OVLD_LOG_WAITS, MONITOR_OVLD_LOG_WRITE_REQUEST, MONITOR_OVLD_LOG_WRITES, diff --git a/storage/innobase/log/log0log.cc b/storage/innobase/log/log0log.cc index 35a3ceadbdd..263be97efd8 100644 --- a/storage/innobase/log/log0log.cc +++ b/storage/innobase/log/log0log.cc @@ -126,12 +126,7 @@ void log_t::create() max_buf_free= buf_size / LOG_BUF_FLUSH_RATIO - LOG_BUF_FLUSH_MARGIN; set_check_flush_or_checkpoint(); - n_log_ios_old= n_log_ios; - last_printout_time= time(NULL); - last_checkpoint_lsn= FIRST_LSN; - n_log_ios= 0; - n_log_ios_old= 0; log_capacity= 0; max_modified_age_async= 0; max_checkpoint_age= 0; @@ -1007,9 +1002,6 @@ log_print( /*======*/ FILE* file) /*!< in: file where to print */ { - double time_elapsed; - time_t current_time; - log_sys.latch.rd_lock(SRW_LOCK_CALL); const lsn_t lsn= log_sys.get_lsn(); @@ -1027,40 +1019,9 @@ log_print( pages_flushed, lsn_t{log_sys.last_checkpoint_lsn}); - current_time = time(NULL); - - time_elapsed = difftime(current_time, - log_sys.last_printout_time); - - if (time_elapsed <= 0) { - time_elapsed = 1; - } - - fprintf(file, - ULINTPF " pending chkp writes\n" - ULINTPF " log i/o's done, %.2f log i/o's/second\n", - log_sys.n_pending_checkpoint_writes, - log_sys.n_log_ios, - static_cast( - log_sys.n_log_ios - log_sys.n_log_ios_old) - / time_elapsed); - - log_sys.n_log_ios_old = log_sys.n_log_ios; - log_sys.last_printout_time = current_time; - log_sys.latch.rd_unlock(); } -/**********************************************************************//** -Refreshes the statistics used to print per-second averages. */ -void -log_refresh_stats(void) -/*===================*/ -{ - log_sys.n_log_ios_old = log_sys.n_log_ios; - log_sys.last_printout_time = time(NULL); -} - /** Shut down the redo log subsystem. */ void log_t::close() { diff --git a/storage/innobase/log/log0recv.cc b/storage/innobase/log/log0recv.cc index 74027cc8423..e3e27d02969 100644 --- a/storage/innobase/log/log0recv.cc +++ b/storage/innobase/log/log0recv.cc @@ -3546,7 +3546,6 @@ static bool recv_scan_log(bool last_phase) if (source_offset + size > log_sys.file_size) size= static_cast(log_sys.file_size - source_offset); - log_sys.n_log_ios++; if (dberr_t err= log_sys.log.read(source_offset, {log_sys.buf + recv_sys.len, size})) { diff --git a/storage/innobase/srv/srv0mon.cc b/storage/innobase/srv/srv0mon.cc index 520ff7adff5..cd576e86da9 100644 --- a/storage/innobase/srv/srv0mon.cc +++ b/storage/innobase/srv/srv0mon.cc @@ -800,11 +800,6 @@ static monitor_info_t innodb_counter_info[] = MONITOR_EXISTING | MONITOR_DISPLAY_CURRENT), MONITOR_DEFAULT_START, MONITOR_OVLD_MAX_AGE_ASYNC}, - {"log_num_log_io", "recovery", "Number of log I/Os", - static_cast( - MONITOR_EXISTING | MONITOR_DISPLAY_CURRENT), - MONITOR_DEFAULT_START, MONITOR_LOG_IO}, - {"log_waits", "recovery", "Number of log waits due to small log buffer (innodb_log_waits)", static_cast( @@ -1706,10 +1701,6 @@ srv_mon_process_existing_counter( value = log_sys.get_lsn(); break; - case MONITOR_LOG_IO: - value = log_sys.n_log_ios; - break; - case MONITOR_OVLD_CHECKPOINTS: value = log_sys.next_checkpoint_no; break; diff --git a/storage/innobase/srv/srv0srv.cc b/storage/innobase/srv/srv0srv.cc index 29a6316fae9..d9b2af54a32 100644 --- a/storage/innobase/srv/srv0srv.cc +++ b/storage/innobase/srv/srv0srv.cc @@ -711,8 +711,6 @@ static void srv_refresh_innodb_monitor_stats(time_t current_time) btr_cur_n_non_sea_old = btr_cur_n_non_sea; #endif /* BTR_CUR_HASH_ADAPT */ - log_refresh_stats(); - buf_refresh_io_stats(); srv_n_rows_inserted_old = srv_stats.n_rows_inserted; diff --git a/storage/rocksdb/mysql-test/rocksdb/r/innodb_i_s_tables_disabled.result b/storage/rocksdb/mysql-test/rocksdb/r/innodb_i_s_tables_disabled.result index 505f394876c..e12f9344ce9 100644 --- a/storage/rocksdb/mysql-test/rocksdb/r/innodb_i_s_tables_disabled.result +++ b/storage/rocksdb/mysql-test/rocksdb/r/innodb_i_s_tables_disabled.result @@ -162,7 +162,6 @@ log_lsn_current recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 log_lsn_checkpoint_age recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 value Current LSN value minus LSN at last checkpoint log_lsn_buf_pool_oldest recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 value The oldest modified block LSN in the buffer pool log_max_modified_age_async recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 value Maximum LSN difference; when exceeded, start asynchronous preflush -log_num_log_io recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 value Number of log I/Os log_waits recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 status_counter Number of log waits due to small log buffer (innodb_log_waits) log_write_requests recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 status_counter Number of log write requests (innodb_log_write_requests) log_writes recovery 0 NULL NULL NULL 0 NULL NULL NULL NULL NULL NULL NULL 0 status_counter Number of log writes (innodb_log_writes)