SystemTapでMySQL 5.5のDisk I/Oを分析する
2010年1月の記事SystemTapでMySQLのDisk I/Oを分析するの続きです。以前作成したSystemTapスクリプトは、実はMySQL 5.5のDisk I/Oを分析することができませんでした。というのも、MySQL 5.5からInnoDBが非同期I/Oを行うようになったのですが、以前のスクリプトは非同期I/Oに対応していなかったためです。本日はMySQL 5.5におけるInnoDBの非同期I/Oについて、確認していきたいと思います。
非同期I/Oとは
非同期I/Oとは、I/O処理をブロックされることなしに行う方式のことです。通常のI/O処理はそれが完了するまで待たされてしまうのですが、非同期I/Oを用いることでI/O処理の完了を待つことなしに他の処理を進めることができます。以下のウェブサイトでとても詳しく解説されています。
- バッファキャッシュとAIO（1） - O'Reilly Japan Community Blog
- バッファキャッシュとAIO（2） - O'Reilly Japan Community Blog
- バッファキャッシュとAIO（3） - O'Reilly Japan Community Blog
- バッファキャッシュとAIO（4） - O'Reilly Japan Community Blog
詳解 Linuxカーネル 第3版
MySQL 5.5のInnoDBにおける非同期I/Oの利用
InnoDBは元々Windowsでのみ非同期I/Oを行っており、それ以外のプラットフォームでは「simulated AIO」と呼ばれる擬似的な非同期I/Oを行っていました。これはSQLを実行するコネクションスレッドがI/O要求をキューイングし、I/OヘルパースレッドがI/O要求をキューから取り出して実際のI/Oを行うというものです。コネクションスレッドがI/Oの完了を待たなくて良いという意味では確かに非同期ですが、I/Oヘルパースレッドが行う処理はあくまで同期I/Oであるため、この方式はsimulated AIOと呼ばれていました。I/Oヘルパースレッドの数はinnodb_read_io_threads、innodb_write_io_threadsという二つのパラメータで設定することが可能です。
MySQL 5.5のInnoDBでは、LinuxにおいてOSネイティブの非同期I/Oが利用されるようになりました。このためにはあらかじめlibaioパッケージをインストールしておく必要がありますが、設定パラメータinnodb_use_native_aioはデフォルトで有効になっており、何もしなければ自動的に非同期I/Oが利用されるようになっています。ただし現在のLinuxカーネルでは、Direct I/Oを利用している場合にのみ非同期I/Oが非同期になるという点に注意してください。つまり、非同期I/Oを利用するにはinnodb_flush_method = O_DIRECTの設定が必須となります。
非同期I/Oが有効化されている場合、コネクションスレッドはI/O要求をキューイングするのではなく、直接非同期I/Oを発行するようになります。そしてI/Oヘルパースレッドは自分自身がI/O処理を行うのではなく、コネクションスレッドが行った非同期I/Oの完了を待機して後処理を行うという役割に変化します。具体的にはコネクションスレッドがio_submit(2)を行い、I/Oヘルパースレッドがio_getevents(2)を行うようになります。
これがどのようなメリットをもたらすかというと、I/Oヘルパースレッドの数を増やすことなしに一度に処理できるI/O要求の数を増やすことができるということになります。MySQL 5.1＋InnoDB Pluginの構成においてinnodb_read_io_threadsとinnodb_write_io_threadsはそれぞれデフォルトで4であり、読み込みで4つ、書き込みで4つまでのI/O要求を一度に処理することができました。しかし、MySQL 5.5においてはOSとストレージサブシステムが許す限りのI/O要求を一度に処理することができるようになります。例えばSATA Native Command Queuingでは、デバイスあたり最大32個のI/O要求をキューイングすることが可能となっています。
分析例
前回作成したSystemTapスクリプトを、非同期I/Oをプローブできるように改造しました。スクリプトは本エントリの末尾にあります。JdbcRunnerのTiny TPC-Cを用い、多重度16で負荷をかけたときのI/Oの様子を以下に示します。最初はMySQL 5.0.77のデータです。
-------- Synchronous I/O -------- ------- Asynchronous I/O -------- rTH r/s rKB/s wTH w/s wKB/s rTH r/s rKB/s wTH w/s wKB/s File 0 0 0 17 164 629 0 0 0 0 0 0 /u02/mysql/ib_logfile1 8 8 128 7 15 14496 0 0 0 0 0 0 /u02/mysql/ibdata1 17 354 6992 1 160 2656 0 0 0 0 0 0 /u02/mysql/tpcc/customer.ibd 0 0 0 1 5 80 0 0 0 0 0 0 /u02/mysql/tpcc/history.ibd 2 22 464 0 0 0 0 0 0 0 0 0 /u02/mysql/tpcc/item.ibd 6 8 128 1 12 224 0 0 0 0 0 0 /u02/mysql/tpcc/new_orders.ibd 17 58 928 1 56 1008 0 0 0 0 0 0 /u02/mysql/tpcc/order_line.ibd 10 20 320 1 14 240 0 0 0 0 0 0 /u02/mysql/tpcc/orders.ibd 17 1057 20656 1 513 9264 0 0 0 0 0 0 /u02/mysql/tpcc/stock.ibd
rTHはそのファイルを読み込んだスレッドの数、r/sは1秒あたりの読み込み回数、rKB/sは1秒あたりに読み込んだ容量(KB)を表しています。非同期I/Oは行われておらず、全て同期I/Oであることが分かります。テーブルスペースファイルに対して読み込みを行うスレッドは最大でコネクションスレッド数＋innodb_read_io_threadsの17個、書き込みを行うスレッドはinnodb_write_io_threadsの1つだけとなっています。
ここでお詫びですが、2009年の記事SSDの真の性能を引き出す MySQL 5.1.38 InnoDB Plugin - SH2の日記において、アーキテクチャの図が間違っていました。innodb_read_io_threadsは先読みだけを行うスレッドであり、通常のページ読み込みはコネクションスレッド自身が行います。コメント欄にあるid:mogwaingさんのご指摘が正しいです。どうもありがとうございました。描き直した図を以下に示します。
先読みというのは、ある程度連続したページの読み込みが要求された際に、フルスキャンだと判断して次に読まれるであろう先の方のデータをあらかじめ読み込んでおく仕組みのことです。詳しくはマニュアルの7.7. Changes in the Read-Ahead Algorithmをご覧ください。
次はMySQL 5.1.60＋InnoDB Pluginのデータです。
-------- Synchronous I/O -------- ------- Asynchronous I/O -------- rTH r/s rKB/s wTH w/s wKB/s rTH r/s rKB/s wTH w/s wKB/s File 0 0 0 17 222 886 0 0 0 0 0 0 /u02/mysql/ib_logfile1 6 6 96 4 12 11440 0 0 0 0 0 0 /u02/mysql/ibdata1 16 458 7328 4 157 2528 0 0 0 0 0 0 /u02/mysql/tpcc/customer.ibd 5 10 160 4 24 480 0 0 0 0 0 0 /u02/mysql/tpcc/history.ibd 6 9 144 0 0 0 0 0 0 0 0 0 /u02/mysql/tpcc/item.ibd 4 6 96 0 0 0 0 0 0 0 0 0 /u02/mysql/tpcc/new_orders.ibd 17 70 1120 4 46 976 0 0 0 0 0 0 /u02/mysql/tpcc/order_line.ibd 14 29 464 3 21 352 0 0 0 0 0 0 /u02/mysql/tpcc/orders.ibd 16 1089 17424 4 385 7104 0 0 0 0 0 0 /u02/mysql/tpcc/stock.ibd
MySQL 5.0.77と比べると、テーブルスペースファイルに対して書き込みを行っているスレッドの数が増えていることが分かります。非同期I/Oは行われていません。
最後に、MySQL 5.5.18のデータです。
-------- Synchronous I/O -------- ------- Asynchronous I/O -------- rTH r/s rKB/s wTH w/s wKB/s rTH r/s rKB/s wTH w/s wKB/s File 0 0 0 17 156 651 0 0 0 0 0 0 /u02/mysql/ib_logfile0 16 40 640 7 18 17072 0 0 0 4 62 992 /u02/mysql/ibdata1 16 306 4896 0 0 0 0 0 0 7 145 2320 /u02/mysql/tpcc/customer.ibd 1 1 16 0 0 0 3 5 80 1 1 16 /u02/mysql/tpcc/history.ibd 13 22 352 0 0 0 0 0 0 0 0 0 /u02/mysql/tpcc/item.ibd 9 22 352 0 0 0 0 0 0 2 36 576 /u02/mysql/tpcc/new_orders.ibd 16 80 1280 0 0 0 6 11 176 6 110 1760 /u02/mysql/tpcc/order_line.ibd 11 109 1744 0 0 0 0 0 0 2 12 192 /u02/mysql/tpcc/orders.ibd 16 1178 18848 0 0 0 0 0 0 7 701 11216 /u02/mysql/tpcc/stock.ibd
テーブルスペースファイルに対する書き込みが非同期I/Oになっていることが分かります。また先読みも非同期I/Oになったため、historyテーブルとorder_lineテーブルに対して先読みが行われていることが判別できます。
このように、MySQL 5.5でI/Oの仕組みが変わりました。ただ性能面ではMySQL 5.1＋InnoDB Pluginの時点で既にかなり良くなっているため、そこからの改善幅はあまり大きくはないと思います。おそらく、よほど高性能なストレージを持ってこない限りI/O性能の違いは分からないでしょう。
SystemTapスクリプト
今回作成したSystemTapスクリプトを以下に示します。前回と同様Perlスクリプトとのセットになっているため、以下のようにパイプでつなげて実行してください。
# stap io2.stp | perl io2.pl
global PROCNAME = "mysqld" global fds probe begin { printf("start\n") } probe syscall.read, syscall.pread { if (execname() == PROCNAME) { fds[pid(), tid()] = fd } } probe syscall.read.return, syscall.pread.return { if (execname() == PROCNAME && $return != -1) { printf("read\t%d\t%d\t%d\t%d\n", pid(), tid(), fds[pid(), tid()], $return) } } probe syscall.write, syscall.pwrite { if (execname() == PROCNAME) { fds[pid(), tid()] = fd } } probe syscall.write.return, syscall.pwrite.return { if (execname() == PROCNAME && $return != -1) { printf("write\t%d\t%d\t%d\t%d\n", pid(), tid(), fds[pid(), tid()], $return) } } probe syscall.io_submit { if (execname() == PROCNAME) { for (i = 0; i < nr; i++) { if ($iocbpp[i]->aio_lio_opcode == 0) { // IOCB_CMD_PREAD printf("aio_read\t%d\t%d\t%d\t%d\n", pid(), tid(), $iocbpp[i]->aio_fildes, $iocbpp[i]->aio_nbytes) } else if ($iocbpp[i]->aio_lio_opcode == 1) { // IOCB_CMD_PWRITE printf("aio_write\t%d\t%d\t%d\t%d\n", pid(), tid(), $iocbpp[i]->aio_fildes, $iocbpp[i]->aio_nbytes) } } } } probe syscall.close { if (execname() == PROCNAME) { printf("close\t%d\t%d\t%d\n", pid(), tid(), fd) } } probe timer.s(1) { printf("print\n") }
#!/usr/bin/perl use strict; use warnings; my (%file_map, $do_print, %has_io, %rthreads, %rtimes, %rbytes, %wthreads, %wtimes, %wbytes, %aio_rthreads, %aio_rtimes, %aio_rbytes, %aio_wthreads, %aio_wtimes, %aio_wbytes); $do_print = 0; while (my $line = <>) { chomp($line); my ($call, $pid, $tid, $fd, $size) = split(/\t/, $line); if (($call eq 'read') or ($call eq 'write') or ($call eq 'aio_read') or ($call eq 'aio_write')) { if (!defined($file_map{"$pid,$fd"})) { $file_map{"$pid,$fd"} = readlink("/proc/$pid/fd/$fd") or next; } my $file = $file_map{"$pid,$fd"}; if (substr($file, 0, 1) eq '/') { $do_print = 1; $has_io{$file} = 1; if ($call eq 'read') { $rthreads{$file}->{$tid} = 1; $rtimes{$file}++; $rbytes{$file} += $size; } elsif ($call eq 'write') { $wthreads{$file}->{$tid} = 1; $wtimes{$file}++; $wbytes{$file} += $size; } elsif ($call eq 'aio_read') { $aio_rthreads{$file}->{$tid} = 1; $aio_rtimes{$file}++; $aio_rbytes{$file} += $size; } elsif ($call eq 'aio_write') { $aio_wthreads{$file}->{$tid} = 1; $aio_wtimes{$file}++; $aio_wbytes{$file} += $size; } } } elsif ($call eq 'close') { if (defined($file_map{"$pid,$fd"})) { delete($file_map{"$pid,$fd"}); } } elsif ($call eq 'print') { my ($sec, $min, $hour, $day, $mon, $year) = localtime(); printf "%04d-%02d-%02d %02d:%02d:%02d\n", $year + 1900, $mon + 1, $day, $hour, $min, $sec; if ($do_print == 1) { print "-------- Synchronous I/O -------- ------- Asynchronous I/O --------\n"; print "rTH r/s rKB/s wTH w/s wKB/s rTH r/s rKB/s wTH w/s wKB/s File\n"; foreach my $file (sort keys %has_io) { printf "%3d %5d %6d %3d %5d %6d %3d %5d %6d %3d %5d %6d %s\n", scalar(keys(%{$rthreads{$file}})), defined($rtimes{$file}) ? $rtimes{$file} : 0, defined($rbytes{$file}) ? $rbytes{$file} / 1024 : 0, scalar(keys(%{$wthreads{$file}})), defined($wtimes{$file}) ? $wtimes{$file} : 0, defined($wbytes{$file}) ? $wbytes{$file} / 1024 : 0, scalar(keys(%{$aio_rthreads{$file}})), defined($aio_rtimes{$file}) ? $aio_rtimes{$file} : 0, defined($aio_rbytes{$file}) ? $aio_rbytes{$file} / 1024 : 0, scalar(keys(%{$aio_wthreads{$file}})), defined($aio_wtimes{$file}) ? $aio_wtimes{$file} : 0, defined($aio_wbytes{$file}) ? $aio_wbytes{$file} / 1024 : 0, $file; } print "\n"; $do_print = 0; %has_io = %rthreads = %rtimes = %rbytes = %wthreads = %wtimes = %wbytes = (); %aio_rthreads = %aio_rtimes = %aio_rbytes = %aio_wthreads = %aio_wtimes = %aio_wbytes = (); } } else { print "$call\n"; } }
