チューニンガソン5の復習 MySQL 5.5 チート編＆勉強会のお知らせ

ゼロスタートの@zakiさんを中心に企画、運営されているチューニンガソンというイベントがあります。指定された環境を用いてOSやサーバ周りのチューニングを行い、性能を競うというものです。2013年1月に行われた第5回ではMySQLがテーマだったということで、本日はこれの復習をしていこうと思います。

しばらく真面目にチューニングしていたのですが思いのほか難しかったので、今回はちょっとズルをして優勝タイムを出すところまでご紹介します。

計測条件

Dropboxでレギュレーションが公開されています。

また、イベントで用いられたものと同じAmazon Machine Imageが公開されています。

  • m1.xlarge (8ECU、4仮想コア、15GBメモリ)
  • Amazon Linux AMI 2012.09
  • MySQL 5.5.29

しかし従量課金のm1.xlargeで作業していると、正直私は焦りを隠せません。落ち着いて作業をするために、まずは自宅のPCへ引っ越しをしました。

計測プログラムのオリジナル版には、結果を集計サーバにPOSTする機能があります。しかしもう集計サーバはありませんので、改変版ではPOST機能を取り除いてあります。またSQLとログを少し見やすく整形しています。@zakiさんに改変版の頒布許可をいただきました。どうもありがとうございます。
データベースはMediaWikiのもので、Wikipedia日本語版が格納されています。

CREATE TABLE `page` (
  `page_id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `page_namespace` int(11) NOT NULL,
  `page_title` varchar(255) CHARACTER SET utf8 COLLATE utf8_bin NOT NULL,
  `page_restrictions` tinyblob NOT NULL,
  `page_counter` bigint(20) unsigned NOT NULL DEFAULT '0',
  `page_is_redirect` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `page_is_new` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `page_random` double unsigned NOT NULL,
  `page_touched` binary(14) NOT NULL DEFAULT '\0\0\0\0\0\0\0\0\0\0\0\0\0\0',
  `page_latest` int(10) unsigned NOT NULL,
  `page_len` int(10) unsigned NOT NULL,
  PRIMARY KEY (`page_id`),
  UNIQUE KEY `name_title` (`page_namespace`,`page_title`),
  KEY `page_random` (`page_random`),
  KEY `page_len` (`page_len`),
  KEY `page_redirect_namespace_len` (`page_is_redirect`,`page_namespace`,`page_len`)
) ENGINE=InnoDB AUTO_INCREMENT=2704666 DEFAULT CHARSET=utf8;

CREATE TABLE `revision` (
  `rev_id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `rev_page` int(10) unsigned NOT NULL,
  `rev_text_id` int(10) unsigned NOT NULL,
  `rev_comment` tinyblob NOT NULL,
  `rev_user` int(10) unsigned NOT NULL DEFAULT '0',
  `rev_user_text` varchar(255) CHARACTER SET utf8 COLLATE utf8_bin NOT NULL DEFAULT '',
  `rev_timestamp` binary(14) NOT NULL DEFAULT '\0\0\0\0\0\0\0\0\0\0\0\0\0\0',
  `rev_minor_edit` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `rev_deleted` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `rev_len` int(10) unsigned DEFAULT NULL,
  `rev_parent_id` int(10) unsigned DEFAULT NULL,
  `rev_sha1` varbinary(32) NOT NULL DEFAULT '',
  PRIMARY KEY (`rev_id`),
  UNIQUE KEY `rev_page_id` (`rev_page`,`rev_id`),
  KEY `rev_timestamp` (`rev_timestamp`),
  KEY `page_timestamp` (`rev_page`,`rev_timestamp`),
  KEY `user_timestamp` (`rev_user`,`rev_timestamp`),
  KEY `usertext_timestamp` (`rev_user_text`,`rev_timestamp`),
  KEY `page_user_timestamp` (`rev_page`,`rev_user`,`rev_timestamp`)
) ENGINE=InnoDB AUTO_INCREMENT=45658130 DEFAULT CHARSET=utf8 MAX_ROWS=10000000 AVG_ROW_LENGTH=1024;

mysql> SELECT *
    -> FROM information_schema.tables
    -> WHERE table_schema = 'wikipedia'
    -> AND table_name IN ('page', 'revision')\G
*************************** 1. row ***************************
  TABLE_CATALOG: def
   TABLE_SCHEMA: wikipedia
     TABLE_NAME: page
     TABLE_TYPE: BASE TABLE
         ENGINE: InnoDB
        VERSION: 10
     ROW_FORMAT: Compact
     TABLE_ROWS: 1670757
 AVG_ROW_LENGTH: 98
    DATA_LENGTH: 164265984 (156.7MB)
MAX_DATA_LENGTH: 0
   INDEX_LENGTH: 207159296 (197.6MB)
      DATA_FREE: 85983232
 AUTO_INCREMENT: 2704666
    CREATE_TIME: 2013-03-03 20:54:20
    UPDATE_TIME: NULL
     CHECK_TIME: NULL
TABLE_COLLATION: utf8_general_ci
       CHECKSUM: NULL
 CREATE_OPTIONS:
  TABLE_COMMENT:
*************************** 2. row ***************************
  TABLE_CATALOG: def
   TABLE_SCHEMA: wikipedia
     TABLE_NAME: revision
     TABLE_TYPE: BASE TABLE
         ENGINE: InnoDB
        VERSION: 10
     ROW_FORMAT: Compact
     TABLE_ROWS: 1599526
 AVG_ROW_LENGTH: 136
    DATA_LENGTH: 217808896 (207.7MB)
MAX_DATA_LENGTH: 0
   INDEX_LENGTH: 431144960 (411.2MB)
      DATA_FREE: 85983232
 AUTO_INCREMENT: 45658130
    CREATE_TIME: 2013-03-03 20:55:53
    UPDATE_TIME: NULL
     CHECK_TIME: NULL
TABLE_COLLATION: utf8_general_ci
       CHECKSUM: NULL
 CREATE_OPTIONS: max_rows=10000000 avg_row_length=1024
  TABLE_COMMENT:

MySQLの設定ファイルはRed Hat Enterprise Linuxバンドル版のmy.cnfを基本として、キャラクタセットのみ追加指定した状態です。チューニングはまったく施されていません。

[mysqld]
# Settings user and group are ignored when systemd is used.
# If you need to run mysqld under different user or group,
# customize your systemd unit file for mysqld according to the
# instructions in http://fedoraproject.org/wiki/Systemd
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0
character-set-server=utf8

[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid
character-set-server=utf8

[mysql]
default-character-set=utf8

計測プログラムが実行するクエリは以下の6種類です。これらが1回ずつ順番に実行されます。

RESET /* Q0 */ QUERY CACHE;

  SELECT /* Q1 */ COUNT(*)
    FROM page p
    JOIN revision r
      ON p.page_id = r.rev_page
   WHERE p.page_is_redirect = 0
     AND p.page_namespace = 0
     AND r.rev_user = 0;

  SELECT /* Q2 */ COUNT(*)
    FROM page p
    JOIN revision r
      ON p.page_id = r.rev_page
   WHERE p.page_is_redirect = 0
     AND p.page_namespace = 0
     AND r.rev_user = 0
     AND p.page_touched > DATE_FORMAT(NOW() - INTERVAL 1 YEAR, '%Y0101000000');

  SELECT /* Q3 */ p.page_id
    FROM page p
    JOIN revision r
      ON p.page_id = r.rev_page
   WHERE p.page_is_redirect = 0
     AND p.page_namespace = 0
     AND r.rev_user = 0
ORDER BY p.page_touched DESC
   LIMIT 10;

  SELECT /* Q4 */ r.rev_user, COUNT(*) AS c
    FROM page p
    JOIN revision r
      ON p.page_id = r.rev_page
   WHERE p.page_is_redirect = 0
     AND p.page_namespace = 0
GROUP BY r.rev_user
ORDER BY c DESC;

  SELECT /* Q5 */ SUBSTRING(r.rev_timestamp, 1, 6), COUNT(*) AS c
    FROM page p
    JOIN revision r
      ON p.page_id = r.rev_page
   WHERE p.page_is_redirect = 0
     AND p.page_namespace = 0
GROUP BY SUBSTRING(r.rev_timestamp, 1, 6)
ORDER BY c DESC;

ベースライン

手元のPCを使用して、まずはそのまま実行してみます。

$ python tgbench_mysql_2.py 127.0.0.1
Q0:0.00018
Q1:5.97537
Q2:4.66229
Q3:4.59017
Q4:14.48054
Q5:14.30720
Total:43.97575


1回目は44.0秒、2回目は41.1秒となりました。2回目はOSのページキャッシュ、InnoDBのバッファプールにデータがキャッシュされるため性能が向上します。クエリの単体性能を計測する際は、2回ずつ実施することをおすすめします。
当日は140秒程度の結果が出ていたそうで、m1.xlargeに比べるとCore i5-2400Sの方が3倍程度速いということになります。m1.xlargeはXeon E5645でSPECint_base2006は36.4、一方Core i5-2400SのSPECint_base2006は36.0とCPUコアあたりの性能にはほとんど違いがないのですが、EC2の方で何らかの制限が設けられているのだと考えられます。

チューニングその1：InnoDBバッファプールの拡大

計測プログラムが実行するクエリはpageテーブルとrevisionテーブルのみにアクセスします。pageテーブルのサイズは354.2MB、revisionテーブルのサイズは618.9MBということで、まずはこれらのテーブルがすべて収まるだけのメモリを割り当てることがチューニングの第一歩になるかと思います。

[mysqld]
# Settings user and group are ignored when systemd is used.
# If you need to run mysqld under different user or group,
# customize your systemd unit file for mysqld according to the
# instructions in http://fedoraproject.org/wiki/Systemd
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0
character-set-server=utf8
innodb_buffer_pool_size=1G


8.8秒になりました。m1.xlargeの場合は、これで17秒程度になったようです。

チューニングその2：RESET QUERY CACHEの回避

クエリ0番にRESET QUERY CACHEがあるのを見てしまうと、やはりこれを回避したいと思うのが人情ではないでしょうか。本番で成功した方はいなかったのですが、回避の可能性には数名の方が気づいていたようです。

やってみましょう。
MySQL Proxyとは、MySQLの通信プロトコルを理解しMySQLクライアントとMySQLサーバとの通信を横取りしてさまざまな操作を行うサーバプログラムです。Luaスクリプトによって処理内容を定義し、ロードバランサとして使用したりクエリのプロファイリングを行ったりすることが想定されています。ライセンスはGPLv2です。なお長い間アルファ版のまま開発が進んでいないため、本番環境で使用することはおすすめしません。

-- tuningathon5_q0.lua
-- Q0: Ignoring 'RESET QUERY CACHE'

function read_query(packet)
    if string.byte(packet) == proxy.COM_QUERY then
        local query = string.sub(packet, 2)
        if string.find(query, "^%s*RESET /%* Q0 %*/ QUERY CACHE%s*$") then
            print("[HIT Q0]")
            proxy.queries:reset()
            proxy.queries:append(1, string.char(proxy.COM_QUERY) .. "FLUSH /* Q0_rewrite */ QUERY CACHE")
            return proxy.PROXY_SEND_QUERY
        end
    end
end

このLuaスクリプトで、RESET QUERY CACHEをFLUSH QUERY CACHEに書き換えてしまいます。RESET QUERY CACHEはクエリキャッシュを削除するコマンド、一方FLUSH QUERY CACHEはクエリキャッシュをデフラグするだけのコマンドです。これら二つのコマンドは処理が成功した際の戻りのパケットが同一ですので、クエリを書き換えていることはそう簡単には発覚しないはずです。

[mysqld]
# Settings user and group are ignored when systemd is used.
# If you need to run mysqld under different user or group,
# customize your systemd unit file for mysqld according to the
# instructions in http://fedoraproject.org/wiki/Systemd
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0
character-set-server=utf8
innodb_buffer_pool_size=1G
port=3307
query_cache_size=1M

MySQLサーバのTCP待ち受けポートを変更し、クエリキャッシュの設定を施しておきます。今回のクエリに対しては、クエリキャッシュは1MBあれば足ります。MySQL Proxyを以下のオプションで起動し、MySQLクライアントから送られてくるクエリをMySQL Proxyで中継してMySQLサーバに渡すようにします。

$ /PATH/TO/mysql-proxy --proxy-address=:3306 \
                       --proxy-backend-addresses=:3307 \
                       --proxy-lua-script=tuningathon5_q0.lua


1.0秒になりました。優勝タイムは6.2秒とのことで、環境の違いを加味してもこの時点で上回ることができたのではないかと思います。

チューニングその3：クエリ1番の修正

RESET QUERY CACHEを回避することでクエリ3〜5番は速くなったのですが、実はクエリ1番と2番が速くなっていません。

mysql> SHOW GLOBAL STATUS LIKE 'Qcache_hits';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Qcache_hits   | 107   |
+---------------+-------+
1 row in set (0.00 sec)

(計測プログラム実行)

mysql> SHOW GLOBAL STATUS LIKE 'Qcache_hits';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Qcache_hits   | 110   |
+---------------+-------+
1 row in set (0.00 sec)

計測プログラムの前後でクエリキャッシュの状態を確認すると、3回しかクエリキャッシュにヒットしていないことが分かります。これはクエリ3〜5番の分です。なぜクエリ1番と2番はクエリキャッシュにヒットしないのでしょうか。まずクエリ1番から確認していきましょう。

mysql> SHOW GLOBAL STATUS LIKE 'Qcache_hits';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Qcache_hits   | 110   |
+---------------+-------+
1 row in set (0.00 sec)

mysql>   SELECT /* Q1 */ COUNT(*)
    ->     FROM page p
    ->     JOIN revision r
    ->       ON p.page_id = r.rev_page
    ->    WHERE p.page_is_redirect = 0
    ->      AND p.page_namespace = 0
    ->      AND r.rev_user = 0;
+----------+
| COUNT(*) |
+----------+
|   273537 |
+----------+
1 row in set (0.00 sec)

mysql>  SHOW GLOBAL STATUS LIKE 'Qcache_hits';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Qcache_hits   | 111   |
+---------------+-------+
1 row in set (0.00 sec)

クエリ1番を手打ちすると、きちんとクエリキャッシュにヒットしていることが分かります。原因を突き止めることはなかなか難しいと思いますが、これは、残念ながらMySQLの不具合です。

AUTOCOMMITがOFFの場合に、トランザクション開始前の最初のクエリがクエリキャッシュにヒットしないというものです。今も直っていません。PythonのMySQLdbモジュールはPython Database API Specification v2.0にもとづきデフォルトでAUTOCOMMITがOFFになっており、この不具合を必ず踏みます。ワークアラウンドとして「START TRANSACTIONで明示的にトランザクションを開始しておく」という方法がありますので、先ほどのLuaスクリプトを以下のように修正します。

-- tuningathon5_q0q1.lua
-- Q0: Ignoring 'RESET QUERY CACHE'
-- Q1: Workaround for Bug#42197

function read_query(packet)
    if string.byte(packet) == proxy.COM_QUERY then
        local query = string.sub(packet, 2)
        if string.find(query, "^%s*RESET /%* Q0 %*/ QUERY CACHE%s*$") then
            print("[HIT Q0]")
            proxy.queries:reset()
            proxy.queries:append(1, string.char(proxy.COM_QUERY) .. "FLUSH /* Q0_rewrite */ QUERY CACHE")
            proxy.queries:append(2, string.char(proxy.COM_QUERY) .. "START /* Q1_workaround */ TRANSACTION", { resultset_is_needed = true })
            return proxy.PROXY_SEND_QUERY
        end
    end
end

function read_query_result(inj)
    if inj.id == 2 then
        return proxy.PROXY_IGNORE_RESULT
    end
end

クエリ0番を実行した直後にSTART TRANSACTIONを実行します。その際START TRANSACTIONの結果をそのままクライアントに返すと計測プログラムが誤動作してしまいますので、read_query_result()ファンクションで結果を握りつぶしています。

0.56秒になりました。グラフでオレンジ色の部分がなくなったことが分かると思います。

チューニングその4：クエリ2番の修正

クエリ2番がクエリキャッシュにヒットしない理由は明快で、NOW()ファンクションを使用しているためです。

  SELECT /* Q2 */ COUNT(*)
    FROM page p
    JOIN revision r
      ON p.page_id = r.rev_page
   WHERE p.page_is_redirect = 0
     AND p.page_namespace = 0
     AND r.rev_user = 0
     AND p.page_touched > DATE_FORMAT(NOW() - INTERVAL 1 YEAR, '%Y0101000000');

マニュアルに、クエリキャッシュにヒットしなくなるファンクションの一覧が記載されています。

このクエリをどうやって直すかですが、あらためてDATE_FORMAT()ファンクションのところをよく見ると、出力結果が年月日のうち年にしか依存していないことが分かると思います。ここの部分は2013年1月1日〜12月31日までは「20120101000000」という文字列を、2014年1月1日〜12月31日までは「20130101000000」という文字列を返します。このくらいでしたらLuaスクリプトで同じ文字列を返すようにできます。

-- tuningathon5_q0q1q2.lua
-- Q0: Ignoring 'RESET QUERY CACHE'
-- Q1: Workaround for Bug#42197
-- Q2: Avoiding NOW() function

function read_query(packet)
    if string.byte(packet) == proxy.COM_QUERY then
        local query = string.sub(packet, 2)
        if string.find(query, "^%s*RESET /%* Q0 %*/ QUERY CACHE%s*$") then
            print("[HIT Q0]")
            proxy.queries:reset()
            proxy.queries:append(1, string.char(proxy.COM_QUERY) .. "FLUSH /* Q0_rewrite */ QUERY CACHE")
            proxy.queries:append(2, string.char(proxy.COM_QUERY) .. "START /* Q1_workaround */ TRANSACTION", { resultset_is_needed = true })
            return proxy.PROXY_SEND_QUERY
         elseif string.find(query, "^%s*SELECT /%* Q2 %*/ COUNT%(%*%)%s*"
                    .. "FROM page p%s*"
                    .. "JOIN revision r%s*ON p%.page_id = r%.rev_page%s*"
                    .. "WHERE p%.page_is_redirect = 0%s*"
                    .. "AND p%.page_namespace = 0%s*"
                    .. "AND r%.rev_user = 0%s*"
                    .. "AND p%.page_touched > DATE_FORMAT%(NOW%(%) %- INTERVAL 1 YEAR, '%%Y0101000000'%)%s*$")
         then
            print("[HIT Q2]")
            proxy.queries:reset()
            proxy.queries:append(1, string.char(proxy.COM_QUERY)
                .. "SELECT /* Q2_rewrite */ COUNT(*) "
                .. "FROM page p "
                .. "JOIN revision r ON p.page_id = r.rev_page "
                .. "WHERE p.page_is_redirect = 0 "
                .. "AND p.page_namespace = 0 "
                .. "AND r.rev_user = 0 "
                .. "AND p.page_touched > '" .. os.date('%Y') - 1 .. "0101000000'")
            return proxy.PROXY_SEND_QUERY
        end
    end
end

function read_query_result(inj)
    if inj.id == 2 then
        return proxy.PROXY_IGNORE_RESULT
    end
end


0.067秒になりました。このグラフでは何も見えなくなりました。拡大してみましょう。

最終的にクエリ4番が処理時間の大半を占めるようになりました。これは、クエリ4番の結果セットが39,434レコードと最も大きいためです。

勉強会のお知らせ

MySQL Proxyを使用してクエリキャッシュを無理やり効かせるという今回のチューニング方針ですが、MySQL Proxyがアルファ版であること、クエリキャッシュはCPUスケーラビリティが悪く最近は使われない傾向であることを考慮すると、実際の業務に応用することは難しくあまり筋が良いチューニング方針だとは言えません。
本エントリ執筆時点でまだ上手くできていないのですが、クエリキャッシュをOFFに戻して、ついでにMySQLを5.6にバージョンアップしてどこまで改善できるのかを調べています。調査結果について、今月久しぶりに開催されるMySQLユーザ会のイベントでご報告したいと思います。

当日は@yoku0825さんもMySQL 5.6の新機能について発表されます。ぜひ、ご参加ください。

Provisioned IOPSの検討 - JPOUG Advent Calendar 2012

2012年9月にAmazon RDSでProvisioned IOPSというサービスが利用できるようになりました。本日はこれを題材にして、IOPSを保証するということについて勉強していきたいと思います。このエントリは、JPOUG Advent Calendar 2012の17日目となります。16日目は@maroon1stさんでした。
Amazon RDSについては、@horiuchiさんが15日目のエントリでまとめ記事を書いていらっしゃいます。Provisioned IOPSについては記事の反響で第3位ということで、なかなか注目度が高かったことが分かりますね。

fioによるIOPSの測定

さて、まずはIOPSを測定するツールを準備しましょう。I/O関連のベンチマークツールはいろいろありますが、今回はfio - Flexible I/O Testerを使用することにしました。これは私が希望する測定パターンをすべて再現できたこと、Red Hat Enterprise Linuxやそのクローン、およびUbuntu向けにバイナリパッケージが用意されておりインストールが簡単なことが主な理由です。RHEL系の場合はRepoForceからバイナリパッケージを入手、Ubuntuの場合はapt-getコマンドでインストールできます。
fioを使用した最近のベンチマーク結果として、@namikawaさんがAmazon EC2 High I/O Quadruple Extra Large Instanceの測定結果を、@kazeburoさんがIntel SSD 910 800GBの測定結果を公開されています。

これを参考にしつつ、以下のようにカスタマイズしておきます。

  • テストファイルサイズを16GBに拡大します。これはRAIDコントローラやストレージのキャッシュによって性能が高ぶれするのを防ぐためです。OSのページキャッシュについてはDirect I/Oを使用することであらかじめ影響を排除しておきます。ディスクに余裕があればファイルサイズはもう少し増やしておきたいところで、例えばさくらインターネットさんではSSDプランの提供にあたり100GBで測定されています。
  • ブロックサイズ4KBに加えて8KB、16KBの測定を行います。8KBはOracle Databaseのデフォルトブロックサイズ、およびPostgreSQLのブロックサイズです。16KBはMySQL InnoDBのページサイズです。
  • 読み書きをミックスさせた測定を行います。読み取り100%、書き込み100%のほかに、読み取り：書き込み＝90：10、50：50、10：90での測定を追加します。
  • 非同期I/Oを使用します。多重アクセスによる性能の伸びを測定する際、fioでは-numjobs=64 -group_reportingとしてマルチスレッド実行をさせることができますが、非同期I/Oを使用して-ioengine=libaio -iodepth=64と指定することもできます。基本的に同じ結果が得られます。MySQL 5.1＋InnoDB Pluginが同期I/Oのマルチスレッド実行、MySQL 5.5が非同期I/Oを行っているということをふまえ、今回は非同期I/Oを採用します。
  • 非同期I/OにおけるQueue Depthのバリエーションを増やします。64以外に、1から256までの測定パターンを用意しておきます。なおSerial ATAの場合はNCQ(Native Command Queuing)の上限が32なので、高速なSSDを持ってきたとしても多重アクセスによる性能の伸びは32で頭打ちとなります。

できあがった測定スクリプトは以下のようになりました。測定パターンはシーケンシャル読み取り、シーケンシャル書き込みの2パターンに加え、ランダム読み書きがブロックサイズ3パターン×読み書き比率5パターン×Queue Depth 9パターンで135パターンあり、合計で137パターンとなります。1回の測定を60秒に設定していますので、全パターンの測定には2時間強かかります。


手元のパソコンで測定した結果をご紹介します。fioのログからこの表を出力するスクリプトを用意していますので、ご利用ください。



Plextor PX-256M2Pはカタログスペックで読み取りIOPSが70,000、書き込みIOPSが65,000となっていますが、ほぼカタログスペック通りの値が出ていることが分かると思います。黄色のセルは、Windowsでよく使われているCrystalDiskMarkと同じ測定を行っている部分です。


ブロックサイズが大きくなるとIOPSは下がっていきます。また読み書きをミックスさせると読み取りのみ、書き込みのみの場合に比べてIOPSが下がります。この傾向はPlextor以外のSSDでも同じでした。

cgroupによるIOPSの制御

では、IOPSの制御を試してみましょう。調べたところ、IOPSを制御する方法は2つ見つかりました。

  • QEMUのDisk I/O Limits機能を使う方法。IBMが中心となって開発が進められている機能です。KVM Forum 2011のウェブサイトにIO Throttling in QEMU (PDF)というプレゼンテーション資料が公開されています。
  • Linuxのcgroup(Control Group)機能を使う方法。cgroupはLinux Kernel 2.6.24からある機能ですが、2.6.37からブロックデバイスに対するI/O帯域、IOPSを制御できるようになりました。RHEL 6はKernel 2.6.32ですが、6.1にこの機能がバックポートされています。@enakai00さんがブログで詳しい解説をされています。

QEMUのDisk I/O Limits機能はまだ開発中ということで、今回はcgroupを使用しました。ここから先は仮想環境で作業を行っていきます。cgroupによるIOPS制御には技術的な制限事項があって、物理環境では少し使いづらいためです。この件については後述します。

  • Storage：Plextor PX-256M2P
  • Host OS：Scientific Linux 6.3 x86_64
  • Host I/O Scheduler：deadline
  • Host Filesystem：ext4 (rw,discard,nobarrier), 4KB aligned
  • KVM Disk Bus：virtio
  • KVM Storage Format：raw
  • KVM Cache Model：none
  • KVM I/O Mode：native
  • Guest OS：Scientific Linux 6.3 x86_64
  • Guest I/O Scheduler：noop
  • Guest Filesystem：ext4 (rw,nobarrier), 4KB aligned

まずIOPSを制御しない状態での、仮想環境の素の性能です。ブロックサイズによる傾向の違いはなかったので、ここから先は16KBの結果のみ掲載します。

物理環境とあまり変わらない形のグラフですが、Queue Depthが小さいときの性能の落ち込みが目立ちます。これはI/Oリクエストが2つのOSを経由するため、レイテンシが長くなっていることが原因です。Queue Depth 1の性能はシングルスレッドで行う大量処理、例えばLOAD DATAやALTER TABLEに効いてくるので、仮想化のオーバーヘッドというものは今でもそれなりにあります。
一方、ピーク性能は物理環境と変わりないことが分かります。処理を詰め込めるだけ詰め込んでしまえば、アライメントが合っていないなどのミスがなければ最終的にはストレージの限界性能が出ます。もちろん、CPUなど他のコンポーネントがボトルネックになっていないことが前提です。
次は、読み取り、書き込みとも10,000 IOPSに制限した測定結果です。これはKVMホストから以下のコマンドを実行して設定します。

# ls -l /dev/sda
brw-rw---- 1 root disk 8, 0  9月 16 23:00 2012 /dev/sda

# echo '8:0 10000' > /cgroup/blkio/libvirt/qemu/k01sl6/blkio.throttle.read_iops_device
# echo '8:0 10000' > /cgroup/blkio/libvirt/qemu/k01sl6/blkio.throttle.write_iops_device


非常にきれいなグラフになっています。ここまでうまくいくとは予想していませんでした。読み取り100%のときはちょうど10,000 IOPSになっており、90%のときは読み取り10,000＋書き込み1,111で11,111 IOPSとなります。50%のときは上限20,000 IOPSですが今回使用したSSDはそこまで性能が出ないため、16,634 IOPSとなっています。
続いて、3,000 IOPS、1,000 IOPSに制限した測定結果です。


きちんと効いていますね。かなり使える機能だと思います。

cgroup使用時の注意点

RHEL 6.3の時点では、cgroupによるI/O帯域、IOPSの制御には技術的な制限事項があります。それはBuffered Writeに対して正常に動作しないというものです。例としてKVMゲストでOS全体に書き込み1,000 IOPSの制限をかけると、以下のようになります。

# echo '252:32 0' > /cgroup/blkio/blkio.throttle.write_iops_device

# dd if=/dev/zero of=test.dat bs=131072 count=8192 oflag=direct
8192+0 records in
8192+0 records out
1073741824 bytes (1.1 GB) copied, 8.20527 s, 131 MB/s

oflag=directを付けた場合は8,192回の書き込みに8.2秒かかるということで、想定通りです。

# dd if=/dev/zero of=test.dat bs=131072 count=8192
8192+0 records in
8192+0 records out
1073741824 bytes (1.1 GB) copied, 202.553 s, 5.3 MB/s

# dd if=/dev/zero of=test.dat bs=131072 count=8192 oflag=dsync
8192+0 records in
8192+0 records out
1073741824 bytes (1.1 GB) copied, 309.503 s, 3.5 MB/s

しかし、oflag=direct以外の設定では極端に性能が劣化してしまいます。OSのバッファに書き込んでいる間は速いのですが、そこから溢れて実際にブロックデバイスに書き込みに行くところで制御がうまくいっていないようです。設定が効かなくてフルスピードになってしまうならまだしも、こんなに遅くなってしまっては困ります。
現状cgroupによるI/O帯域、IOPSの制御が期待通りに動作するのは、Direct I/Oに対してのみです。RHELのマニュアルにも注意事項が記載されています。

Currently, the Block I/O subsystem does not work for buffered write operations. It is primarily targeted at direct I/O, although it works for buffered read operations.

Red Hat Enterprise Linux 6 Chapter 3. Subsystems and Tunable Parameters - Red Hat Customer Portal

Oracle Database、MySQLはDirect I/Oを使用していますが、すべてのI/OがDirect I/Oというわけではありません。また、PostgreSQLはDirect I/Oを使用していません。これらのソフトウェアに対して直接cgroupでI/O帯域、IOPSの制御を行うことは、まだ無理です。
ではなぜこの機能がRHEL 6.1にバックポートされたのかですが、おそらくKVMでの利用を狙ってのことだと考えられます。qemu-kvmは設定によって、KVMゲスト側のI/O方式に関わらずKVMホスト側でDirect I/Oを行わせることができます。仮想化によるシステム統合やプライベートクラウド基盤の構築を行う際、KVMホスト側でqemu-kvmプロセスにcgroupの設定を行うことで、KVMゲストごとのI/Oリソース消費量を制御することができるというわけです。
qemu-kvmにDirect I/Oをさせるには、仮想ディスクのキャッシュモデルにnoneを指定します。

デフォルトはwritethroughです。writethroughの場合はBuffered I/Oが行われるため、cgroupによるI/O帯域、IOPSの制御は先ほどと同じように誤動作してしまいます。ご注意ください。

# dd if=/dev/zero of=test.dat bs=131072 count=8192 oflag=direct
8192+0 records in
8192+0 records out
1073741824 bytes (1.1 GB) copied, 262.503 s, 4.1 MB/s

なおwritebackは設定としては存在しているのですが、障害発生時にデータを失う危険性があるためサポート対象外となっています。
ここまでの内容から、RHEL 6.3の時点でIOPSの制御を行うための前提条件は以下のようになります。

  • KVMによる仮想化を行う
  • 仮想ディスクのキャッシュモデルにnoneを指定する
  • KVMホスト側でqemu-kvmプロセスに対しcgroupの設定を行う

ここでcgroupによるI/O帯域、IOPSの制御はブロックデバイスを対象とした機能ですので、以下の条件も追加されます。

  • KVMゲストのイメージファイルが、NFS上ではなくブロックデバイス上に配置されている

イメージファイルがブロックデバイス上に配置されていない場合は、もう一つの方法であるQEMUのDisk I/O Limits機能が提供されるのを待つことになるかと思います。

IOPSを保証するということ

話をAmazon RDSに戻すと、Amazon Web Servicesは仮想化基盤としてKVMではなくXenを使用しているので、ここまで述べたものとは別の方法でProvisioned IOPSを提供しているということになります。XenでIOPSを制御する方法はすぐには見つかりませんでしたが、もしDom 0でtapdiskプロセスにcgroupが効くのであれば似たような方法で実現できるのかもしれません。あるいは、もっと低いレイヤで実装しているのかもしれません。
IOPSを保証するというのはAmazon RDSのようなパブリッククラウドサービスだけでなく、プライベートクラウド基盤や一般のシステム開発にとっても重要な概念です。近年一つのシステムが一つのストレージを占有できる構成は少なくなってきており、システム基盤の共通化という方針のもと複数システムで少数のサーバやストレージを共有するようになってきています。その際CPUやメモリについては現行を踏襲したハードウェアリソースを割り当ててもらえるのですが、ストレージについては容量しか考慮してもらえないことが多く、あとから深刻な性能問題を起こすことが増えています。
IOPSというものがストレージ製品のカタログに書いていないことも、サイジングの際に容量しか考慮してもらえない原因の一つだと考えています。IOPSは同じストレージ製品でも構成によって大きく変わるので、確かにカタログに書きづらい部分はあります。そこで今回簡単にIOPSを測定できるスクリプトを用意しましたので、これを用いてさまざまなストレージ製品の性能を事前に収集しておくことをおすすめします。
プライベートクラウド基盤を設計する際は、特にDBMSを稼動させる計画がある場合、CPUコア数やメモリ量だけでなくIOPSについても目標値を定め、適切な設備投資を行ってください。
システム統合を行う際は、まず現行システムのリソース消費状況を調査すると思います。その際CPU使用率だけ見るのではなく、必ずI/O状況も見てください。Oracle Databaseであれば、Statspack/AWRレポートのLoad ProfileセクションからPhysical readsとPhysical writes、MySQLであればSHOW ENGINE INNODB STATUSからFILE I/Oセクションのreads/sおよびwrites/sを確認してください。I/O状況の調査は、夜間バッチや業務繁忙期などシステム負荷が高い時間帯を必ず含むようにしてください。そして、各システムのIOPSを合計したよりも高い性能のストレージ製品を調達してください。
Provisioned IOPSはユーザから見ると希望するIOPSを得られるというサービスですが、クラウド基盤提供側やシステム統合の立場から見ると違った意味があります。この機能には、特定のユーザやシステムが必要以上にI/Oリソースを占有して他のシステムに影響を与えることを防ぐ意味があります。現状さまざま前提条件がありますが、RHEL系でKVMを使用している場合は検討する価値のある機能だと思います。最大の課題はOracle DatabaseがKVM上で動作保証されていないことですね。まあ、システム統合のついでにPostgreSQLにマイグレーションするというのもいいかもしれませんね。
Oracle Databaseについていえば、IOPSが足りないときの究極の解決策はOracle Exadataを導入することです。I/O性能が本当に一桁違うので、現行システムのI/O状況があまり分かっていなくてもそこがボトルネックになることはないでしょう。ただEngineered Systemに任せきりになって、いつの間にか自社の技術力がなくなっていたということのないようにしたいものです。
JPOUG Advent Calendar 2012、18日目は@mutatsuさんです。それではまた。

tpcc-mysqlにおける初期データロードのチューニング

ピンポイントチューニング講座です。tpcc-mysqlを使ったことのある方はご存知かと思いますが、最初にtpcc_loadコマンドで行う初期データのロードがかなり遅いです。実は簡単にチューニングする方法があるので、今回はこれをご紹介したいと思います。
tpcc-mysqlについて復習しておきたい方は、以下のエントリを先にご覧ください。

TPC-CのER図を見ると、ほとんどのテーブルに倉庫ID(Warehouse ID)を示すカラムがあることが分かります。

TPC-Cでは倉庫テーブルのレコード件数がデータベース全体の規模を決めるスケールファクタになっていて、これを増やすとそれぞれのテーブルに倉庫IDが2のデータ、倉庫IDが3のデータ、…とデータが積み重なっていく形になっています。ここでそれぞれの倉庫IDのデータは互いに独立しているので、並列化をかけることができます。

商品テーブルのみスケールファクタと関係なく10万レコードで固定されているため、まず最初に商品テーブルのデータロードを行います。そのあと論理CPUの数だけ並列にデータロードを実行します。tpcc_loadにはデータの一部分だけをロードするオプションが用意されていますので、これを利用することができます。


クアッドコアの環境でスケールファクタ1,000、およそ100GBのデータロードを行ってみました。


並列度が低い場合はTurbo Boostが効くのでクアッドコアで4倍とまではいきませんが、きちんと性能が伸びていることが分かると思います。100GBのデータロードに2時間20分なら、まあ待てるかなといったところです。
余談ですがデータ・ウェアハウス向け製品ではデータロードの性能は毎時10TBに達するそうで、MySQLなどとはまるで別世界の話になっています。すごいですね。

データベース負荷テストツールまとめ(5)

というわけで、JPOUG> SET EVENTS 20120721 | Japan Oracle User Groupに参加して発表をしてきました。通常の勉強会と比べて発表者と聴講者の一体感を増すための工夫がなされていて、とても良かったと思います。有限コーヒーかと思ったら無限ビールだったのも驚きです。JPOUGの運営メンバのみなさま、会場を提供してくださった日本オラクルのみなさま、当日お越しいただいたみなさま、どうもありがとうございました。
私のセッションでは、データベース負荷テストツールまとめ(5)と題して過去4回分のまとめと自作ツールの紹介をさせていただきました。JdbcRunnerはOracle Database、MySQLとPostgreSQLの間でTPC-BとTPC-Cの性能比較ができる唯一のオープンソースソフトウェアですので、いろいろ試してみていただければと思います。試した結果をブログなどで公開していただけると作者が喜びます。

プレゼンテーション資料からリンクしているウェブサイトの一覧です。

Java並行処理プログラミング

一冊だけ書籍の紹介をさせてください。

Java並行処理プログラミング ―その「基盤」と「最新API」を究める―

Java並行処理プログラミング ―その「基盤」と「最新API」を究める―

この本はJavaでマルチスレッドプログラミングをするなら必ず読んでおくべきと言われている名著なのですが、2006年に出版されたあとしばらく品切れで入手困難な状態が続いていました。私はこの本をずっと探し続けていて、市の図書館でようやく見つけたときは本当にうれしかったです。この本は素晴らしい本で、どのくらい素晴らしいかと言うと、図書館で借りて読んだあと途中まで作っていたJdbcRunnerのソースコードを全部捨てて書き直したくらいです。この本が手に入らなかったらJdbcRunnerは完成しませんでした。2009年に復刊ドットコムでめでたく復刊され、今では普通に手に入れることができます。

MySQL 5.6におけるsync_binlog=1の改善について＆勉強会のお知らせ

2012年6月のエントリの続きです。前回は同期レプリケーションによるネットワーク遅延のある環境において、MySQLの性能がどの程度低下するのかということを確認しました。その中でも特にsync_binlogが1に設定されている場合、性能が大きく低下するということが分かりました。参考としてAmazon RDSのマルチAZデプロイメントにおいては、性能と信頼性のトレードオフを考慮した結果、sync_binlogがデフォルトで0に設定されているということを調査しました。
タイトルでネタバレしていますが、MySQLの次期バージョン、MySQL 5.6でこのsync_binlog=1の性能が大きく改善します。前回と同じ負荷テストをMySQL 5.5.25からMySQL 5.6.6-labsに差し替えて行った結果を、以下に示します。


前回のMySQL 5.5.25と異なり、sync_binlog=1においても多重度に応じたスループットの伸びが確認できると思います。代表的なところで往復遅延時間(Round Trip Time、以下RTT)が4ミリ秒の場合におけるMySQL 5.5.25、5.6.6-labsの結果を並べてみると、以下のようになります。

素晴らしいですね。

バイナリログのグループ・コミット

この性能改善は、バイナリログに対するグループ・コミットという新機能によってもたらされています。グループ・コミットとは、複数のクライアントからのコミット要求をまとめて処理する機能です。
グループ・コミットがない場合、複数のクライアントからのコミット要求は以下のように順番に処理されます。DBMSとしてACIDを満たすため、バイナリログへの書き込みができるスレッドは同時に一つだけとなっています。

今回の環境はディスクに同期書き込み(pwrite(2)＋fsync(2))をするところでDRBDによるネットワーク遅延の影響を受け、ここにRTT分の時間が加算されます。RTT 4ミリ秒の場合はコミットに最低でも4ミリ秒かかるため、どんなに頑張っても1秒間に250回しかコミットできないということになります。実際にはこれに合わせてInnoDBログにも同期書き込みをする必要があるため、1秒間にコミットできる回数はさらに減ります。
グループ・コミットがある場合、複数のクライアントからのコミット要求は以下のようにまとめて処理されます。

先に来たコミット要求を処理している間に次のコミット要求が来た場合、ディスクへの同期書き込みを両方まとめて行います。バイナリログへの書き込みができるスレッドが同時に一つだけという点は変わらないのですが、一度のfsync(2)で複数のコミット要求を処理することにより、1秒間にコミットできる回数を大幅に増やすことができます。

グループ・コミットのこれまでの経緯

グループ・コミットはACIDを備えたDBMSであれば基本的にサポートしていることが望ましい機能です。本機能がMySQL 5.6でようやくサポートされるにいたった経緯を確認しておきしょう。
まずInnoDBストレージエンジンの方ですが、こちらは2001年にリリースされたMySQL 3.23の時点ですでにグループ・コミットをサポートしていました。
2005年にリリースされたMySQL 5.0において、バイナリログとInnoDBログの整合性を取るための機能改善が行われました。それまではMySQLサーバがクラッシュした際にタイミングによってバイナリログとInnoDBログの整合性が取れなくなり、レプリケーションスレーブが壊れてしまうことがありました。この機能改善はInnoDB側に2フェーズコミットを行わせるという方針で実装されたのですが、これによってバイナリログ有効時にInnoDBのグループ・コミットが効かなくなるという新たな問題が引き起こされました。

2010年にリリースされたMySQL 5.1＋InnoDB Pluginにおいて、sync_binlogが0の場合に限り再びInnoDBのグループ・コミットが効くようになりました。sync_binlogが0の場合は本来の目的であるバイナリログとInnoDBログの整合性を取ることはできないものの、レプリケーションを活用したスケールアウト構成においてマスタの性能を大幅に上げることができるようになりました。

同じく2010年にリリースされたMySQL 5.5において、準同期レプリケーションが導入されました。準同期レプリケーションはグループ・コミットと直接の関係はないのですが、これとMHAを組み合わせることでsync_binlogが0の場合でもマスタ障害によるデータロストやレプリケーションスレーブの不整合を防ぐことができるようになりました。ここまできてようやく性能と信頼性の両方を担保することができるようになったのです。

MySQL 5.6は現在開発マイルストーンが5.6.5まで、実験版が5.6.6-labsまでリリースされています。この5.6.6-labsにおいてついにバイナリログのグループ・コミットが実装されたという次第です。バイナリログのグループ・コミットによってsync_binlog=1における性能が大幅に改善され、共有ストレージやDRBDを用いたクラスタ構成においても、レプリケーションと組み合わせた際の性能と信頼性を両方担保することができるようになります。Amazon RDSでレプリケーションスレーブが壊れて困ったことのある方は、MySQL 5.6の正式版がリリースされてAmazon RDSが対応するまでの辛抱です。

他のDBMSにおけるグループ・コミットのサポート状況

Oracle Databaseははるか昔からグループ・コミットをサポートしていました。ウェブで調べられる範囲では、Oracle 7の時点ですでにサポートされていたことを以下のマニュアルから確認することができます。Oracle 7がリリースされたのは1992年で、いまから20年前のことです。PC-9801FAが初めてi486SXを搭載し、Windows 3.1がリリースされ、Linuxカーネルが0.96だったころの話です。

PostgreSQLは2001年にリリースされたPostgreSQL 7.1でWAL(Write Ahead Logging)が導入され、このときにグループ・コミットもサポートされました。しかし内部の排他制御の設計が適切でなく、これまであまり性能が出ていませんでした。commit_delayというパラメータによってグループ・コミットを発生しやすくすることもできるのですが、こちらの効果も限定的なものでした。
PostgreSQLは次のPostgreSQL 9.2でグループ・コミットの設計が見直され、きちんと性能が出るように改善が図られています。PostgreSQL 9.2は現在ベータ2までリリースされており、順調に行けば2012年中に正式版がリリースされる見込みです。

Oracle Databaseから遅れること20年、MySQL、PostgreSQLもようやく…といったところです。

勉強会のお知らせ

話は変わって、2012年7月21日(土)にJPOUG、日本オラクルユーザ会主催のイベントが催されます。

Oracle OpenWorld Unconferenceに引き続きセッション枠をいただいたので、私は「データベース負荷テストツールまとめ(5)」と題して今回のエントリなどで使ったツールの紹介をする予定です。事前に過去4回分をざっと読み返していただくと、当日の話が分かりやすくなると思います。DBサーバのハードウェア、ソフトウェアを調査される方やクラウドサービスの性能評価をされる方、それからパフォーマンス・チューニングの教材を探している方などにおすすめのセッションです。

イベントとしてはOracle Databaseの話が中心となりますが、木村さんがMySQLの話、小田さんと林さんがDBエンジニアのキャリアについての話をされるなど、Oracle Database以外の話もいろいろ聞けると思います。オラクル青山センターですのでコーヒーもたくさん飲めます。

dateコマンドのオプションについて

前回のエントリで当初「date -s "`LANG=C date`"」というコマンドをご紹介していたのですが、このオプションでは誤動作する場合があるとのご指摘をいただきました。具体的には、環境変数LC_ALLまたはLC_TIMEが設定されている場合に、誤った時刻が設定されてしまいます。

# LANG=C date
Wed Jul  4 02:47:29 JST 2012
# export LC_ALL=ja_JP.UTF-8
# LANG=C date
2012年  7月  4日 水曜日 02:47:38 JST

この状態でdate -sコマンドを投入すると、文字列の解析に失敗して常に午後8時となります。

# export LC_ALL=ja_JP.UTF-8
# date -s "`LANG=C date`"
2012年  7月  4日 水曜日 20:12:00 JST

ロケールの設定はLC_ALL→LC_TIME→LANGという優先順位になっているので、以下のように書くのが正解でした。大変失礼いたしました。

# date -s "`LC_ALL=C date`"

前回のエントリはロケールに依存しない書き方「date `date +'%m%d%H%M%C%y.%S'`」に修正しました。CPU使用率の高騰についてはもう片付いたころかと思いますが、Twitterでいろいろ教えていただいたので、dateコマンドのオプションの書き方をいくつかご紹介しておきます。

# date `date +'%m%d%H%M%C%y.%S'`
# date -s "`LC_ALL=C date`"
# date -s now
# date -s today
# date -s '1 sec -1 sec'
# date -s 'tomorrow yesterday'
# date -s 'next week last day -96 hours -1440 minutes -86400 seconds'

nowが短くて覚えやすいですね。dateコマンドはオプションをBisonで構文解析しているそうで、かなり自由に書くことができます。

うるう秒のあとにMySQLなどのCPU使用率が高騰する件について

2012年7月1日のうるう秒のあとに、MySQLやJavaなどのCPU使用率が高騰する事象が報告されています。

                 CPU     %user     %nice   %system   %iowait    %steal     %idle
08時30分01秒     all      0.02      0.00      0.02      0.04      0.00     99.91
08時40分01秒     all      0.02      0.00      0.02      0.08      0.00     99.88
08時50分01秒     all      0.02      0.00      0.02      0.03      0.00     99.92
09時00分01秒     all      0.11      0.00      0.13      0.04      0.00     99.72
09時10分01秒     all     23.02      0.00     29.09      0.11      0.00     47.78
09時20分01秒     all     23.11      0.00     29.08      0.06      0.00     47.75
09時30分01秒     all     22.85      0.00     28.73      0.03      0.00     48.38
09時40分01秒     all     23.19      0.00     29.59      0.11      0.00     47.12
09時50分01秒     all     23.28      0.00     29.11      0.04      0.00     47.57
top - 03:51:01 up 31 days,  2:49,  2 users,  load average: 1.85, 1.68, 1.64
Tasks: 115 total,   1 running, 114 sleeping,   0 stopped,   0 zombie
Cpu(s): 23.9%us, 22.7%sy,  0.0%ni, 48.3%id,  0.0%wa,  0.2%hi,  4.9%si,  0.0%st
Mem:   2054808k total,  1318072k used,   736736k free,   168900k buffers
Swap:  4194296k total,    11192k used,  4183104k free,   830472k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 1393 mysql     20   0  717m  45m 5988 S 91.3  2.3   1003:34 /usr/sbin/mysqld --basedir=/usr --
 1601 taira     20   0 1399m 108m 9636 S 87.7  5.4   1001:11 java -server -Xmx256m -Xms256m wik
    9 root      20   0     0    0    0 S 42.2  0.0 204:13.15 [ksoftirqd/1]
    4 root      20   0     0    0    0 S  6.3  0.0 219:36.78 [ksoftirqd/0]
   13 root      20   0     0    0    0 S  1.3  0.0 203:36.27 [ksoftirqd/2]
   17 root      20   0     0    0    0 S  0.3  0.0   3:03.04 [events/2]
13372 taira     20   0 15020 1204  932 R  0.3  0.1   0:00.04 top -c
    1 root      20   0 19204 1408 1220 S  0.0  0.1   0:00.61 /sbin/init

MySQLが被害を受けているので調べていたのですが、原因はLinuxカーネルの不具合とのことです。

サーバを再起動するか、以下のコマンドを投入して日付を再設定することで回復します。

# date `date +'%m%d%H%M%C%y.%S'`

影響を受けるシステムはRed Hat Enterprise Linux 6、Ubuntu 12.04など比較的新しいカーネルを搭載したものに限られます。Red Hat Enterprise Linux 5は影響を受けません。また事象の発生は上位のNTPサーバがLeap Indicatorを送信してくる場合に限られ、ntpdを稼動させていない場合は影響を受けません。7月1日のsyslogに以下のようなログが記録されているかどうかをご確認ください。

Jul  1 08:59:59 sbridge kernel: Clock: inserting leap second 23:59:60 UTC

MySQLの場合、MySQL 5.5においてsrv_lock_timeout_threadとsrv_error_monitor_threadというバックグラウンドスレッドがこの不具合により暴走します。MySQL 5.1についてはこれらのバックグラウンドスレッドがfutex(2)を利用していないため、CPU使用率の高騰は発生しませんでした。

日曜だったのが不幸中の幸いでしょうか。対応された方はお疲れさまでした。