InnoDB - High disk write I/O on ibdata1 file and ib_logfile0

Question

Server Specification: VPS with following info

model name  : Intel(R) Xeon(R) CPU           E5649  @ 2.53GHz
MemTotal:      2058776 kB
MemFree:        244436 kB

We are running IP.Board from Invision Power Services, we are using innodb_file_per_table and have reloaded the database to reduce ibdata1 size. However, we still got problem of high CPU and I/O usage lately despite of the reduced ibdata1 size.

From my inspection, I believe that it causes by high I/O usage on ibdata1. Below is the data I obtained using pt-ioprofile -cell sizes (in Percona ToolKit). Basically, it's the total I/O amount collected in the period of 30 seconds.

# pt-ioprofile -cell sizes
Fri Jul 20 10:22:23 ICT 2012
Tracing process ID 8581
     total      pread       read     pwrite      fsync       open      close   getdents      lseek      fcntl filename
   6995968          0          0    6995968          0          0          0          0          0          0 /db/mysql/ibdata1
   1019904          0          0    1019904          0          0          0          0          0          0 /db/mysql/ib_logfile0
    204800     204800          0          0          0          0          0          0          0          0 /db/mysql/admin_phpbb3forum/phpbb_posts.ibd
     49152      49152          0          0          0          0          0          0          0          0 /db/mysql/admin_ips/ips_reputation_cache.ibd
     32768      32768          0          0          0          0          0          0          0          0 /db/mysql/admin_ips/ips_reputation_totals.ibd
     29808          0          0          0          0          0          0      29808          0          0 /db/mysql/admin_ips/
... (other trivial I/O records truncated)

Running iotop and I see DISK WRITE: goes up and down around 2M/s and 200K/s

My question is, why we have high I/O write on ibdata1 and ib_logfileX while we have only about 5-10 small update per second into our sessions tables, which are also MEMORY table (only about 300K in size)? It is puzzling me because there's also no equivalent write I/O on any other table file, which indicates that the write I/O is not caused by UPDATE/INSERT/DELETE.

Note that I'm only a programmer who are just by chance have the duty to maintain this, so please feel free to ask for more info. I've done a lot of things to this server, but please don't assume that I have done anything I should have done already.

Additional info:

# ls -l /db/mysql/ib*
-rw-rw---- 1 mysql mysql  18874368 Jul 21 01:26 /db/mysql/ibdata1
-rw-rw---- 1 mysql mysql 134217728 Jul 21 01:26 /db/mysql/ib_logfile0
-rw-rw---- 1 mysql mysql 134217728 Jul 21 01:26 /db/mysql/ib_logfile1

and

mysql> SHOW VARIABLES LIKE 'innodb%';
+-------------------------------------------+------------------------+
| Variable_name                             | Value                  |
+-------------------------------------------+------------------------+
| innodb_adaptive_flushing                  | ON                     |
| innodb_adaptive_flushing_method           | estimate               |
| innodb_adaptive_hash_index                | ON                     |
| innodb_adaptive_hash_index_partitions     | 1                      |
| innodb_additional_mem_pool_size           | 20971520               |
| innodb_autoextend_increment               | 8                      |
| innodb_autoinc_lock_mode                  | 1                      |
| innodb_blocking_buffer_pool_restore       | OFF                    |
| innodb_buffer_pool_instances              | 1                      |
| innodb_buffer_pool_restore_at_startup     | 0                      |
| innodb_buffer_pool_shm_checksum           | ON                     |
| innodb_buffer_pool_shm_key                | 0                      |
| innodb_buffer_pool_size                   | 402653184              |
| innodb_change_buffering                   | all                    |
| innodb_checkpoint_age_target              | 0                      |
| innodb_checksums                          | ON                     |
| innodb_commit_concurrency                 | 0                      |
| innodb_concurrency_tickets                | 500                    |
| innodb_corrupt_table_action               | assert                 |
| innodb_data_file_path                     | ibdata1:10M:autoextend |
| innodb_data_home_dir                      |                        |
| innodb_dict_size_limit                    | 0                      |
| innodb_doublewrite                        | ON                     |
| innodb_doublewrite_file                   |                        |
| innodb_fake_changes                       | OFF                    |
| innodb_fast_checksum                      | OFF                    |
| innodb_fast_shutdown                      | 1                      |
| innodb_file_format                        | Barracuda              |
| innodb_file_format_check                  | ON                     |
| innodb_file_format_max                    | Barracuda              |
| innodb_file_per_table                     | ON                     |
| innodb_flush_log_at_trx_commit            | 2                      |
| innodb_flush_method                       | O_DIRECT               |
| innodb_flush_neighbor_pages               | 0                      |
| innodb_force_load_corrupted               | OFF                    |
| innodb_force_recovery                     | 0                      |
| innodb_ibuf_accel_rate                    | 100                    |
| innodb_ibuf_active_contract               | 1                      |
| innodb_ibuf_max_size                      | 201310208              |
| innodb_import_table_from_xtrabackup       | 0                      |
| innodb_io_capacity                        | 4000                   |
| innodb_kill_idle_transaction              | 0                      |
| innodb_large_prefix                       | OFF                    |
| innodb_lazy_drop_table                    | 0                      |
| innodb_lock_wait_timeout                  | 50                     |
| innodb_locks_unsafe_for_binlog            | OFF                    |
| innodb_log_block_size                     | 4096                   |
| innodb_log_buffer_size                    | 4194304                |
| innodb_log_file_size                      | 134217728              |
| innodb_log_files_in_group                 | 2                      |
| innodb_log_group_home_dir                 | ./                     |
| innodb_max_dirty_pages_pct                | 75                     |
| innodb_max_purge_lag                      | 0                      |
| innodb_mirrored_log_groups                | 1                      |
| innodb_old_blocks_pct                     | 37                     |
| innodb_old_blocks_time                    | 0                      |
| innodb_open_files                         | 300                    |
| innodb_page_size                          | 16384                  |
| innodb_purge_batch_size                   | 20                     |
| innodb_purge_threads                      | 1                      |
| innodb_random_read_ahead                  | OFF                    |
| innodb_read_ahead                         | linear                 |
| innodb_read_ahead_threshold               | 56                     |
| innodb_read_io_threads                    | 24                     |
| innodb_recovery_stats                     | OFF                    |
| innodb_recovery_update_relay_log          | OFF                    |
| innodb_replication_delay                  | 0                      |
| innodb_rollback_on_timeout                | OFF                    |
| innodb_rollback_segments                  | 128                    |
| innodb_show_locks_held                    | 10                     |
| innodb_show_verbose_locks                 | 0                      |
| innodb_spin_wait_delay                    | 6                      |
| innodb_stats_auto_update                  | 0                      |
| innodb_stats_method                       | nulls_equal            |
| innodb_stats_on_metadata                  | OFF                    |
| innodb_stats_sample_pages                 | 8                      |
| innodb_stats_update_need_lock             | 1                      |
| innodb_strict_mode                        | OFF                    |
| innodb_support_xa                         | ON                     |
| innodb_sync_spin_loops                    | 30                     |
| innodb_table_locks                        | ON                     |
| innodb_thread_concurrency                 | 0                      |
| innodb_thread_concurrency_timer_based     | OFF                    |
| innodb_thread_sleep_delay                 | 10000                  |
| innodb_use_global_flush_log_at_trx_commit | ON                     |
| innodb_use_native_aio                     | ON                     |
| innodb_use_sys_malloc                     | ON                     |
| innodb_use_sys_stats_table                | OFF                    |
| innodb_version                            | 1.1.8-rel27.1          |
| innodb_write_io_threads                   | 24                     |
+-------------------------------------------+------------------------+
90 rows in set (0.00 sec)

From @RolandoMySQLDBA : Please run this

SET @TimeInterval = 300;
SELECT variable_value INTO @num1 FROM information_schema.global_status
WHERE variable_name = 'Innodb_os_log_written';
SELECT SLEEP(@TimeInterval);
SELECT variable_value INTO @num2 FROM information_schema.global_status
WHERE variable_name = 'Innodb_os_log_written';
SET @ByteWrittenToLog = @num2 - @num1;
SET @KB_WL = @ByteWrittenToLog / POWER(1024,1) * 3600 / @TimeInterval;
SET @MB_WL = @ByteWrittenToLog / POWER(1024,2) * 3600 / @TimeInterval;
SET @GB_WL = @ByteWrittenToLog / POWER(1024,3) * 3600 / @TimeInterval;
SELECT @KB_WL,@MB_WL,@GB_WL;

and show the output. This will tell you how many bytes per hour is written to ib_logfile0/ib_logfile1 based on the next 5 minutes.

Above SQL query result (At 8am local time, while the members online is about 25% of the stat during the day):

mysql> SELECT @KB_WL,@MB_WL,@GB_WL;
+--------+----------+-------------------+
| @KB_WL | @MB_WL   | @GB_WL            |
+--------+----------+-------------------+
|  95328 | 93.09375 | 0.090911865234375 |
+--------+----------+-------------------+
1 row in set (0.00 sec)

Answer 1

Here are a few things you could change

• innodb_log_buffer_size : You have 4M. The default is 8M. Try raising it to 8M.
• innodb_log_file_size : You have 128M. Given the following info you supplied
  • you write on avg 93MB per hour to the innodb log files, based on 25% of the stat
  • peak time would be about 372 MB an hour
  • half is 186 MB round off to 192MB
  • set innodb_log_file_size to 192M
• innodb_io_capacity seems a little high, make it 200 or 300 (depending on hardware)
• innodb_read_io_threads and innodb_write_io_threads should be maxed out at 64. Sometimes, less is better in a write-heavy environment. Use 8 or 16 in such cases.

To change innodb_log_file_size to 192M, add this to /etc/my.cnf

[mysqld]
innodb_log_buffer_size=8M
innodb_log_file_size=192M
innodb_open_files=300
innodb_read_io_threads=64
innodb_write_io_threads=64

then do the following

mysql -u... -p... -e"FLUSH TABLES;"
service mysql stop
mv /var/lib/mysql/ib_logfile0 /var/lib/mysql/ib_logfile0000
mv /var/lib/mysql/ib_logfile1 /var/lib/mysql/ib_logfile0001
service mysql start

Test this during slow times and see if this improves things

UPDATE 2012-10-19 12:31 EDT

To put your situation into perspective think about what the purposes of ibdata1 and ib_logfile0/1 are. Rather than rewriting everything, please read my most recent post about ibdata1 and InnoDB Log Files : What exactly are iblog files in mysql

Once you have read my other post, now consider this: What would increase I/O on these files?

• Updating Secondary Indexes in ibdata1's Insert Buffer
• Cleaning up the Rollback Segments/Undo Space

IMHO I would increase the InnoDB Buffer Pool from 384M to 1G.

I would also recommend upgrading RAM to 8G