2009年 2月 23日 月曜日
やっぱり Sun がスキ！
2009年 2月 23日 月曜日
パフォーマンスボトルネックの探し方（続き）
はじめに
前回の エントリ では nxge のチューニングを施して、スループットが 3.6Gbps になった状態での解析結果までをご紹介しました。今回はその続きです。
Apache の最新版を使ってみる
これまで使用して来たバンドル版の Apache はバージョン 2.0.63 です。一方、最新リリースはバージョン 2.2.11 です。2.2.x では I/O の実装が変更されており、これによって性能が上がる可能性があります。Apache の最新版を使用して、どの程度性能が出るか試してみたいと思います。Apache のコンパイルは以下の手順で行いました。今回は 64bit でコンパイルしてあります。また、Apache のキャッシュ機能は使用していません。
# LDFLAGS="-B direct" CFLAGS='-m64' ./configure --prefix=/usr/local/apache2.64bit
# gmake
# gmake install
# PATH=/usr/local/apache2.64bit/bin:${PATH}; export PATH
# LD_LIBRARY_PATH_64=/usr/sfw/lib/amd64; export LD_LIBRARY_PATH_64
# vi /usr/local/apache2.64bit/conf/httpd.conf
# /usr/local/apache2.64bit/bin/apachectl start
Apache 2.2 系を使ってみる事にします
早速性能を測定
dladm コマンドでトラフィックを見てみると、534MB/s, つまり 4.3Gbps ほどの性能が出ています。先ほどは 3.6Gbps でしたので 700Mbps ほど性能が向上しました。初めて 4Gbps を越えましたが、このくらい出ていればリンクアグリゲーションでギガビットイーサネットのポートを束ねるよりも効果的であると言えると思います。まだ 10Gbps の半分も出ていませんので、もう少し解析を続けたいと思います。
# dladm show-dev -s -i 1 nxge0
...
ipackets rbytes ierrors opackets obytes oerrors
nxge0 125715 7550295 0 396034 568337848 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 125957 7567101 0 390700 560692368 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 126931 7621305 0 392393 563126976 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 126817 7614564 0 392250 562935589 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 127240 7638855 0 389528 559050398 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 127175 7635648 0 391883 562428220 0
性能が 4Gbps を越えました
vmstat
まずは vmstat を見てみます。cpu の id が 0% になっており、やはり CPU ボトルネックです。cpu の sy が 100% なので、CPU は sys で使われている様です。
# vmstat 1 kthr memory page disk faults cpu r b w swap free re mf pi po fr de sr s0 s1 s2 -- in sy cs us sy id ... 18 0 0 28253364 30362228 75904 11 0 0 0 0 0 0 0 0 0 595386 1150 128655 0 100 0 17 0 0 28253364 30362148 78020 11 0 0 0 0 0 0 0 0 0 611144 1109 127456 0 100 0 16 0 0 28253364 30362240 78773 11 0 0 0 0 0 0 0 0 0 616220 1070 127647 0 100 0 19 0 0 28253364 30362072 77473 11 0 0 0 0 0 0 0 0 0 607398 1036 127760 0 100 0 22 0 0 28253364 30362200 75965 11 0 0 0 0 0 0 0 0 0 596055 1269 128268 0 100 0 23 0 0 28253364 30362080 74654 11 0 0 0 0 0 0 0 0 0 588108 1122 129089 0 100 0
CPU ボトルネックです
prstat
続いて prstat も見てみます。httpd の SYS が多いので、先ほどと同様 Apache のプロセスが SYS の発生源になっています。
# prstat -mL 1
...
PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID
20798 daemon 0.0 11 0.0 0.0 0.0 0.0 72 17 1K 3 9 0 httpd/1
20687 daemon 0.0 10 0.0 0.0 0.0 0.0 65 25 1K 1 0 0 httpd/1
20857 daemon 0.0 9.8 0.0 0.0 0.0 0.0 72 19 1K 4 11 0 httpd/1
20686 daemon 0.0 9.3 0.0 0.0 0.0 0.0 76 15 1K 7 15 0 httpd/1
20801 daemon 0.0 7.3 0.0 0.0 0.0 0.0 82 11 864 9 7 0 httpd/1
20877 daemon 0.0 7.0 0.0 0.0 0.0 0.0 81 12 943 2 6 0 httpd/1
20743 daemon 0.0 7.0 0.0 0.0 0.0 0.0 83 10 1K 3 2 0 httpd/1
20837 daemon 0.0 7.0 0.0 0.0 0.0 0.0 81 13 942 1 0 0 httpd/1
20659 daemon 0.0 6.6 0.0 0.0 0.0 0.0 75 19 842 2 7 0 httpd/1
20731 daemon 0.0 6.4 0.0 0.0 0.0 0.0 78 15 802 8 11 0 httpd/1
20835 daemon 0.0 6.0 0.0 0.0 0.0 0.0 84 10 722 0 0 0 httpd/1
CPU を消費しているのは Apache が発行しているシステムコールでした
システムコールの種類
truss -c でシステムコールの種類を割り出します。出力の中の elapsed の値は計測を行っていた期間を示しており、sys totals の値はシステムコールの総計です。詳しく見てみると sys totals が約 67 秒なのに対し、sendfilev というシステムコールの実行時間もほぼ同じ 67 秒となっています。どうやら sendfilev が殆どの時間を使っている様に見て取れます。sendfilev は sendfile のバリエーションですが sendfile はデータの受け渡しがカーネル内で済むので、read してから write する場合の様にユーザランドを経由する場合に比べて効率的です。これが 2.0 に比べて性能が向上した理由の一つであると考えられます。
# truss -c -p `pgrep -nx httpd`
^C
syscall seconds calls errors
read .015 631 12
write .031 613
open .024 613
close .009 619
stat .043 613
getpid .004 613
fcntl .000 6
fcntl .000 6
sendfilev 67.145 1164 551
pollsys .015 563
accept .000 6
shutdown .000 6
getsockname .000 6
-------- ------ ----
sys totals: 67.291 5459 563
usr time: .230
elapsed: 3130.450
CPU を消費しているシステムコールは sendfilev でした
何が行われているかをもう少し細かく見てみる
truss を使って更に詳しく見てみましょう。まず read システムコールが発行されています。read されている中身は "GET /008 HTT..." ですので、HTTP の GET リクエストを受け取っているのだと思われます。read の引数にあるファイルディスクリプタ 11 番は恐らくソケットでしょう。次に write をしています。write の中身は "192.168.0.2 " ですが、これは Apache のアクセスログの書き込みであると思われます。続いて、リクエスト要求のあったファイルを stat で確認しています。次のシステムコールは getpid で、プロセス ID を取得しています。open でリクエストのあったファイルを開き、最後に sendfilev で送信しています。
# truss -o /var/tmp/truss-httpd-02.dump -E -vall -p `pgrep -nx httpd`
...
0.0000 read(11, " G E T / 0 0 8 H T T".., 8000) = 105
0.0001 write(8, " 1 9 2 . 1 6 8 . 0 . 2 ".., 78) = 78
0.0000 close(12) = 0
0.0001 stat("/data/web/008", 0xFFFFFD7FFFDFF3A0) = 0
d=0x000000B500010002 i=12 m=0100766 l=1 u=0 g=0 sz=10485760
at = Feb 2 20:24:19 JST 2009 [ 1233573859 ]
mt = Jan 30 23:06:43 JST 2009 [ 1233324403 ]
ct = Feb 2 13:39:24 JST 2009 [ 1233549564 ]
bsz=131072 blks=20485 fs=zfs
0.0000 getpid() = 20928 [20649]
0.0000 open("/data/web/008", O_RDONLY) = 12
0.1153 sendfilev(0, 11, 0x0058B1B8, 2, 0xFFFFFD7FFFDFEDB0) = 10486053
sfv_fd=-2 sfv_flag=0x0 sfv_off=5833320 sfv_len=293
sfv_fd=12 sfv_flag=0x0 sfv_off=0 sfv_len=10485760
read -> write -> stat -> open -> sendfilev の順に処理が流れていました
その他の分析
システムコールの流れは分かりましたが、もう少し別の角度からも状況を分析したいと思います。使用するコマンドは mpstat です。出力を見てみると Apache 2.0 の時に比べて xcal, intr, migr, smtx が目立って多くなっています。いずれも CPU の消費を増やす原因となります。migr はプロセスが別のプロセッサに移動した回数を示しており、以前はこの値が 200 を越えると多いと言われていました。
# mpstat 1 ... CPU minf mjf xcal intr ithr csw icsw migr smtx srw syscl usr sys wt idl 0 0 0 60131 77736 4187 14579 43 1300 1730 7157 25 0 100 0 0 1 0 0 62342 77830 4036 14572 37 1254 1742 7189 19 0 100 0 0 2 0 0 68504 75532 3900 15175 82 1164 1791 7842 89 1 99 0 0 3 0 0 70467 75267 3829 15700 88 1254 1709 7943 343 1 99 0 0 4 0 0 70624 76365 3808 15938 95 1305 1844 8298 101 0 100 0 0 5 0 0 66244 76809 3622 16717 92 1341 1862 8094 108 0 100 0 0 6 0 0 70596 76814 3992 16525 89 1356 1879 8080 115 1 99 0 0 7 11 0 78071 74775 3712 17020 88 1143 1970 8680 341 1 99 0 0
xcal, intr, migr, smtx が多くなっています
インタラプトの原因
mpstat で intr が多かった原因を探るため、lockstat コマンドを使用します。lockstat に -I オプションを付けるとカーネル内のインタラプト処理のプロファイルを見る事が出来ます。-g オプションを付けると、関数 a() が別の関数 b() を呼び出した時に、b() の行った処理も a() に加算される様になり、インタラプトを発生させている大元の処理を統計情報上に浮かび上がらせる事が可能です。出力結果は Caller が呼び出し元の関数で、Count が実行回数を示しています。出力内容を見てみると、sys_syscall と sendfilev がトップに表示されていますので、intr の原因は sendfilev の様です。
# lockstat -kgIW sleep 10 Profiling interrupt: 7848 events in 10.109 seconds (776 events/sec) Count genr cuml rcnt nsec Hottest CPU+PIL Caller ------------------------------------------------------------------------------- 5161 66% ---- 0.00 7356 cpu[2] sys_syscall 5152 66% ---- 0.00 7302 cpu[2] sendfilev 5151 66% ---- 0.00 7303 cpu[2] sendvec_chunk 5115 65% ---- 0.00 7308 cpu[2] snf_segmap 2977 38% ---- 0.00 7055 cpu[2] tcp_output 2970 38% ---- 0.00 7059 cpu[2] tcp_wput_data 2891 37% ---- 0.00 6941 cpu[2] kstrwritemp 2882 37% ---- 0.00 7091 cpu[2] tcp_send 2837 36% ---- 0.00 6960 cpu[2] sostream_direct 2803 36% ---- 0.00 6969 cpu[2] tcp_wput
sendfilev がインタラプトを発生させている原因でした
lockstat 続き
lockstat -I の -g オプションを外した出力も合わせて掲載しておきます。bcopy と mutex_enter が頻繁に呼び出されている事が分かります。もしあなたがカーネル開発者であれば、この情報がチューニングに役立つはずです。
# lockstat -kIW sleep 10 Profiling interrupt: 7848 events in 10.106 seconds (777 events/sec) Count indv cuml rcnt nsec Hottest CPU+PIL Caller ------------------------------------------------------------------------------- 1196 15% 15% 0.00 5029 cpu[5] bcopy 1044 13% 29% 0.00 4835 cpu[2] mutex_enter 541 7% 35% 0.00 8162 cpu[6] mutex_vector_exit 340 4% 40% 0.00 4763 cpu[5] nxge_start 294 4% 44% 0.00 4815 cpu[0] atomic_add_int_nv 199 3% 46% 0.00 4772 cpu[2] atomic_add_32 197 3% 49% 0.00 4898 cpu[7] tcp_send_data
lockstat で -g オプションを付けないと枝葉の関数を見る事が出来ます
スピンミューテックスの原因
smtx はロックが取得出来なかった場合にスピンした回数です。頻繁にスピンが発生すると CPU を空費してしまうため、なるべく避けたい状態です。スピンミューテックスも lockstat コマンドで詳しく見る事が可能です。こちらも上位に sys_syscall と sendfilev が上がっており、sendfilev がスピンミューテックスの原因になっている事が分かります。
# lockstat -g -D 10 sleep 10 Adaptive mutex spin: 768605 events in 10.187 seconds (75452 events/sec) Count genr cuml rcnt nsec Lock Caller ------------------------------------------------------------------------------- 701380 91% ---- 0.00 29158 0xffffffff86fc8f58 sys_syscall+0x17b 698865 91% ---- 0.00 29156 0xffffffff86fc8f58 sendfilev+0x380 698865 91% ---- 0.00 29156 0xffffffff86fc8f58 sendvec_chunk+0x85c 365684 48% ---- 0.00 28361 0xffffffff86fc8f58 rrw_enter+0x18 365684 48% ---- 0.00 28361 0xffffffff86fc8f58 rrw_enter_read+0x11 364292 47% ---- 0.00 29465 0xffffffff86fc8f58 fop_getpage+0x47 364292 47% ---- 0.00 29465 0xffffffff86fc8f58 segmap_fault+0x118 364292 47% ---- 0.00 29465 0xffffffff86fc8f58 zfs_shim_getpage+0x37 364292 47% ---- 0.00 29465 0xffffffff86fc8f58 snf_segmap+0x214 335696 44% ---- 0.00 30026 0xffffffff86fc8f58 rrw_exit+0x11 ------------------------------------------------------------------------------- ...
smtx の原因も sendfilev でした
ここまでのまとめとチューニングの候補
Apache 2.0.x から 2.2.x に変更する事で性能が上がりました。性能が向上した原因はシステムコールが read, write から sendfilev に変更された事の様です。一方、sendfilev を使用する事によりインタラプトやスピンミューテックスが増加しました。
先ほどは Apache のチューニングが有効であると書きましたが、今度は一つのシステムコールの中で CPU を使っているので、アプリケーションのチューニングは効果が無さそうです。一方 sendfilev() はファイルシステムからデータを読み出していますので、ファイルシステムのチューニングは有効であると思われます。ファイルシステムに Sun StorageTek QFS を使用してブロックサイズを増やしてあげると非常に効果が高そうです。
更に、CPU 性能がボトルネックで、プログラムの並列度には制限が無いため Sun SPARC Enterprise T5440 に置き換えると非常に効果的かもしれません。
lighttpd（ライティ）
今回のベンチマークは HTTP のダウンロードの性能を計測していますが、必ず Apache を使用しなくてはいけない訳ではありません。そこで Youtube や Wikipedia のコンテンツ配信でも使用されているという lighttpd を試してみる事にします。
lighttpd は軽量・高速が売りの http サーバです。元々はシングルプロセス、シングルスレッドの実装でしたが、現在はマルチプロセスで構成する事が可能になっており、今回の様なマルチコアのシステムでもリソースを有効に使えます。また、Solaris 向けのチューニングも幾つか入っており、性能が期待出来ます。
Youtube に倣って lighttpd を使用してみます
インストール
lighttpd は最新版の 1.4.20 をダウンロードして、64bit でコンパイルしてあります。
# /usr/local/sbin/lighttpd -v lighttpd-1.4.20 - a light and fast webserver Build-Date: Feb 2 2009 11:51:34 # file /usr/local/sbin/lighttpd /usr/local/sbin/lighttpd: ELF 64-bit LSB executable AMD64 Version 1, dynamically linked, not stripped, no debugging information available
lighttpd は最新版を 64bit でコンパイルしました
lighttpd の構成
lighttpd の構成は lighttpd.conf に記述します。server.event-handler パラメータは多重 I/O 待ちの方法を設定するパラメータです。今回は Solaris 固有の /dev/poll を使用する事にしました。server.network-backend はソケットにデータを書き出す方法を設定するパラメータです。writev を使用する様に設定してあります。server.max-worker はフォークするプロセスの数です。今回は 8 コアのサーバなので 8 を指定しました。
# cat /etc/lighttpd/lighttpd.conf server.document-root = "/data/web/" server.errorlog = "/var/log/lighttpd/error.log" server.port = 80 mimetype.assign = ( ".html" => "text/html", ".txt" => "text/plain", ".jpg" => "image/jpeg", ".png" => "image/png" ) static-file.exclude-extensions = ( ".fcgi", ".php", ".rb", "~", ".inc" ) index-file.names = ( "index.html" ) server.event-handler="solaris-devpoll" server.network-backend = "writev" server.max-worker = 8
Solaris の /dev/poll を使用する設定にしてあります
早速測定
dladm コマンドで性能を測定します。約 803MB/s なので 6.4Gbps ほど出ている様です。先ほどが 4.3Gbps でしたので、2Gbps 以上速くなりました。1.5 倍以上性能が向上したことになります。何故これほど性能が上がったのか原因を探って行きたいと思います。
# dladm show-dev -s -i 1 nxge0
...
ipackets rbytes ierrors opackets obytes oerrors
nxge0 121333 7292772 0 551333 841121608 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120944 7268148 0 551986 842231276 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120353 7229502 0 550841 840587112 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120500 7235352 0 550710 840466908 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120853 7255338 0 551833 842210781 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120397 7228176 0 550543 840241368 0
lighttpd で性能が 1.5 倍になりました！
システムの状況
vmstat でシステム全体の状況を見てみますと、id が 0 なのでやはり CPU ボトルネックです。システムコールの回数と sys の割合は先ほど同様高くなっています。先ほどに比べて re と mf の数値が高くなっています。mf はマイナーフォルトでメモリのページングが多く発生している兆候となります。ページングも CPU を消費する処理です。
# vmstat 1 ... kthr memory page disk faults cpu r b w swap free re mf pi po fr de sr s0 s1 s2 -- in sy cs us sy id 14 0 0 28594444 30200584 60604 78476 0 0 0 0 0 0 0 0 0 40506 32755 50390 1 99 0 14 0 0 28594444 30210288 57141 75336 0 0 0 0 0 0 0 0 0 40588 32561 50220 1 99 0 11 0 0 28594444 30210140 58610 76582 0 0 0 0 0 0 0 0 0 40551 33251 49931 1 99 0 14 0 0 28594444 30204448 60581 78293 0 0 0 0 0 0 0 0 0 40741 33673 50099 1 99 0 18 0 0 28594444 30199220 63630 80969 0 0 0 0 0 0 0 0 0 40588 33167 49921 1 99 0 17 0 0 28594444 30172716 66668 83617 0 0 0 0 0 0 0 0 0 40442 32964 49719 1 99 0 6 0 0 28594444 30170932 70143 86752 0 0 0 0 0 0 0 0 0 40295 32065 49771 1 99 0
ページングが増えている様です
prstat
続いて prstat -L でプロセスの稼働状況を確認します。prstat は他の UNIX でいう top コマンドと同等のコマンドです。出力内容を見ると、シングルスレッドの lighttpd プロセスが 8 つ起動している様です。RSS のカラムがプロセスサイズですが lighttpd プロセスのサイズは 50MB から 100MB ほどあり、多少大きい様に思えます。
PID USERNAME SIZE RSS STATE PRI NICE TIME CPU PROCESS/LWPID
21130 root 159M 101M cpu6 54 0 0:04:22 7.8% lighttpd/1
21131 root 153M 93M cpu2 58 0 0:04:19 7.8% lighttpd/1
21127 root 78M 50M cpu0 54 0 0:04:22 7.7% lighttpd/1
21129 root 100M 64M run 55 0 0:04:20 7.7% lighttpd/1
21126 root 75M 47M cpu7 57 0 0:04:21 7.7% lighttpd/1
21128 root 87M 53M cpu5 60 0 0:04:18 7.6% lighttpd/1
21125 root 91M 56M run 55 0 0:04:20 7.6% lighttpd/1
21132 root 94M 52M cpu4 53 0 0:04:18 7.6% lighttpd/1
21136 root 3892K 3080K cpu0 59 0 0:00:01 0.1% prstat/1
1009 root 3108K 1964K sleep 59 0 0:00:44 0.0% iostat/1
lighttpd のプロセスサイズは 50MB - 100MB になっていました
mpstat
mpstat も見てみましょう。Apache 2.2 の時に出ていた xcal が無くなりました。migr も大分少なくなっています。
CPU minf mjf xcal intr ithr csw icsw migr smtx srw syscl usr sys wt idl 0 11348 0 0 5224 3366 6132 1697 181 1644 57 4184 1 99 0 0 1 11974 0 0 4836 3197 6034 1669 187 1745 54 3456 1 99 0 0 2 13513 0 0 4937 3220 6307 1801 175 1879 81 4409 2 98 0 0 3 12179 0 0 5037 3310 6147 1785 188 1763 66 4106 1 99 0 0 4 11807 0 0 4910 3150 6412 1704 206 1755 43 4017 1 99 0 0 5 12650 0 0 4928 3191 6494 1768 222 1848 60 4198 1 99 0 0 6 12438 0 0 5036 3318 6125 1724 217 1832 41 4015 1 99 0 0 7 11436 0 0 4972 3321 6025 1691 163 1807 47 3821 1 99 0 0
xcal が無くなりました
システムコールを観察する
再び truss -c の結果です。write が突出している一方、read が殆どありません。mmap / munmap の回数が多い様です。先ほど prstat でプロセスサイズが大きかったのはファイルを mmap してから write している所為かもしれません。
# truss -c -p `pgrep -nx lighttpd`
^C
syscall seconds calls errors
read .004 408 4
write 22.667 120902
open .088 4586
close .024 4574
time .000 299
stat .120 4182
ioctl .143 707
fcntl .001 418
fcntl .000 14
mmap .158 7586
munmap 2.898 7573
writev .009 404
memcntl .281 7586
accept .001 28 14
-------- ------ ----
sys totals: 26.399 159267 18
usr time: .612
elapsed: 49.520
lighttpd は mmap, munmap している様です
システムコールの流れ
truss コマンドを使って実際に何が起きているのかを見てみましょう。ログを見ると、まず HTTP の GET を read() で受け取り、リクエストされたファイルを open() して、mmap() し、それをそのまま write() している様です。また一回の write() のサイズは 64KB である事が分かります。
# truss -o /var/tmp/truss-lighttpd-02.dump -E -vall -p `pgrep -nx lighttpd`
# less /var/tmp/truss-lighttpd-02.dump
...
0.0000 read(211, " G E T / 0 3 3 H T T".., 127) = 81
0.0001 writev(211, 0x00449CF0, 1) = 188
iov_base = 0x00749D50 iov_len = 188
0.0000 open("/data/web/033", O_RDONLY) = 212
0.0000 fcntl(212, F_SETFD, 0x00000001) = 0
0.0000 mmap(0x00000000, 524288, PROT_READ, MAP_SHARED, 212, 0) = 0xFFFFFD7FF7A13000
0.0001 memcntl(0xFFFFFD7FF7A13000, 524288, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
0.0002 write(211, "¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0".., 524288) = 65536
0.0000 write(5, "D3¥0¥0¥004¥0¥0¥0", 8) = 8
0.0000 accept(3, 0xFFFFFD7FFFDFF810, 0xFFFFFD7FFFDFF80C, SOV_DEFAULT) Err#11 EAGAIN
0.0005 write(6, "¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0".., 458752) = 65536
0.0005 write(7, "¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0".., 327680) = 65536
0.0004 write(8, "¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0".., 65536) = 65536
0.0003 write(10, "¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0".., 262144) = 65536
0.0003 write(12, "¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0".., 393216) = 65536
0.0003 write(13, "¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0".., 131072) = 65536
0.0009 write(14, "¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0¥0".., 458752) = 65536
mmap したファイルを write している様です
Software Large Send Offload
Solaris の LSO 機能を利用すると CPU 負荷を減らす事が出来ます。nxge の場合は nxge.conf で soft-lso-enable というパラメータを設定します。
# vi /platform/i86pc/kernel/drv/nxge.conf soft-lso-enable = 1; # reboot
LSO を使用した場合の測定結果
dladm の出力は 846MB/s ほどですので大体 6.7Gbps の性能になりました。この記事の一番最初では 1.9Gbps でしたので、スループットは 3.5 倍以上になりました。7Gbps 近くまで出ていますので、10GbE のメリットを十分享受出来ていると言っていいのではないかと思います。
# dladm show-dev -s -i 1 nxge0
...
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120475 7234656 0 583893 890204366 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120443 7232979 0 582062 887277854 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120462 7232418 0 583000 889047252 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120278 7222350 0 582143 887593626 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 120124 7214892 0 581692 886646548 0
ipackets rbytes ierrors opackets obytes oerrors
nxge0 119646 7188804 0 578414 881221640 0
7Gbps 近くまで性能が上がりました！
ここまでのまとめと考えられるチューニング
Apache 2.2.x から lighttpd に変更する事で大幅に性能が上がりました。性能が上がった要因はシステムコールが sendfilev から mmap + write に変更された為の様です。また write のサイズも Apache 2.0.x に比べて大きくなっていました。更に LSO を使用する事で 7Gbps 近くまで性能を挙げる事が出来ました。
更に性能を上げる為に、Jumbo Frame を使用してパケットサイズを 8K 等にすれば効果があると思われます。また mmap による page-in が多少足かせになっている様ですので、Solaris の MPSS(multiple pagesize support) 機能を使用してプロセスのメモリページサイズを大きく取ってあげれば I/O の抜けが良くなりそうです。
今回は Apache 2.0.x, 2.2.x, lighttpd を使用しましたが、Open Web Server や nginx 等、別の HTTP サーバも試してみると良いかもしれません。もちろんサーバをもっと性能が良い Sun SPARC Enterprise T5440 等に変更すれば更にスループットは向上します。
全体のまとめ
最後に簡単に振り返ってみますと、HTTP サーバには幾つかの実装があり、それぞれ性能や性質が異なっていました。Apache 2.0 は 8KB 単位で read して write しており、Apache 2.2 は sendfilev を使用していました。lighttpd は mmap して 64KB 単位で write していました。結果として一番速かったのは lighttpd でしたが、Solaris の解析ツールを使用する事で何が性能に寄与しているのかをより深く知る事が出来ました。vmstat を出発点として色々なツールを組み合わせる事により、アプリケーションの動きをつぶさに見て取れる事がご理解頂けたと思います。
一点強調しておきたいのは今回の解析例では DTrace を使用していないという事です。もちろん DTrace を使えば更に深く広く調査を進める事が可能ですが、DTrace のスクリプトを作成せずとも今回ご紹介した様な解析が出来る様に沢山のツールが揃っている事が Solaris の優れた点の一つだと思います。今回ご紹介出来なかった中にも便利なツールが沢山ありますので、是非色々と試して頂けたらと思います。以上、Solaris でボトルネック解析をする一例をご紹介しました。
注意
今回は検証用マシン調達の都合上、数年前の古い CPU を使用しています。最新の機材を使用すれば 10GbE を溢れさせる事は十分可能です。一例として http://blogs.sun.com/puresee/entry/10_gigabit_ethernet_on_ultrasparc1 をご覧下さい。
ダウンロードするファイルのサイズや数を変更した場合、今回の解析結果はそのまま当てはまらないかもしれません。lighttpd の実装は mmap を使用しているとご紹介しました。例えば、今回の負荷シナリオではコンテンツのサイズを 10MB としていましたが、これが 1GB だったら性能はどうなるでしょうか。
今回は負荷生成に ab を使用しましたが、より現実的な負荷シナリオやレスポンスタイムの監視を実現するため JMeter 等のツールを使われるとより良いベンチマークになると思います。
参考文献
- 今回の記事の内容を OpenSolaris Hot Topics Seminar でお話した際の スライド
- 同じく OpenSolaris Hot Topics Seminar でお話したのを録画したムービー 1, 2 と 音声 ファイル
- sys の原因を解析するコマンドの紹介
- Solaris のコマンドの挙動を確認する
- Solaris のマニュアル
- Solaris Internals のサポートページ
Posted at 12:50午後 2 23, 2009 by Daisuke Homma in Sun | 投稿されたコメント[0]
投稿されたコメント:
Subscribe!