2013年9月アーカイブ

トークの内容はひとつ前のエントリにて紹介していますが、なんとBest Talk Awards 第3位をいただきました！ありがとうございます！

牧さん、941さん、JPAの皆様、ボランティアの皆様、参加した全てのPerl Mongersの皆様と、妻と子供たちに感謝です。

ベストトーク賞第3位の賞品は「国内の技術カンファレンスの参加チケット費用」ということでPerlに限らず、様々なカンファレンスに参加できるようです。せっかくなのでPerl以外で、LT発表ができるところに行ってみたいのでオススメがあれば @kazeburo 宛にメンション頂けると嬉しいです！

YAPC::Asia 2013 2日目は、藤原さんの「社内ISUCONの作り方」、弊社の話ですが、牧さんの「本当にあったレガシーな話」、myfinderさんの「フルテストも50msで終わらせたい」あたりがよかった。ISUCONの課題はもっと社内の研修や勉強会でつかってもらえるようにしたいところ。

あと、妻と子供も日吉まできていたので、京都から参加していた友人と一緒にご飯食べたり、GrowthForecastの話を@sonotsさんとしたり、とても楽しい日になりました。

来年の運営がどうなるかまだ分からないですが、この楽しいお祭りを続けることができるよう協力して行きたい。

YAPC::Asia 2013 Tokyo の1日目に「PSGI/Plack・Monocerosで学ぶハイパフォーマンスWebアプリケーションサーバの作り方」というタイトルで発表をしてきました

livedoorBlogのPlack/Starlet化を背景として、この半年間ぐらいの間、PlackやStarletの高速化に取り組んできました。この発表はその中で学んだPSGI/Plackの基本仕様、PSGIサーバの構築の方法と最適化、PSGIサーバの選び方、またMonocerosについて紹介しました。

多くのWebアプリケーションではこの最適化の恩恵を受ける事はないかもしれません。しかし、アプリケーションが動作する基盤がどのように実装され、最適化のテクニックが施されているかを知る事により、アプリケーション層の最適化がより捗るのではないかと思います。

質問等があれば気軽に、コメントやtwitterでメッセージを下さいませ。

1日目のトークでは、tokuhiromのFuture Perlの話。新しい構文や正規表現やpfjのexobrainなど、が気になりました。

あと、前夜祭のLT-Thonでも喋りました。こちらはなんとベストエルティニスト賞というのを頂いてしました。ありがとうございます。トロフィー、ちゃんと持ち帰りました。

喋った内容はApache::LogFormat::Compilerについてです。モジュールの成り立ちとAxsLog、AccessLogへの組み込みされた経緯などの紹介です

このスライドの中でつかってる。BACK TO THE FUTUREのレゴ。Amazonで買えます。ご興味があればこちらもどうぞ

ツチノコブログのWEBサーバベンチマークツール比較の記事で紹介されていた。WebサーバのG-WAN。この記事によると凄く速いようです。

Intel Xeon E5-2640 (6コア/12スレッド 2.50GHz) を2つというサーバで

gwan　 334944 req/s
nginx　111842 req/s

と、速いと言われているnginxの3倍の速度を出しています。

このベンチマーク結果がとても気になったので、なぜG-WANが速いのか、自分でも検証してみました。

結論から言うと以下の2つ。

1) G-WANはデフォルトで物理CPUに合わせた数のスレッドを起動する
2) HTMLファイルも一度読み込んでキャッシュする

という事です。

今回はAWSのcc2.8xlarge(E5-2670 8コア/16スレッド 2.60GHz *2)を使ってベンチマークを行いました。OSはAmazon Linuxです。

G-WANの起動とベンチマーク

G-WANはソースコードが公開されていないので、バイナリをダウンロードしてきて起動します

$ wget http://gwan.com/archives/gwan_linux64-bit.tar.bz2
$ tar jxf gwan_linux64-bit.tar.bz2 
$ cd gwan_linux64-bit
$ ./gwan

これで8080でListenされるはずなのですが、なぜか分かりませんが8080じゃなくランダムなポートが割り振られていました。 ここのところはもっと検証する必要があるかもしれませんが、ソースコード公開されてないし、パス。

pstreeコマンドでみると

$ pstree $(pgrep gwan)
gwan───16*[{gwan}]

となり、デフォルトで16個のスレッドが起動されてました。

ドキュメントルートディレクトリ以下に”hello world”と書かれたファイルを設置してwrkを使ってベンチマークすると

$ ./wrk -c 300 -t 4 -d 10 http://localhost:40832/helloworld.html
Running 10s test @ http://localhost:40832/helloworld.html
  4 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
  　Latency   511.46us  165.04us  17.13ms   89.64%
　　Req/Sec    78.63k     8.37k   98.00k    68.01%
  2957522 requests in 10.00s, 744.62MB read
　Requests/sec: 295814.08
　Transfer/sec:     74.48MB

となりました。ツチノコブログと大体同程度、30万req/sec速いですね!

nginxの起動とベンチマーク

nginxはyumでいれました。

$ sudo yum install nginx

この状態で、service nginx start してベンチマークを行うと

$ ./wrk -c 300 -t 4 -d 5 http://localhost/helloworld.html
Running 5s test @ http://localhost/helloworld.html
  4 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     5.94ms   49.24ms   3.60s    99.00%
    Req/Sec     8.61k     2.27k   15.78k    65.09%
  162163 requests in 5.00s, 34.94MB read
  Socket errors: connect 0, read 0, write 0, timeout 116
Requests/sec:  32440.86
Transfer/sec:      6.99MB

なんか遅いですね。timeoutのエラーも出てるし

この時のnginx.confの主な箇所を抜き出すと

worker_processes 1;
events {
    worker_connections  1024;
}

http {
    include       /etc/nginx/mime.types;
    default_type  application/octet-stream;
    access_log off;
    sendfile        on;
    keepalive_timeout  65;
    access_log off;
    server {
        listen       80;
        server_name  localhost;
        location / {
            root   /usr/share/nginx/html;
            index  index.html index.htm;
        }
    }
}

となっています。デフォルトと異なるのは access_log を offにしている点

nginxのデフォルトは、worker_processes が 1 なので、32個CPUが見えても 1個しかCPUを利用しません。最初から16個使うG-WANとここが大きく異なります。

nginxのチューニング

これは差が付き過ぎ。ということでnginxのチューングを行います。

スレッド数

G-WANのスレッドと同じ数のプロセスを起動します

worker_processes 16;
worker_cpu_affinity 0000000000000001 0000000000000010 0000000000000100 0000000000001000 0000000000010000 0000000000100000 0000000001000000 0000000010000000 0000000100000000 0000001000000000 0000010000000000 0000100000000000 0001000000000000 0010000000000000 0100000000000000 1000000000000000;

acceptのタイミング調整

acceptシリアライズ化のためのmutexが確保出来なかった際に、retryするまでの待機時間だそうです。デフォルトは500msec。

accept_mutex_delay 100ms;

keepalive

1接続中に何回のリクエストまで受けるかの設定、nginxのデフォルトは 100 しかないので増やします

keepalive_requests 500000;

これでベンチマークを行うと、

$ ./wrk -c 300 -t 4 -d 10 http://localhost/helloworld.html
Running 10s test @ http://localhost/helloworld.html
  4 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   525.74us  218.71us   5.46ms   74.17%
    Req/Sec    85.20k     9.04k   98.44k    87.22%
  3213990 requests in 10.00s, 695.78MB read
Requests/sec: 321432.91
Transfer/sec:     69.59MB

この時点でG-WANを少し超えました。

ファイルIOレス化

G-WANに対してアクセスをかけながらstraceで見ていて、一つ気になったことがあります。

accept4(53, 0x7ff3982dce10, [16], SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(47, {{EPOLLIN, {u32=7831200, u64=7831200}}}, 1024, 1000) = 1
accept4(53, {sa_family=AF_INET, sin_port=htons(34988), sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_NONBLOCK) = 70
setsockopt(70, SOL_TCP, TCP_NODELAY, [1], 4) = 0
epoll_ctl(47, EPOLL_CTL_ADD, 70, {EPOLLIN|EPOLLPRI|0x2000, {u32=70, u64=70}}) = 0
accept4(53, {sa_family=AF_INET, sin_port=htons(35008), sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_NONBLOCK) = 113
setsockopt(113, SOL_TCP, TCP_NODELAY, [1], 4) = 0
epoll_ctl(47, EPOLL_CTL_ADD, 113, {EPOLLIN|EPOLLPRI|0x2000, {u32=113, u64=113}}) = 0
epoll_wait(47, {{EPOLLIN, {u32=7831200, u64=7831200}}, {EPOLLIN, {u32=70, u64=70}}, {EPOLLIN, {u32=113, u64=113}}}, 1024, 1000) = 3
read(113, "GET /helloworld.html HTTP/1.1\r\nH"..., 4064) = 56
writev(113, [{"HTTP/1.1 200 OK\r\nServer: G-WAN\r\n"..., 251}, {"Hello World\n\n", 13}], 2) = 264
read(70, "GET /helloworld.html HTTP/1.1\r\nH"..., 4064) = 56
writev(70, [{"HTTP/1.1 200 OK\r\nServer: G-WAN\r\n"..., 251}, {"Hello World\n\n", 13}], 2) = 264
accept4(53, {sa_family=AF_INET, sin_port=htons(35017), sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_NONBLOCK) = 187
setsockopt(187, SOL_TCP, TCP_NODELAY, [1], 4) = 0
epoll_ctl(47, EPOLL_CTL_ADD, 187, {EPOLLIN|EPOLLPRI|0x2000, {u32=187, u64=187}}) = 0
accept4(53, 0x7ff3982dce10, [16], SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(47, {{EPOLLIN, {u32=70, u64=70}}, {EPOLLIN, {u32=113, u64=113}}, {EPOLLIN, {u32=187, u64=187}}}, 1024, 1000) = 3
read(187, "GET /helloworld.html HTTP/1.1\r\nH"..., 4064) = 56
writev(187, [{"HTTP/1.1 200 OK\r\nServer: G-WAN\r\n"..., 251}, {"Hello World\n\n", 13}], 2) = 264
read(113, "GET /helloworld.html HTTP/1.1\r\nH"..., 4064) = 56
writev(113, [{"HTTP/1.1 200 OK\r\nServer: G-WAN\r\n"..., 251}, {"Hello World\n\n", 13}], 2) = 264
read(70, "GET /helloworld.html HTTP/1.1\r\nH"..., 4064) = 56
writev(70, [{"HTTP/1.1 200 OK\r\nServer: G-WAN\r\n"..., 251}, {"Hello World\n\n", 13}], 2) = 264
epoll_wait(47, {{EPOLLIN, {u32=187, u64=187}}}, 1024, 1000) = 1
read(187, "GET /helloworld.html HTTP/1.1\r\nH"..., 4064) = 56
writev(70, [{"HTTP/1.1 200 OK\r\nServer: G-WAN\r\n"..., 251}, {"Hello World\n\n", 13}], 2) = 264
epoll_wait(47, {{EPOLLIN, {u32=187, u64=187}}}, 1024, 1000) = 1
read(187, "GET /helloworld.html HTTP/1.1\r\nH"..., 4064) = 56
writev(187, [{"HTTP/1.1 200 OK\r\nServer: G-WAN\r\n"..., 251}, {"Hello World\n\n", 13}], 2) = 264

なんだか分かりますか？

接続を受けてリクエストを読んでレスポンスしてを繰り返していますが、この間にhelloworld.htmlを読み込む動作がありません。おそらく一度メモリに読み込んでファイルIOをしないようになっているのでしょう。

nginxでもファイルのIOを減らしてあげる事で高速化するかもということでもう２つnginx.confにパラメータを追加。

ファイルディスクリプタのキャッシュ

open_file_cache を使うと一度開いたファイルディスクリプタを再利用できます

    location / {
        root   /usr/share/nginx/html;
        index  index.html index.htm;
        open_file_cache max=100;
    }

TCP_CORKによるデータ書き出しタイミングの変更

tcp_nopush を使います。

tcp_nopush　on;

nginxはデフォルトでファイルを送り出す際にsendfileシステムコールを使いますが、sendfileの前に動くHTTPヘッダのパケット書き出しを遅延させ、ヘッダとファイルの中身を一度に送り出すように調整します

これで再度ベンチマークを行うと、

$ ./wrk -c 300 -t 4 -d 10 http://localhost/helloworld.html
Running 10s test @ http://localhost/helloworld.html
  4 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   510.32us  382.89us  13.19ms   84.26%
    Req/Sec   102.05k    17.80k  125.89k    60.65%
  3820481 requests in 10.00s, 827.07MB read
Requests/sec: 382102.47
Transfer/sec:     82.72MB

さらに速くなりました。G-WANよりも20%ぐらい高速です。

まとめ

速い遅いには理由がある。psやstraceだけでもいろんなことが分かりますね。

G-WANって何が嬉しいのかというと、Cでハンドラを書いてそれがそれなり高速に動作する & 内蔵のKVSやグラフ描画などWebで便利なAPIが用意されているってことなんだろうけど、今やmod_mrubyやnginx-lua、LLのアプリケーションサーバでもそれなりの速度がでるので使いどころは少ないだろうなというのが個人的感想。なによりソースコードが公開されていないので問題が起きたときの調査に難がありますね。

ちなみにこのサーバでStarletを動かすと、

./wrk -c 32 -t 8 -d 10 http://localhost:5000/
Running 10s test @ http://localhost:5000/
  8 threads and 32 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   152.96us   91.59us   3.88ms   89.21%
    Req/Sec    22.96k     2.71k   37.11k    77.09%
  1729085 requests in 10.00s, 227.56MB read
Requests/sec: 172989.08
Transfer/sec:     22.77MB

G-WANやnginxほどじゃないけどやっぱり速い。