From 80ca845efbabb5c1d512ab1c7cbf8f66c758e3be Mon Sep 17 00:00:00 2001 From: Tian Xia Date: Fri, 15 May 2015 16:24:57 -0700 Subject: [PATCH] Slowing down transaction log init Summary: This diff added a configurable variable to throttle the write rate of new innodb log file initialization. Default speed is 128MB/second, and setting it to 0 will turn off the throttling. I also changed the default value of innodb_fsync_freq to 1MB to reduce system stalls caused by fsyncing large trunks of file. Test Plan: jenkins Testing command: mysqld --datadir=/tmp/log_init --skip-grant-tables --skip-networking --socket=socket --innodb-log-file-size=1G --innodb-txlog-init-rate=[rate] With --innodb-txlog-init-rate=0 (no throttling, 1GB init finished in ~49s) 2015-05-22 16:51:20 4018018 [Note] InnoDB: Setting log file ./ib_logfile101 size to 1024 MB InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000 2015-05-22 16:52:09 4018018 [Note] InnoDB: Setting log file ./ib_logfile1 size to 1024 MB InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000 With --innodb-txlog-init-rate=10485760 (10MB/s throttling, 1GB log init finished in ~103s) 2015-05-22 16:55:28 4022136 [Note] InnoDB: Setting log file ./ib_logfile101 size to 1024 MB InnoDB: log file write is throttled at 10MB/s InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000 2015-05-22 16:57:11 4022136 [Note] InnoDB: Setting log file ./ib_logfile1 size to 1024 MB InnoDB: log file write is throttled at 10MB/s InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000 Without setting the option (use default. 1GB init finished in ~50s. Note the write is already below 128MB/s, so the throttling didn't have any effect) 2015-05-22 17:18:51 4055898 [Note] InnoDB: Setting log file ./ib_logfile101 size to 1024 MB InnoDB: log file write is throttled at 128MB/s InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000 2015-05-22 17:19:41 4055898 [Note] InnoDB: Setting log file ./ib_logfile1 size to 1024 MB InnoDB: log file write is throttled at 128MB/s InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000 Reviewers: jtolmer Reviewed By: jtolmer --- .../sys_vars/r/innodb_fsync_freq_basic.result | 2 +- .../r/innodb_txlog_init_rate_basic.result | 25 +++++++++++++++++++ .../t/innodb_txlog_init_rate_basic.test | 25 +++++++++++++++++++ storage/innobase/handler/ha_innodb.cc | 15 ++++++++--- storage/innobase/include/os0file.h | 3 +++ storage/innobase/os/os0file.cc | 22 +++++++++++++--- 6 files changed, 84 insertions(+), 8 deletions(-) create mode 100644 mysql-test/suite/sys_vars/r/innodb_txlog_init_rate_basic.result create mode 100644 mysql-test/suite/sys_vars/t/innodb_txlog_init_rate_basic.test diff --git a/mysql-test/suite/sys_vars/r/innodb_fsync_freq_basic.result b/mysql-test/suite/sys_vars/r/innodb_fsync_freq_basic.result index d2d3cc3234b4..20be86568d2a 100644 --- a/mysql-test/suite/sys_vars/r/innodb_fsync_freq_basic.result +++ b/mysql-test/suite/sys_vars/r/innodb_fsync_freq_basic.result @@ -1,7 +1,7 @@ SET @orig_fsync_freq = @@global.innodb_fsync_freq; SELECT @orig_fsync_freq; @orig_fsync_freq -134217728 +1048576 SET GLOBAL innodb_fsync_freq = 1024*1024*1024; SELECT @@global.innodb_fsync_freq; @@global.innodb_fsync_freq diff --git a/mysql-test/suite/sys_vars/r/innodb_txlog_init_rate_basic.result b/mysql-test/suite/sys_vars/r/innodb_txlog_init_rate_basic.result new file mode 100644 index 000000000000..2540be0d368e --- /dev/null +++ b/mysql-test/suite/sys_vars/r/innodb_txlog_init_rate_basic.result @@ -0,0 +1,25 @@ +SET @orig_txlog_init_rate = @@global.innodb_txlog_init_rate; +SELECT @orig_txlog_init_rate; +@orig_txlog_init_rate +134217728 +SET GLOBAL innodb_txlog_init_rate = 500*1024*1024; +SELECT @@global.innodb_txlog_init_rate; +@@global.innodb_txlog_init_rate +524288000 +SET GLOBAL innodb_txlog_init_rate = 0; +SELECT @@global.innodb_txlog_init_rate; +@@global.innodb_txlog_init_rate +0 +SET GLOBAL innodb_txlog_init_rate = -1; +Warnings: +Warning 1292 Truncated incorrect innodb_txlog_init_rate value: '-1' +SELECT @@global.innodb_txlog_init_rate; +@@global.innodb_txlog_init_rate +0 +SET GLOBAL innodb_txlog_init_rate = 12345; +Warnings: +Warning 1292 Truncated incorrect innodb_txlog_init_rate value: '12345' +SELECT @@global.innodb_txlog_init_rate; +@@global.innodb_txlog_init_rate +0 +SET GLOBAL innodb_txlog_init_rate = @orig_txlog_init_rate; diff --git a/mysql-test/suite/sys_vars/t/innodb_txlog_init_rate_basic.test b/mysql-test/suite/sys_vars/t/innodb_txlog_init_rate_basic.test new file mode 100644 index 000000000000..7fa021d36bf6 --- /dev/null +++ b/mysql-test/suite/sys_vars/t/innodb_txlog_init_rate_basic.test @@ -0,0 +1,25 @@ +--source include/have_innodb.inc + + +SET @orig_txlog_init_rate = @@global.innodb_txlog_init_rate; + +SELECT @orig_txlog_init_rate; + +# 500MB/s +SET GLOBAL innodb_txlog_init_rate = 500*1024*1024; +SELECT @@global.innodb_txlog_init_rate; + +# min value +SET GLOBAL innodb_txlog_init_rate = 0; +SELECT @@global.innodb_txlog_init_rate; + +# invalid value +# too small +SET GLOBAL innodb_txlog_init_rate = -1; +SELECT @@global.innodb_txlog_init_rate; + +# not bound to page size +SET GLOBAL innodb_txlog_init_rate = 12345; +SELECT @@global.innodb_txlog_init_rate; + +SET GLOBAL innodb_txlog_init_rate = @orig_txlog_init_rate; diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index 819d2475a39d..485ef215a381 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -18175,9 +18175,17 @@ static MYSQL_SYSVAR_ULONG(spin_wait_delay, srv_spin_wait_delay, static MYSQL_SYSVAR_ULONGLONG(fsync_freq, os_fsync_freq, PLUGIN_VAR_RQCMDARG, "The value of this variable determines how often InnoDB calls fsync when " - "creating a new file. Default is to call fsync after every 128M written. " - "Setting this value to zero would make InnoDB flush the file before closing " - "it.", NULL, NULL, 1ULL << 27, 0, ULONG_MAX, UNIV_PAGE_SIZE); + "creating a new file. Default is to call fsync after every time the buffer " + "(1MB) is written. Setting this value to zero would make InnoDB flush the " + "file before closing it.", + NULL, NULL, OS_FILE_WRITE_BUF_SIZE, 0, ULONG_MAX, OS_FILE_WRITE_BUF_SIZE); + +static MYSQL_SYSVAR_ULONGLONG(txlog_init_rate, os_txlog_init_rate, + PLUGIN_VAR_OPCMDARG, + "The value of this variable determines how fast (in bytes/s) InnoDB " + "initializes the transaction log when creating a new file" + "Setting this value to 0 means no limit. Default is 128MB", + NULL, NULL, 1ULL << 27, 0ULL, ULONG_MAX, 1ULL << 20); static MYSQL_SYSVAR_UINT(load_table_thread_num, innobase_load_table_thread_num, PLUGIN_VAR_RQCMDARG, @@ -18688,6 +18696,7 @@ static struct st_mysql_sys_var* innobase_system_variables[]= { MYSQL_SYSVAR(sync_spin_loops), MYSQL_SYSVAR(spin_wait_delay), MYSQL_SYSVAR(fsync_freq), + MYSQL_SYSVAR(txlog_init_rate), MYSQL_SYSVAR(load_table_thread_num), MYSQL_SYSVAR(table_locks), MYSQL_SYSVAR(thread_concurrency), diff --git a/storage/innobase/include/os0file.h b/storage/innobase/include/os0file.h index b585f59f6315..bdd5f6a8687b 100644 --- a/storage/innobase/include/os0file.h +++ b/storage/innobase/include/os0file.h @@ -142,6 +142,8 @@ enum os_file_create_t { ON_ERROR_NO_EXIT is set */ }; +#define OS_FILE_WRITE_BUF_SIZE 1ULL<<20 + #define OS_FILE_READ_ONLY 333 #define OS_FILE_READ_WRITE 444 #define OS_FILE_READ_ALLOW_DELETE 555 /* for mysqlbackup */ @@ -227,6 +229,7 @@ extern ulint os_n_file_reads; extern ulint os_n_file_writes; extern ulint os_n_fsyncs; extern ullint os_fsync_freq; +extern ullint os_txlog_init_rate; /** Seconds waiting for file flushes to finish */ extern ulonglong os_file_flush_time; diff --git a/storage/innobase/os/os0file.cc b/storage/innobase/os/os0file.cc index a998c02259f5..43bc88450834 100644 --- a/storage/innobase/os/os0file.cc +++ b/storage/innobase/os/os0file.cc @@ -95,7 +95,8 @@ UNIV_INTERN ulint os_innodb_umask = S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP; UNIV_INTERN ulint os_innodb_umask = 0; #endif /* __WIN__ */ -UNIV_INTERN ullint os_fsync_freq = 1ULL << 27; +UNIV_INTERN ullint os_fsync_freq = OS_FILE_WRITE_BUF_SIZE; +UNIV_INTERN ullint os_txlog_init_rate = 1ULL << 27; #ifndef UNIV_HOTBACKUP /* We use these mutexes to protect lseek + file i/o operation, if the @@ -2322,9 +2323,8 @@ os_file_set_size( current_size = 0; - /* Write up to 1 megabyte at a time. */ - buf_size = ut_min(64, (ulint) (size / UNIV_PAGE_SIZE)) - * UNIV_PAGE_SIZE; + /* Write 1 megabyte at a time. */ + buf_size = OS_FILE_WRITE_BUF_SIZE; buf2 = static_cast(ut_malloc(buf_size + UNIV_PAGE_SIZE)); /* Align the buffer for possible raw i/o */ @@ -2333,11 +2333,17 @@ os_file_set_size( /* Write buffer full of zeros */ memset(buf, 0, buf_size); + if (os_txlog_init_rate > 0) { + fprintf(stderr, "InnoDB: log file write is throttled at %lluMB/s\n", + os_txlog_init_rate/(1ULL<<20)); + } + if (size >= (os_offset_t) 100 << 20) { fprintf(stderr, "InnoDB: Progress in MB:"); } + ulonglong start_time = my_timer_now(); while (current_size < size) { ulint n_bytes; @@ -2353,6 +2359,14 @@ os_file_set_size( goto error_handling; } + if (os_txlog_init_rate > 0) { + /* check write rate on every chunk (1MB) we write */ + while ((double)(current_size + n_bytes) > os_txlog_init_rate * + my_timer_to_seconds(my_timer_since(start_time))) { + os_thread_sleep(1000); /* sleep for 1000 usecs */ + } + } + /* Print about progress for each 100 MB written */ if ((current_size + n_bytes) / (100 << 20) != current_size / (100 << 20)) {