Hatena::ブログ(Diary)

SH2の日記 RSSフィード

2012-07-02 うるう秒のあとにMySQLなどのCPU使用率が高騰する件について このエントリーを含むブックマーク

2012年7月1日のうるう秒のあとに、MySQLJavaなどの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使用率の高騰は発生しませんでした。

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