本文書は、CentOS５において、"yum update"を実行するとやたらめったら遅いよ！ という問題を解決するまでの道のりを記録したものである。我輩自身の備忘録と、 後進の人々の参考までに残す所存ナリ。
とにもかくにも、yum updateが遅いんじゃぁぁぁ！一回実行するだけで一時間近く かかる。いったいナニやってんの？どうしてそんなに遅いの？原因は？対策は？ 再発防止策は！？…はぁはぁ。ことほど左様に、我輩はこの問題にストレスを 感じておったわけです。はい。
あ、今回はyum fastestmirrorとかで回避できる問題じゃないことはあらかじめ 調査済みなのであしからず。
「何が遅いのか」を、まずは探さねばならん。言えば、画面上に以下のように 表示されている部分がとにかく遅い。さくさく進んだかなー、と思ったら、 同じところで数分以上うんうんうなったりする。
# time yum upgrade Loaded plugins: rhnplugin, security You can use up2date --register to register. (snip) real 52m43.977s ←遅ぇ！ user 1m45.447s sys 1m22.121s (snip) |
どーせyumがCPU食ってるんだろ？と思ってtopを表示した結果が以下のとおり。 yumがCPUを食って…ないよ？ あれ？
top - 16:32:38 up 13 days, 2:34, 3 users, load average: 1.75, 0.60, 0.24
Tasks: 137 total, 1 running, 136 sleeping, 0 stopped, 0 zombie
Cpu0 : 0.0%us, 0.3%sy, 0.0%ni, 0.0%id, 99.7%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu1 : 0.0%us, 0.0%sy, 0.0%ni,100.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 5695124k total, 4983816k used, 711308k free, 1043052k buffers
Swap: 4194300k total, 0k used, 4194300k free, 3177136k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
4669 root 20 0 12808 1060 768 R 0.3 0.0 0:00.13 top
1 root 20 0 10416 708 592 S 0.0 0.0 0:08.46 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.09 kthreadd
3 root 20 0 0 0 0 S 0.0 0.0 0:00.45 ksoftirqd/0
5 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kworker/u:0
6 root RT 0 0 0 0 S 0.0 0.0 0:00.42 migration/0
7 root RT 0 0 0 0 S 0.0 0.0 0:02.64 watchdog/0
(snip)
|
そんかし、とにかくI/O Waitが高い。ほぼ100%張り付き状態。そのワリには、 上位にはDになってるプロセスやCPU食ってるプロセスは見当たらない。 ということは、本当にものスゴいI/O待ちをしてるということか？でもyum update くらいでそんな巨大なI/Oって要求されるものか？
こういうときは、上のレイヤーから探すに限る。まずはstraceを取って、yumが 何をしようとして止まっているのかを確認してみよう。さすれば、どこが遅いのか くらいはわかるんじゃなかろうか。取り方は以下の通り。CentOS5のころの yumは^Cで止まらないので、まず^Zで止めてkillするのがよろしかろう。
# strace -ttt -o yum_upgrade.txt /usr/bin/yum upgrade Loaded plugins: rhnplugin, security You can use up2date --register to register. centos5_latest: [######################################## ] 7084/9588^Z [1]+ Stopped strace -ttt -o yum_upgrade.txt /usr/bin/yum upgrade # kill %1 [1]+ Terminated strace -ttt -o yum_upgrade.txt /usr/bin/yum upgrade # |
で、これで取れたstraceを見てみると…、ファイル /var/cache/yum/centos5_latest/primary.xml.gz.sqlite をごそごそやってるときに、1024byteのwrite()がやたらめったら遅くなることが あるのがわかった。
1450767911.641136 open("/var/cache/yum/centos5_latest/primary.xml.gz.sqlite", O_RDWR|O_CREAT|O_LARGEFILE, 0644) = 8
(snip)
1450767920.360336 write(8, "\n\0\0\0\26\1V\0\1V\1u\1\224\1\263\1\322\1\361\2\20\2/\2N\2m\2\214\2\253"..., 1024) = 1024
1450767920.360455 _llseek(8, 13068288, [13068288], SEEK_SET) = 0
1450767920.360538 read(8, "\2\0\0\0\27\0]\0\0\1r\321\3\322\3\245\3x\3K\3$\2\375\2\326\2\255\2\204\2["..., 1024) = 1024
1450767920.360671 _llseek(8, 103409664, [103409664], SEEK_SET) = 0
1450767920.360771 write(8, "\n\0\0\0\17\2/\0\2/\2N\2m\2\214\2\253\2\312\2\351\3\10\3'\3F\3e\3\204"..., 1024) = 1024 ★これで５秒かかっている
1450767925.402961 _llseek(8, 7990272, [7990272], SEEK_SET) = 0
1450767925.403094 write(8, "\n\0\0\0\30\0\316\0\0\316\0\361\1\24\0017\1Z\1}\1\240\1\303\1\346\2\t\2,\2O"..., 1024) = 1024
1450767925.403260 _llseek(8, 91370496, [91370496], SEEK_SET) = 0
1450767925.403376 read(8, "\2\0\0\0\26\0\327\0\0\0\\e\1\32\0\372\0\327\1:\1~\1]\1\304\1\241\1\345\2\10"..., 1024) = 1024
1450767925.403499 _llseek(8, 34436096, [34436096], SEEK_SET) = 0
|
1024byteのwrite()に五秒以上かかるなんて！syncなfilesystemじゃないし、 open()にO_DIRECTやO_SYNCフラグが付加されているわけでもない。なぜ？ さらによく見ると、seek()してwrite()してseek()してread()して…の 繰り返しなので、もしかしたら細かなランダムアクセスが原因かもしれない。
ちょい新しいkernelが必要なんだが、プロセスがkernel内のどこを実行しているかを
リアルタイムに知る方法として、/proc/
おおぅなるほど！ext3のjournalか！journal書き込みは同期I/Oだから、ここで
ディスクI/Oを待ってモッスゴ遅くなっておったのだな。確かに、/var/cache/yumは
/(root)と同じパーティションにあって、/ は ext3 のdefault(つまり
data=ordered)でmountされていた。
回避策がないか、ということも含めて、「こうすればもう少し高速になるんじゃ
ないか？」というのを検証してみることにする。
んー、じゃぁ、/var/cache/yum/を、スッゲぇ高速なtmpfsに配置したらどうだろうか、
と思ってしまった。早速実行してみる。一応以前のは取っとく。
は や す ぎ るーッ！
やっぱtmpfs(RAM diskみたいなもん)は偉大だな！Journalもないしな！
ext3のjournalが同期書き込みするから悪いんだろ、という見当がついたので、
これを裏付けるために、/ を ext2 でmountして、yum upgradeがどれだけ高速になるか
確認してみよう。/はinitrd中でmountされるので、ext3→ext2に変更するなら
initrdの再作成とOS再起動が必要なことに注意。
むむぅ、半分くらいにはなったが、思ったよりは早くならないな…。
このときの/proc/
ext3のjournalの同期書き込みが遅いのはわかったので、
じゃぁjournalの書き込みモードを、data=journalからdata=writebackにしたら
どうなるだろう、と思ってしまった。よーしやってみようぜー。なお、障害時の
fsが壊れる恐れがあるとかスッゴいキケンなので、よい子はまねをしないように。
うーん、そんなに大きくは変わらないねぇ。
じゃ、やっぱりランダムアクセスなのかな…。
今回の問題は、以下の三つが重なったために起こった性能問題だったことがわかった。
さらに、後で判ったが、ATF(4Kセクタ)問題も本件に大きな影を落としていた。
4KセクタなHDDに対し、伝統的なパーティショニング(先頭パーティションが63セクタ
目から始まる)を施してしまうと、I/O速度がとたんに1/2以下になっちゃうという
アレ。今回はそれも絡んでた模様。
…有効な対策はないなぁ…。
一応このくらいは考えられるけど。一番効果デカいのはtmpfsだった。
もういっそyum updateするラッパスクリプト書いて、そこでtmpfs使いながら
updateするようにしたらどうかねぇ。
というわけで、遅い遅いとゆってたyum updateをなんとかするという調査はこれにて
終了。最後はちょいもやっとしたけど、原因はわかったのでよかったことにする。
ext3のjournalがかかわるので、これがXFSとかext4とかbtrfsだとまた変わって
くるんだろうけど、CentOS5じゃそのあたりうまく使えないし、とりあえずは
これで調査完了とする。なお、CentOS6とかだとデータベースが整列された
状態でyum repository上に配置されてるらしく、今回のような問題は起こらない。
CentOS5でもそういうことしてくれてればよかったのにね！
# while : ; do cat /proc/3039/stack; sleep 1; done
(snip)
[
# mount | grep " / "
/dev/mapper/VolGroup00-LogVol00 on / type ext3 (rw)
#
■検証
●tmpfs mount
# cd /var/cache/yum/
# mv centos_latest centos5_latest.org
# mkdir centos_latest
# mount -t tmpfs none centos5_latest
# time yum upgrade
(snip)
real 1m24.733s
user 0m34.308s
sys 0m8.343s
(snip)
# rm -rf centos5_latest
# mv centos5_latest.org centos5_latest
●ext2 mount
# vi /etc/fstab
(/ の filesystem type を ext2 に変更)
# mkinitrd -f /boot/initrd-`uname -r` `uname -r`
# shutdown -r now
(再起動)
# time yum update
(snip)
real 23m16.943s
user 0m55.520s
sys 0m36.368s
(snip)
#
# cat /proc/1987/stack
[
●ext3 mount with data=writeback
(設定して再起動した)
# mount | grep " / "
/dev/mapper/VolGroup00-LogVol00 on / type ext3 (rw,noatime,data=writeback)
# time yum update
(snip)
real 20m42.535s
user 0m54.448s
sys 0m36.884s
(snip)
#
■結論
■対策
■おわりに