KLabGames Tech Blog

KLabは、多くのスマートフォン向けゲームを開発・提供しています。 スマートフォン向けゲームの開発と運用は、Webソーシャルゲームと比べて格段に複雑で、またコンシューマゲーム開発とも異なったノウハウが求められる領域もあります。 このブログでは、KLabのゲーム開発・運用の中で培われた様々な技術や挑戦とそのノウハウについて、広く紹介していきます。

この文書は@julienPauliさんによる記事「realpath_cache」の日本語翻訳です。元々は@gilbiteさんがKLab社内向けに翻訳したものでしたが、日本語では見たことがない指摘を含んでおり今でも有用だと考えたため、@julienPauliさんの了解を取った上で@hnwが修正・追記して公開するものです。

はじめに

PHP に realpath_cache_get(), realpath_cache_size() という関数があることをご存じでしょうか? また、php.ini に realpath_cache から始まる設定項目があることは?

realpath cache は知っておきたい極めて重要な概念です。 特に、コードのデプロイ時にシンボリックリンクを取り扱う場合は知っておくべきでしょう。 この仕組みはサーバの性能向上およびIOの削減を実現するもので、PHP 5.1 で導入されました。 ちょうど PHP 界隈にフレームワークが現れ始めた時期ですね。

stat システムコールの復習

あなたのシステムがどうやって動いているのか、重々ご承知とは思いますが、いったん整理しましょう。 特定のパス が指定された場合に、カーネルやファイルシステムは実際のところ何が指定されたのかを知る必要があります。 (Unixでいうところの)ファイルにアクセスしようとしてパスを指定するときは、必ずあなた自身なり、ライブラリなり、カーネルなりがそのパスを解決する必要があります。 ここでいうパスの解決とは、要はそれがファイルなのか、ディレクトリなのか、はたまたリンクなのか、という情報を得る事です。

パスの解決は、OSにそのファイルの種類を問い合わせることで行われます。 ファイルがシンボリックリンクだった場合は、さらにリンク先のファイルの種類を問い合わせることになります。 "../hey/./you/../foobar" のような相対パスの場合には、まずフルパスに直し、そのフルパスのパス解決を行います(Unixでいうファイルは、すべての種類の実ファイル、ディレクトリ、リンクのことを指します)。

通常、相対パスについては、C の realpath() 関数が呼ばれます。 そして、この関数は、stat() システムコールを呼びます

stat() は重い処理です。 システムコールですからカーネルトラップやコンテキストスイッチを発生させますし、ほぼ確実にディスクに対してメタデータを問い合わせます。 カーネルの stat() のソース http://lxr.free-electrons.com/source/fs/stat.c#L190 を追ってみると、予想通りファイルシステムへの問い合わせ (inode->getattr()) につながっていますね。 通常、カーネルは buffer cache を使用するためディスクへの問い合わせの影響はかなり小さいのですが、高負荷なサーバでは欲しい情報がbuffer cacheに乗っていないかもしれません。 その結果、できれば発生させたくないはずの IO が発生してしまうことになります。

PHP がやっていること

PHP のプロジェクトでは大量のファイルを使用しますよね。 昨今は大量のクラスを使用するので、大量のファイルが存在することになります(1ファイルに1クラスだと仮定しています)。 ですから、autoload していようとなかろうと、大量のファイルを include し、読み込み、カーネルに stat 情報を問い合わせる必要があります。 そんなわけで、PHPからファイルアクセスするたびにパスの解決、リンクの解決、またファイルの情報の取得が行われます。 これらは全て stat() システムコールを使用します。 そこで、stat() システムコールの結果は realpath cache と呼ばれる領域にキャッシュされています。 実はPHPの他にも多くのソフトウェアがstatをキャッシュしています。コードを眺めてみれば気づきますよ ;-)

システムコールの結果をキャッシュするといっても、PHP がキャッシュするのはパス解決された結果であるところのrealpathだけです。(オーナーや、パーミション、各種日時といった)その他の情報はrealpath cacheではキャッシュされません。ただし、PHPには最後のstatシステムコール1件をキャッシュする仕組みがあり、そちらではその他の情報もキャッシュされます。

例によって、ソースコードを確認してみると良さそうですね。 PHP でファイルへのアクセスが発生すると、php_resolve_path() が使用されます。 この関数はすぐに tsrm_realpath() を呼びますが、 これも virtual_file_ex() を呼び、 最終的に tsrm_realpath_r() が呼ばれます。

ここからが面白いところです。realpath_cache_find() などの関数が呼ばれると、指定されたパスに対してstat 情報が過去に問い合わせされて既にキャッシュされているかどうか、realpath cacheの連想配列を検索します。

この連想配列の要素には構造体 realpath_cache_bucket が使用されており、多くの情報がカプセル化されています:

typedef struct _realpath_cache_bucket {
    zend_ulong                    key;
    char                          *path;
    char                          *realpath;
    struct _realpath_cache_bucket *next;
    time_t                         expires;
    int                            path_len;
    int                            realpath_len;
    int                            is_dir;
#ifdef ZEND_WIN32
    unsigned char                  is_rvalid;
    unsigned char                  is_readable;
    unsigned char                  is_wvalid;
    unsigned char                  is_writable;
#endif
} realpath_cache_bucket;

この bucket が見つからなかった場合は、lstat() のプロキシである php_sys_lstat() が呼ばれ、ファイルシステムへの問い合わせを行います。 そして、問い合わせ結果を含むbucketが realpath cache へと保存されます。

PHP 設定とそのカスタマイズ

さて、PHP の realpath cache で抑えておくべきことがいくつかあります。まずは INI の設定から。:

マニュアルが警告している通り、そう頻繁にファイル変更が起こらないようなサーバ(プロダクション環境)の場合は、TTL を大きくしておくべきでしょう。 また、デフォルトの size はとんでもなく小さいですね。Symfony2 のようなフレームワークを使っているのであれば、16K は1リクエストで埋まってしまいます。 realpath_cache_get() を監視すれば、16K の制限にすぐ引っかかってしまう様子が見て取れるでしょう。 512K とか、なんなら1Mにした方が良いでしょう。 realpath cache が埋まるということは、他のエントリのための余地が無くなっている状態ですから、キャッシュミスが原因でstat()が乱発され、カーネルにストレスを与え続けてしまいます。 この size を理論的に導出するのは難しいのですが、ソースのここを見る限り、1エントリにつき、sizeof(realpath_cache_bucket) + 解決されたパスの総文字数 + 1 となっています。 自分の環境(LP64)では、sizeof(realpath_cache_bucket) = 56 バイトでした。

もう一つ落とし穴があります。PHP は出会った全てのパスを解決しようとしますが、その際に細かくパーツ分けして、1つずつパス解決していきます。 "/home/julien/www/fooproject/app/web/entry.php" にアクセスしたとしますね。 そうすると、まず、最少単位に分解して "/home" の解決をして 1 エントリとしてキャッシュに放り込む、続いて "/home/julien"、"/home/julien/www"とやっていきます。 どういうことでしょうか?理由の一つは、ディレクトリの全レベルのアクセスを確認するのに使うためです。 次に、多くの PHP ユーザはパスを組み立てるのに文字列連結する傾向があるので、あるパスの一部をPHPが確認済みかもしれません。 その場合、realpath cache に問い合わせればユーザーがアクセス可能かどうか判断することができます。 キャッシュへの問い合わせは非常に軽いですからね。 詳細の処理はtsrm_realpath_r() のソースコードに記述されています。 これは全てのサブパスについて呼び出される再帰関数です。

これまで見てきた通り、キャッシュはあった方がいいですよね!

新規にデプロイしてウェブサイトを公開する前に、URL をいくつか叩いてキャッシュを準備しておくのも重要です。 これはOPcode キャッシュだけではなくて、realpath cache、ひいてはカーネルのページキャッシュを準備するという事にもなります。

さて、realpath cacheはどうクリアするのでしょうか?この関数はPHP上で隠されています。realpath_cache_clear() だと思いましたか?残念ながらそんな関数は存在しません :-) clearstatcache(true) なのです。この true が非常に大事です。このパラメータ名は$clear_realpath_cacheで、言うまでもなく我々が探していたものです。

では、例を。

<?php
$f = @file_get_contents('/tmp/bar.php');

echo "hello";

var_dump(realpath_cache_get());

この場合、次のような結果が得られます。:

hello
array(5) {
  ["/home/julien.pauli/www/realpath_example.php"]=>
  array(4) {
    ["key"]=>
    float(1.7251638834424E+19)
    ["is_dir"]=>
    bool(false)
    ["realpath"]=>
    string(43) "/home/julien.pauli/www/realpath_example.php"
    ["expires"]=>
    int(1404137986)
  }
  ["/home"]=>
  array(4) {
    ["key"]=>
    int(4353355791257440477)
    ["is_dir"]=>
    bool(true)
    ["realpath"]=>
    string(5) "/home"
    ["expires"]=>
    int(1404137986)
  }
  ["/home/julien.pauli"]=>
  array(4) {
    ["key"]=>
    int(159282770203332178)
    ["is_dir"]=>
    bool(true)
    ["realpath"]=>
    string(18) "/home/julien.pauli"
    ["expires"]=>
    int(1404137986)
  }
  ["/tmp"]=>
  array(4) {
    ["key"]=>
    float(1.6709564980243E+19)
    ["is_dir"]=>
    bool(true)
    ["realpath"]=>
    string(4) "/tmp"
    ["expires"]=>
    int(1404137986)
  }
  ["/home/julien.pauli/www"]=>
  array(4) {
    ["key"]=>
    int(5178407966190555102)
    ["is_dir"]=>
    bool(true)
    ["realpath"]=>
    string(22) "/home/julien.pauli/www"
    ["expires"]=>
    int(1404137986)

例示のPHPファイルのフルパスがパーツごとに解決されているのがわかると思います。 実は/tmp/bar.phpは存在していないので、当然ながらこのエントリーはキャッシュにはありません。 しかし、/tmpまでは解決されていることがわかります。つまり /tmp へはアクセス可能であることがわかるため、 これ以後の/tmp以下のパス解決は、最初の1回より安上がりになります。

realpath_cache_get() が返す連想配列には、キャッシュ失効時刻("expires")など重要な情報が入っていますね。 これはrealpath_cache_ttl の設定値とファイルへの最終アクセス日時から計算されています。 key は、解決されたパスのハッシュ値で、FNV hash の一種が使われています。 ですが、これは内部的な情報であって必要な情報ではありません(この値はシステムの整数のサイズに応じてinteger もしくは float になります)。

ここでclearstatcache(true) を呼ぶとrealpath cacheの連想配列がリセットされ、以前にキャッシュされていたファイルであっても新しいファイルアクセスとして PHP に stat() を強制させることになります。

OPcode cache の場合

さらに別の落とし穴を紹介しましょう。

realpath cacheは、プロセスごとに存在するものであって、共有メモリで共有されるものではない

ですから、キャッシュの失効や変更、手動での消去などについては、プロセスプール内の全てのプロセス で行われる必要があるのです(訳注:全プロセス横断でのrealpath cache消去機能は提供されていないため、非現実的だと考えるべきでしょう)。 opcode キャッシュ拡張を使っている場合にコードデプロイが失敗するのはこれが主な理由です。 デプロイ時にはシンボリックリンクの切り替えをすると思います。例えば /www/deploy-a から /www/deploy-b のように。 ここで忘れがちなのが、opcode キャッシュ拡張は(少なくとも OPCache と APC については)、PHPの内部的な realpath cache を信頼しているということです。 つまり、opcode キャッシュ拡張はシンボリックリンク先の変更があったことに気づきません。 さらに悪いことに、realpath cacheの全エントリが徐々に失効していくにつれ、徐々にリンク先の変更に気づいていくわけです。 どうなるかは言わんでも分かりますな?

デプロイ時にこの残念なメカニズムの発生を防ぐ一番の解決策は、完全に新しいPHPワーカープールを準備しておくことです。 fastCGI handler でその新しいプールにロードバランスさせ、古いプールはワーカーが全部仕事をやり終えたら放棄してしまえばよいのです。

この方法だと良い点がたくさんあります。 デプロイA が メモリプールA で動いて、デプロイB が メモリプールB で動く。 以上。 2つのデプロイ間で完全にメモリイメージの分離を行い、なんのメモリ共有もさせない。 realpath cacheも、opcode cache も、何もかもが新しくなるわけです。 FastCGI プールのロードバランスは、少なくとも Lighthttpd と Nginx では使えます :) 私もプロダクション環境で実践していますが、手堅いですよ!

終わりに

realpath cacheについて何か書いてくれと依頼されたのは、多分、皆がツラい経験をしたことがあるからだと思います(それも、おそらくコードのデプロイ時に)。 ということで、その仕組と、存在意義や設定の変更の必要性とその仕方を書きました。他に何かあるかな?

翻訳者による補足

PHPプロジェクトでシンボリックリンク切り替えによるデプロイ(特にホットデプロイ)を行っている場合に、OPcacheとの組み合わせで何故か新しいファイルに切り替わらない、という事件があちこちで起きているのではないでしょうか。その原因の一つと、解決策を示した文章を紹介しました。

本稿で指摘されている、シンボリックリンクによるデプロイとrealpath cacheとの相性の悪さは非常に悩ましい問題です。元の記事ではOPcacheとの組み合わせで問題が起きるように読めるかもしれませんが、実はOPcache無しでもrealpath cacheが古いシンボリックリンク先を返してしまうことで同様の事故が起こる可能性があります。

多くのPHPプロジェクトではrealpath_cache_sizeの値が小さすぎて本稿の問題そのものは起きないかもしれません。その場合でも、OPcacheが提供している全プロセス共有のrealpath cacheという、本稿で触れられていない落とし穴があります。実はこちらの方がトラブル事例としては多い可能性もありそうです。

本稿で提案されているプロセスプールを新旧2個用意するという解決策は完璧ではあるものの、小規模案件では非現実的なこともあるでしょう。 元記事の筆者の@julienPauliさんはSensioLabsの社員でもあります。同社はSymfonyの開発元として有名で、大規模案件に取り組んでいることで知られていますから、この解決策で特に問題はないということだと思われます。

(11/1 08:45 追記)一方で、プロセスプールを2個用意するという提案は安全側に倒しすぎだという見方もできます。というのも、シンボリックリンクを利用したデプロイを行っていても本稿で指摘した問題が露呈しない状況もあるのです。詳細はまた別エントリでお伝えすることになると思いますが、昨今のフレームワークを使った開発であれば問題が起きない環境の方が多数派だろうと予想しています。ですから、今うまく動いているプロジェクトのデプロイプロセスをわざわざ変更する必要は無いでしょう。

こんにちは, @mecha_g3 です.

ISUCON6に「この技術部には問題がある!」チームとして出場し, 優勝しました.
メンバーは まとめ役の @methane, インフラ屋の @kizkoh, 僕がアプリ改造を担当しました.

他のメンバー参加記事:

予選とその反省

ISUCON6予選をトップ通過しました

余裕を持って優雅に戦えたとか書いてありますが, 僕は全然余裕がなく, 準備したツールが中々動かなかったり, git 操作のミスで変更が反映されてなかったり, DBコネクションを食いつぶす変なバグを埋め込んでしまったりで足を引っ張りまくりでした.

その反省もあって, 本選用にAWSの開発環境を用意し, 作業に必要なツールやエディタの設定は全て済ませておきました.
またこの開発環境では, ログの収集やアプリのデプロイ, ベンチマーク時のプロファイルの結果をhtml形式でレポートするスクリプト等を作っておきました.

さらに, 予めスタートダッシュチェックリストを作っておき, 問題公開後にしかできないけど必ず必要な作業の一覧を作り, 誰がやるか予め決めておきました.

この開発環境とスタートダッシュチェックリストのおかげで, 本選時にアプリの改造に集中することができました.

例えば

  • ~/deploy で競技サーバにアプリのデプロイ
  • ~/restart で競技サーバのアプリやnginx, MySQLの再起動.
  • ~/applog で競技サーバ上のアプリのログをtail -f
  • ~/make_report ベンチマーク後, 競技サーバ上のアプリのログを収集してレポートのhtmlを出力してslackに通知

これらを Makefile から呼び出すことで, 競技中に vim の中に閉じこもることができます.
問題に合わせて微妙に変更しないといけない所も, インフラ担当の @kizkoh が良い感じにメンテしてくれました.

本選

前半戦

スタートダッシュチェックリストに書いておいた事を淡々と進めました. 競技が始まると全然頭が回らなくなるので作っておいて本当に良かった.

僕は初期状態のアプリを git 管理してビルドが通るようにし, デプロイスクリプトを修正したり, 8080番ポートでLISTENするようにしたり, 予め用意しておいたプロファイル用のライブラリを挿入したりなどを行いました.

ISUCON のアプリには毎回 /initialize という, ベンチマーク前にデータセットを初期化するリクエストが存在します.
これをトリガにして nginx のログをローテートし, 1分間(ベンチマーク時間) pprofの記録, dstat, pidstat を裏で動かすスクリプトを事前に準備していました.
が, 本選の問題には /initialize は存在せず(やられた), アプリケーション側からベンチの開始を検出するのが難しかったので, ベンチマークをかける頃に /startprofile というパスを手動で叩くようにしました.

Webサーバのログを見ると UA に benchmarker というような文字があったのでこれを使うかも考えましたが, 意図せぬタイミングで暴発すると面倒なのでやめました.

作戦会議

お弁当を食べながらアプリを触ったり, 作戦会議を行いました.
ここまでスタートダッシュに集中していたのでアプリのソースは全然読んでませんでした.

スタートダッシュ中にログの集計やアプリの構成などを理解していた @methane からアプリの構成や, 現状考えている方針を共有してもらいました.

Server-Sent Events は全く触ったことがなかったけど, テキストベースのプロトコルだと分かった後は簡単でした.
svgは業務外で何度か触ったことがあり, xml形式だということは知っていたので怖くはなかったです.

リアルタイムのお絵かきサービスだけど, やることはテキストの共有. つまりチャットのような物.
普段業務でやっている事と大差ないよね, 多分go言語有利な問題だし, 実力出せれば勝てる.

お絵かき部分の共有をとにかく高速化しよう.
内容の変更をDBにポーリングしている構造になっている所を直せば劇的にスコアが上がるはず.
描いた内容は他のクライアントに2秒以内に反映されていれば良いので, 急いで返す必要はなく, ある程度バッファしてまとめて返すほうが効率いいよね.
という会話をしました.

インフラ方面では, dockerを潰し, node.jsをフロントから剥がし, nginxをフロントに置くなど大規模な構成変更を決めていました.

中盤戦

オンメモリ作戦

DBに毎回問い合わせている部分をなくせば良いので, オンメモリ作戦を実施しました.
起動時にDBの内容を全て SELECT しメモリ上に乗せ, 変更された内容は DB に保存しつつオンメモリの内容も更新します.
最新の情報はメモリ上にあるので, DBへの問い合わせをなくすことができます.

全部と書いていますが, ここで行ったのは room, strokes, points が対象です.

最初は, 最終的にアプリをroomで水平分散するかもしれないからそこを意識しつつオンメモリ化を考えていて手が中々動きませんでした.
難しいので1プロセスで動く前提で作ります! と割り切ってからはサクサクと作業が進みました. 最終的にアプリは1プロセスだったので結果論ですが正解でした.

具体的には以下のようなコードを書いていました.

type RoomRepo struct {
    sync.Mutex
    Rooms map[int64]*Room
}

func NewRoomRepo() *RoomRepo {
    return &RoomRepo{
        Rooms: map[int64]*Room{},
    }
}

func (r *RoomRepo) Init() {
    log.Println("room repo init start")
    r.Lock()
    defer r.Unlock()

    rooms := []Room{}
    err := dbx.Select(&rooms, "SELECT `id`, `name`, `canvas_width`, `canvas_height`, `created_at` FROM `rooms` ORDER BY `id` ASC")
    need(err)

    for i, _ := range rooms {
        strokes := []Stroke{}
        err := dbx.Select(&strokes, "SELECT `id`, `room_id`, `width`, `red`, `green`, `blue`, `alpha`, `created_at` FROM `strokes` WHERE `room_id` = ? ORDER BY `id` ASC", rooms[i].ID)
        need(err)

        var owner_id int64
        err = dbx.QueryRow("SELECT token_id FROM `room_owners` WHERE `room_id` = ?", rooms[i].ID).Scan(&owner_id)
        need(err)

        for j, s := range strokes {
            ps := []Point{}
            dbx.Select(&ps, "SELECT `id`, `stroke_id`, `x`, `y` FROM `points` WHERE `stroke_id` = ? ORDER BY `id` ASC", s.ID)
            strokes[j].Points = ps
        }

        rooms[i].ownerID = owner_id
        rooms[i].Strokes = strokes
        rooms[i].watchers = map[int64]time.Time{}
        r.Rooms[rooms[i].ID] = &rooms[i]
    }
    log.Println("room repo init end")
}

func (r *RoomRepo) Get(ID int64) (*Room, bool) {
    r.Lock()
    defer r.Unlock()

    room, ok := r.Rooms[ID]
    return room, ok
}

...

オンメモリ作戦のデバッグ

Go での開発はコンパイルエラーでしょうもないミスはすぐ分かるし, vim の QuickFix でエラー箇所に簡単にジャンプできるのでIDEで開発しているような気分になります.
競技時間中は頭が全然回らず, 焦って明らかに変なコードを書いてしまいがちですがかなり助けられました.

コンパイルが通った後は, 実行時にすぐ分かるエラーを数か所直しました.
ブラウザで動作確認してみると, 全ルームidが同じルームを参照してしまうバグが発生していましたが, forループの変数のスコープのあるある問題だなとすぐ気づき修正できました.

この頃にはインフラ担当の構成変更も終わり, HTTP2を喋っていて 10000点 以上でるようになっていました(すごい).
ここにオンメモリ作戦の改造を入れたアプリをデプロイし, ベンチマークをかけてみると一発でPASSし 23428点.

svg生成のGo移植

オンメモリ作戦が一段落したところで, @methane が node.js で動いていた /img/* へのリクエストの svg 出力部分をgoで出力する関数ができたので試したいという.
投入してみると, 空の svg が出力されていて動作せず. デバッグを任せられたのでとりあえず printデバッグで関数が呼ばれているかなどを確認しました.

DBから引いた状態の room には strokes は空なので, 空の svg が出力されていましたというだけでした. オンメモリ化とつなぎ込めば解決です.

また, 前回ベンチマークの警告からnginxの設定ミスがわかり, それを修正も入っており 39101点.

svg生成結果のキャッシュ

ベンチマーク時のプロファイルを見ていると, svg 生成部分がアプリ全体のうち 64.31% と中々重そうでした.
ここをなんとかキャッシュできると, 他チームに差をつけれそうです.

Strokeは内容は, アプリケーションの性質から, 追記のみであることがわかりました.
つまり, 1stroke毎に <polyline> ... </polyline> が1行増えるだけで, 1度書いた部分が変更されることはありません.

閉じタグを含めない状態の svg を Room 毎にキャッシュしておき, Stroke が増える度に1行ずつ追記します.
/img/* へリクエストが来た際は, キャッシュしている svg を出力し, 最後に </svg> を追加するだけで, 何度も同じ svg を生成しなくてすみます. あたまいい!

具体的には以下のようなコード.

room.svgInit が初回レンダリング済みかどうかのフラグ. 初回 svg 出力時に svgBuf を作ります.
Stroke が追加された場合は 同様の Fprintf で svgBuf に追記します.

func renderRoomImage(w io.Writer, room *Room) {
    room.svgMtx.Lock()

    if !room.svgInit {
        buf := bytes.NewBuffer(make([]byte, 0, 1024))

        fmt.Fprintf(buf,
            `<?xml version="1.0" standalone="no"?><!DOCTYPE svg PUBLIC "-//W3C//DTD SVG 1.1//EN" "http://www.w3.org/Graphics/SVG/1.1/DTD/svg11.dtd"><svg xmlns="http://www.w3.org/2000/svg" version="1.1" baseProfile="full" width="%d" height="%d" style="width:%dpx;height:%dpx;background-color:white;" viewBox="0 0 %d %d">`,
            room.CanvasWidth, room.CanvasHeight,
            room.CanvasWidth, room.CanvasHeight,
            room.CanvasWidth, room.CanvasHeight)

        for _, stroke := range room.Strokes {
            fmt.Fprintf(buf,
                `<polyline id="%d" stroke="rgba(%d,%d,%d,%v)" stroke-width="%d" stroke-linecap="round" stroke-linejoin="round" fill="none" points="`,
                stroke.ID, stroke.Red, stroke.Green, stroke.Blue, stroke.Alpha, stroke.Width)
            first := true
            for _, point := range stroke.Points {
                if !first {
                    buf.WriteByte(' ')
                }
                fmt.Fprintf(buf, `%.4f,%.4f`, point.X, point.Y)
                first = false
            }
            buf.WriteString(`"></polyline>`)
        }

        room.svgBuf = buf
        room.svgInit = true
    }

    svg := room.svgBuf.Bytes()
    room.svgMtx.Unlock()

    w.Write(svg)
    w.Write([]byte(`</svg>`))
}


func (r *RoomRepo) AddStroke(roomID int64, stroke Stroke, points []Point) {
    r.Lock()
    defer r.Unlock()

    room, ok := r.Rooms[roomID]
    if !ok {
        log.Println("[warn] no such room")
        return
    }

    stroke.Points = points
    room.Strokes = append(room.Strokes, stroke)

    room.svgMtx.Lock()
    if room.svgInit {
        buf := room.svgBuf
        fmt.Fprintf(buf,
            `<polyline id="%d" stroke="rgba(%d,%d,%d,%v)" stroke-width="%d" stroke-linecap="round" stroke-linejoin="round" fill="none" points="`,
            stroke.ID, stroke.Red, stroke.Green, stroke.Blue, stroke.Alpha, stroke.Width)
        first := true
        for _, point := range stroke.Points {
            if !first {
                buf.WriteByte(' ')
            }
            fmt.Fprintf(buf, `%.4f,%.4f`, point.X, point.Y)
            first = false
        }
        buf.WriteString(`"></polyline>`)
    }
    room.svgMtx.Unlock()
}

これで /img/* のCPU時間が数倍早くなり, 44655点.

終盤戦

@kizkoh は MySQL と node.js を別サーバに移したりなど, 複数台構成に向けての変更を行っていました.
@methane は node.js に文句をいいながら何かをやっていました.

僕は他にチューニングできるところが無いか探し, まだオンメモリ化できていない, /api/rooms をオンメモリ化する作業を行っていました.
ここには全然リクエストが来ていなかったので, 高速化してもスコアは伸びないと思ってましたが, 遅いせいでワークロードが下がりリクエストが来ていないのかもと思い一応着手しました.

インフラの構成変更が最優先だったので, この変更はなかなかベンチをかけれず..

終了30分前には複数台構成が落ち着き, node.js に対する謎の変更も入り, 最高点 83560点 を記録.
このあと /api/rooms のオンメモリ化をデプロイしてみると 13000点 程度に落ちてしまったのでエラーも見ずに巻き戻し.

安全にゴールしようという事で全台再起動試験. 問題なくうまく立ち上がり一安心.
しかし, ベンチをかけてみるとなぜか 55729点. 83560点 と同じ構成のハズなのに..

もう一度ベンチをかけると 59296点. なんだかスコアが不安定である.
会場の他チームがラストスパートをかけた為Azure東日本リージョン全体が重くなったのか, 再起動時にハズレインスタンス引いたのか.

とにかく1分毎に Enqueue を押して, 良いスコアが出るのを祈る... が 55855点 でFINISH.

終了後

ベスト時に比べると 27000点も低いスコアで終わってしまったので不完全燃焼.
ベスト時のスコアなら優勝だったのに! という事にならないかとても不安でした.

練習してきた事はちゃんと発揮できたし, 役割分担も良かった. 後悔は無いね, という感じでドキドキの結果発表.

最初に75000点を超えたということで特別賞を受賞.
その後, 2位の発表でスコアが3万点台だったのを見てガッツポーズ! 優勝を確信しました.

懇親会

初対面の方が多かったですが, 優勝チームということもありたくさん絡んでもらえました.
みなさん個性的で面白い方ばかり, 1日同じ問題に取り組んだ人同士の会話は盛り上がらないはずはなく, 懇親会はあっという間に終わりました.

他にも, 高専プロコンつながりで知っていた沖縄高専の学生チームと話したり, 秋葉さん imosさんの 競プロC++ チームと絡んだりでき, 非常に楽しかったです.

勝って飲む酒の美味しいこと!!!

感想

毎年予選あたりの時期は忙しい事が多く, 練習時間がとれず過去2回予選落ちし, 本選に出場できたのは今回が初めてでした.
今年こそ本選に行くぞ! という気持ちで今年は予選1ヶ月前から練習を開始しました.

ISUCON では, アプリの改造する為の知識はもちろん, HTTPのキャッシュの管理, MySQL や nginx のチューニング, カーネルパラメータのチューニングなど, 上から下まで知識が要求されます.
そもそも存在を知らなければチューニングできませんし, 付け焼き刃の知識では試行錯誤で時間が奪われます.

普段からGoでアプリを書いている人, 普段からインフラをメンテナンスしている人, 幅広い知識があり全体を見て方針を決めれる人 のチーム構成は完璧だったと思います.

優勝賞金は, もうすぐ発表になると予想されている MacBook Pro の新型を買って, ISUCONステッカーを貼ります. これでモチベーションを上げて来年からも優勝目指すぞ!

最後に, ISUCON の練習に業務時間をたくさん使わせて頂きました. 本当に感謝してます. いつか還元するので許してください :)

今回は、以前このブログで紹介した KMSについて、そのサーバサイドの構成を紹介したいと思います。

KMS の基本的なところ

汎用性

KMS は、チャットシステムを手軽に実現するための、SaaS型サービスとして企画されました。 つまり、1つの KMS のシステムを複数のゲームアプリが利用することが前提にありました。 そのため KMS は汎用性を常に意識して設計しています。

汎用的なシステムとして設計したため、KMS ではチャットに関するもの以外のデータ、例えばゲーム内のギルド情報などのデータは扱いません。 一方で NGワードなどのチャット機能に必要なデータは、利用ゲームごとに個別に保持し、必要に応じてゲームサーバから更新できるようにしています。

チャンネルを軸としたシステム

KMS はメッセージをやりとりする場であるチャンネルを軸としたチャットシステムです。 ユーザは特定のチャンネルに所属することで、そのチャンネルに対して発言することができるようになり、また同じチャンネルに所属する他のユーザが発したメッセージを受け取ることができます。 ユーザが発言したメッセージは、リアルタイムに他のユーザに転送されます。

KMS のチャンネル構成は、KMSを利用するゲームアプリ次第です。 例えば、自由に参加できるワールドチャットや、ギルドやチームに参加するユーザに限定したチャット、また 1 対 1 の個人チャットなどの用途が考えられます。

ユーザ認証

KMS はゲーム内で使うためのチャットシステムですので、クローズドなチャットです。 つまり、クライアントが KMS のサーバに接続する際は、ユーザ認証を実施する必要があります。 ユーザ認証に必要なデータは KMS 自体では生成せずに、ゲームサーバ側から受け取る形にしています。

KMS サーバの構成

KMS のサーバサイドの主要部分は、次の4種類のサーバで構成されています。

KMSの構成

UA サーバ

UA とは User Agent の略で、 クライアントアプリが接続する先のサーバです。 ユーザの発言をリアルタイムに他のユーザへ配信するために、クライアントアプリとサーバとの間の通信プロトコルとしては WebSocket を使っています。

構成としては、フロントエンドに nginx を置き、バックエンドには tornado を使っています(※)。 また tornado のスーパーバイザとして Circusを使っています。 nginx と Circus = tornado の間は Unix Domain Socket で接続しています。

※ フロントエンドサーバ、バックエンドサーバ
KLab では Web アプリケーションサーバを立てる際、フロントエンドとバックエンドの 2種類のサーバを動かします。 クライアントからの接続はフロントエンドのサーバが受け付け、バックエンドのサーバに proxy する構成です。

バックエンドのサーバは、Web アプリケーションの本体を動作させる環境になります。

フロントエンドのサーバの役割はいくつかあります。 例えば

  • アクセスログの標準化
    • tornado や uwsgi など、異なるバックエンドを併用する場合でも、アクセスログの形式を揃えられる
  • バックエンド処理の、タイムアウト管理
    • バックエンドの処理に時間がかかりすぎている場合に、フロントエンドがそのリクエストを強制的にエラーにすることで、接続リソースを開放する
  • クライアントリクエストのパーキング
    • 大量アクセス時に、全てのリクエストを並列に処理するとスラッシングなどの状態に陥るので、バックエンドの並列数は絞りつつ、クライアント接続をパーキングすることで混雑時のユーザエクスペリエンスの低下を緩和する

などがあります。

フロントエンドとバックエンドのサーバは、前記のようにその間を Unix Domain Socket で接続するので、同一のマシン上で動作させています。

API サーバ

ゲームサーバからのリクエストを受け付けるサーバです。 こちらはプロトコルとして HTTPS を使っています。 ユーザ認証用のデータなど、クライアントアプリが KMS を利用する上で必要なデータの追加更新削除の操作に加えて、ゲーム運用者がチャット上のデータを参照したりするためのリクエストも、この APIサーバが担当します。

構成としては、フロントエンドに nginx を置き、バックエンドには uwsgi を使っています。 こちらも、nginx と uwsgi の間は Unix Domain Socket で接続しています。

IRC サーバ

UA サーバ間及び、UAサーバと API サーバの間でのメッセージ配信用基盤として利用しています。

UA サーバも API サーバも、当然ながら複数台のサーバマシンを用意しています。 なので、 例えばサーバ S1 に接続している U1 ユーザが C チャンネルに対して発言した内容を、同じ C チャンネルに所属している S2 サーバ上の U2 ユーザに配信するためには、 S1 サーバと S2 サーバの間でメッセージを転送する必要があります。 そのための基盤として KMS では IRC サーバをチューニングした上で利用しています。

また、ユーザの発言を UA サーバ間で配送するためだけでなく、ゲームサーバがAPIサーバを通じてチャットへ送ってくるシステムメッセージの配信や、チャンネルへのユーザの入退室情報の配信などにも、IRCサーバを利用しています。

DB サーバ

ユーザ認証情報や、 チャンネルに対して発言されたメッセージのログや、ユーザが所属するチャンネル情報などを保管しています。 MySQL を利用しています。

KMS サーバアプリのバージョン管理

KMS は、複数のゲームアプリが利用するシステムです。 当然ながら KMS とゲームアプリの開発および運用は独立しています。 ですので KMS がバージョンアップしたからと言って、それに合わせてゲームアプリのバージョンアップを強制することはできません。

そのために KMS では UA サーバ・API サーバ共に、クライアントがサーバに接続する際に利用したい KMS バージョンを選択できるようにしています。 この仕組みにより KMS では下位互換性の無い改修を新規バージョンに施すことを容易にしました。 極端な話をすれば、利用するゲームアプリ専用バージョンの KMS を用意して同時に運用することも、可能になっています。

バージョン選択の仕組み

クライアント側からの、KMS サーバのバージョン選択は、次のような形で実現しています。

バージョン選択の仕組み(UAの場合)

まず、tornado(UAサーバ)と uwsgi(APIサーバ)上では、KMS を利用する全ゲームアプリが利用する予定のバージョンのサーバアプリを全て動かしています。 これらのサーバアプリと(フロントエンドの) nginx の間は Unix Domain Socket で接続しますが、この待ち受け用の Unix Domain Socket をサーバアプリのバージョンごとに用意しておきます。 つまり、バージョン1.1 とバージョン1.2 のサーバアプリが平行稼働していた場合、バージョン1.1用の待ち受けソケットと 1.2用の待ち受けソケットの2つの待ち受けソケットができます(※)。

※待ち受けソケット

Unix Domain Socket なので、待ち受けソケットとは、具体的にはファイルシステム上に配した socket ファイルのことです。

クライアントからの KMS サーバへの接続は、最初にフロントエンドの nginx が受け付けます。 その際にクライアントは利用したい KMS バージョンを、URL の中に埋め込みます。 nginx はその URL を見て、クライアントからの接続をどのバージョンのサーバアプリにプロキシーするかを判断し、適切な待ち受け用の Unix Domain Socket へ接続を回します。

この仕組みにより、KMS を利用するゲームアプリは、任意のタイミングで、利用する KMS のバージョンを変更することができます。 また KMS の運営側としては、利用するゲームアプリに気兼ねすること無く、新しいバージョンのサーバアプリをデプロイすることができます。

KMS の裏側の裏話

ここまでで説明した構成は、実装前の設計段階で固まっていて、大きな変更はありませんでした。 しかしながら、細かいところでは当然ながら初期の設計どおりではまずい箇所がいくつか出てきました。 また、負荷テストを実施してみると思わぬところがボトルネックになっていることが分かりました。

IRC サーバと UA の関係

最初期の構想では、UA の役割はクライアントと IRC ネットワークの間の橋渡し役として、ユーザ認証と NG ワードチェック、そして参加チャンネルの管理程度に留めたいと考えていました。 そのため、クライアント = UA 間の接続に 1 対 1 対応する UA = IRC 間の接続を作り、接続クライアントの数だけ IRC ネットワーク上にユーザを登録する構成を考えていました。

この方式では、UA を動かしている tornado が管理する接続の数は、1クライアントにつき2つの接続になります。 当然ながら tornado が管理する接続の数が増えるとそれだけリソースを消費するため、さばけるクライアントの上限が低くなってしまいます。 性能テストをしてみたところ、このクライアント接続に 1 対 1 対応する IRC 接続を作るという設計では、目標とする性能を実現できませんでした。

この問題に対処するために、当初の設計を変更して、UA と IRC の間の接続は 1つで済ませることにしました。 これに伴って、当初の設計では IRC の機能に依存していたクライアント間のメッセージの適切な配送機能を、UA 上にも実装する必要に迫られることになりました。

UA のチューニング

KMS では、クライアントと UA の間の接続は WebSocket を使った常時接続です。 前述したように、同時に取り扱う接続の数が多ければそれだけ tornado のリソースを消費することになります。 また UA の応答性はクライアントのユーザビリティに直結します。 そのため、UA チューニングには特に時間を費やしました。

その中で実施した施策の1つに、PyPy の導入があります。 PyPy は python インタプリタ実装の 1つで、 JIT を実装しているため標準のインタプリタである CPython よりも実行速度が期待できます。 PyPy の導入によりパフォーマンス向上の効果は一定ありましたが、それでもまだ目標とするパフォーマンスには到達しませんでした。

そのため、ひたすら cProfile プロファイリングを取得して、ボトルネックを解析し、対策を施しました。 その際に活躍したのが、 KCachegrind です。 KCachegrind を使った解析により、主なボトルネックとしては JSON の解析部分と tornado のマルチタスク処理部分であることが分かりました。

JSON

KMS はクライアントと UA の間や、(IRC を通じた) UA 同士、UA と API の間などの通信の全てにおいて JSON を使っています。 そのため JSON 処理の高速化が肝になりました。

一般的には JSON エンコードには json.dumps() を使うかと思いますが、その実装の実体は json.encoder.JSONEncoder クラスの encode() メソッドになります。 json パッケージでは json.dumps() 呼び出し時の JSONEncoder クラスの初期化コストを抑えるために、パッケージの初期化時にこのオブジェクトをキャッシュしますが、このオブジェクトキャッシュが使われるのは json.dumps() のデフォルト引数群に、デフォルト値以外の値が渡されない場合だけです。 KMS では separators オプションを指定したかったので、 独自に json.encoder.JSONEncoder クラスのオブジェクトをキャッシュしておくようにしました。

また、PyPy の JSON エンコードライブラリでは呼び出しオプションの与え方によって、その実装の一部分で C言語実装のコードが使われる場合と Python 実装が使われる場合があります(※)。 C言語実装が使われるか否かは、json.dumps() の引数 ensure_asciiTrue (default) か False かで変わります。 True であれば C言語実装が使われ、False であれば Python 実装が使われます。 当然ながら Python 実装版よりも、C言語版の方がパフォーマンスが高いので、コードを見直して必ず C言語版の実装が使われるようにしました。

※ JSON encoder の実装切替ポイント

前述の通り json.dumps() の実装の実体は json.encoder.JSONEncoder クラスにあります。 このクラスのコンストラクタ中で、 ensure_ascii 引数の値によって利用する実装を切り替えている部分(160行目)があります。

        if ensure_ascii:
            self.__encoder = raw_encode_basestring_ascii
        else:
            self.__encoder = raw_encode_basestring

この raw_encode_basestring_asciiraw_encode_basestring の実装の実体はそれぞれ同じファイルの49行目40行目にあるのですが、 raw_encode_basestring_ascii だけは更に536行目付近の

try:
    from _pypyjson import raw_encode_basestring_ascii
except ImportError:
    pass

このコードで、C言語実装をロードしています。

マルチタスク処理

Python はインタプリタの実装上、ネイティブ thread による並列実行のパフォーマンスがよくありません。 そのため tornado はノンプリエンプティブ型のマルチタスク処理システムを独自実装して、並列処理を実現しています。 このマルチタスク処理システムでは、ユーザコードから tornado への実行権限の譲り渡すタイミングを、ユーザコード上で指定する形になっています。 プロファイリングを取得してみると、このマルチタスク処理の部分がそれなりに重いことが分かりました。 その対策として、実行権限の譲渡のポイントを精査し、不要な実行権限の移譲が発生しないように対策しました。

最後に

KMS は SaaS として、1つのシステムで複数のゲームアプリ向けにチャットシステムを提供するために開発しました。 SaaS 型のシステムにした理由は、リアルタイムにチャットメッセージを配信するためのサーバシステムは、どうしても一般的なゲームのサーバシステムとは異なる部分が大きいため、利用案件の数だけチャットサーバシステムを立てていたのでは、運用が回らなくなると考えたからでした。

汎用的なシステムにしたために少し複雑になっている部分もありますが、KMS を利用するゲームアプリの自由度を損なわずに、それでいて運用性の高いシステムに仕上がりました。 この KMS の汎用的かつ柔軟な構造は、将来あるであろう、何か新しいことを KMS の上で実現したい、というリクエストに十分応えてくれることでしょう。

KG SDKに関するお問い合わせ

KLabでは、開発パートナー様と共同開発したゲームをKLabにてパブリッシング、プロモーションを行うというモデルを積極的に進めており、開発パートナー様にKG SDKの提供もしています。
パブリッシング事業につきましてはこちら
KG SDKに関するお問い合わせにつきましてはこちら
をご覧ください。

↑このページのトップヘ