alp と Plack::Middleware::QueryCounter を合わせて使うと捗る

OSS紹介 Advent Calendar 2017 - Qiita 4日目の記事です。

@tkuchiki 氏が作っている alp (Access Log Profiler) は、もはや ISUCON 競技者必須ツールとなった、LTSV 形式のアクセスログをいい感じに集計してくれるツールです。 github.com

通常は alp では reqtime, apptime など、リクエストの処理に要した時間を集計するこのでパフォーマンスチューニングするのですが、実は集計対象は引数 --apptime-label を指定することで、集計時に自由に決めることができます。パフォーマンスに影響するなんらかの数値をログに出力しておけば、それを key にして集計できるということですね。

そこでもうひとつ、@acidlemon 氏作の便利 Plack::Middleware を組み合わせてみました。

metacpan.org

Plack::Middleware::QueryCounter::DBI は enable するだけで、DBIx::Tracer を使ってそのリクエスト中の DBI でのクエリ発行数を計測し、レスポンスヘッダに出力してくれます。

    log_format ltsv 'host:$remote_addr\t'
    # (snip)
                    'query_total:$upstream_http_x_querylog_total\t'
                    'query_read:$upstream_http_x_querylog_read\t'
                    'query_write:$upstream_http_x_querylog_write\t'
                    'query_other:$upstream_http_x_querylog_other\t'

ということで、nginx ではそのヘッダを LTSV 形式でログに残すようにすれば…

$ alp -r --avg --apptime-label="query_total" < access.log
+-------+--------+---------+----------+--------+-----------+-----------+------------+-----------+--------+-------------------------------------------------------+
| COUNT |  MIN   |   MAX   |   SUM    |  AVG   | MAX(BODY) | MIN(BODY) | SUM(BODY)  | AVG(BODY) | METHOD |                          URI                          |
+-------+--------+---------+----------+--------+-----------+-----------+------------+-----------+--------+-------------------------------------------------------+
| 5     | 35.000 |  35.000 |  175.000 | 35.000 |  2119.000 |  2430.000 |  11479.000 |  2295.800 | POST   | /api/xxxxxxx/top                                      |
| 51    |  6.000 | 474.000 | 1765.000 | 34.608 |    38.000 |   656.000 |   3741.000 |    73.353 | POST   | /api/yyyyyy/action                                    |
| 1     | 19.000 |  19.000 |   19.000 | 19.000 |  2825.000 |  2825.000 |   2825.000 |  2825.000 | GET    | /api/user                                             |
| 5     | 17.000 |  18.000 |   87.000 | 17.400 |  1527.000 |  1588.000 |   7807.000 |  1561.400 | POST   | /api/zzzzzz/info                                 |
....

どこの path の処理中にクエリを大量に発行しているのかが一目瞭然ですね。

ベンチマーク中に大変便利だったのでご紹介でした。

ISUCON 7 本選で負けてきました

毎年恒例の ISUCON 7 本選に参加して、惨敗してきました。

競技中の最終スコアが 19600 程度、これが再現できていれば7位だったのですが、実際の結果は fail で 0 点、過去7大会の予選と本選で一度も経験したことがないスコアなしでの終戦でした。

今回の問題はインフラ、ミドルウェア的にいじるところはほぼなく、nginx の設定は初期状態からいじらず (APIで返す websocket の endpoint を Go の TCP 5000 にしたので)、MySQL で最低限の設定をしたのみでした。チームメイトの @acidlemon, @handlename のコード修正を見守るばかりで、もっと能動的に動けたらなあ、という後悔もあり。

やったこと

  • m_items をメモリに持つ (handlename)
  • getStatusをtickerのときのみキャッシュする (acidlemon)
  • getCurrentTime のタイムスタンプをメモリにのせる (acidlemon)
  • roomごとに接続先ホストを round robin で決定 (handlename)
  • adding ON DUPLICATE KEY UPDATE をやめる (acidlemon, fujiwara)
    • pkey を auto increment で別に作成し、同一 time での INSERT をロックなしに可能にする
  • GetPriceとGetPowerをキャッシュする (handlename)

15時ぐらいに一時 24000 程度で暫定1位を取ったものの、ここからたまに通るけどたまに事後検証で fail する、というのが解消しきれず。

途中、math/big.Int の計算がとにかくボトルネックなのはプロファイリングで把握していたので、正確な計算を諦めて DB には float で持つ (そうすると SELECT sum(isu) で大量に転送しないでも合計の概算が得られる) というブランチは自分が並行で実装していて、これも 24000 程度。ただしこれも稀に fail するので最終的には採用せず。

acidlemon が確定値を cache することで adding の SELECT を減らす、というコードを1時間ほど書いていったものの、これの微妙なバグが全員で最後まで取り切れなかったので(取り切れていたらスコアももう少し伸びて至ろうなという雰囲気)、その後あれこれ細かいところを詰めたもののブレイクスルーはなく、終戦、という感じでした。

最後はスコア 0 で終わりたくないので直前に3回連続で通過していたコードで最終提出したのですが、結果的には fail でした。過去すべての大会でスコアを残せていた自分としてはそれがとにかく残念ですが、まあ仕方ないですね。

出場チームの皆様、ありがとうございました。優勝したチーム MSA (会社の同僚チーム) 、おめでとうございます!

ISUCON 7 予選2日目を3位で通過しました

まずは出題と運営チームの皆様にお礼を。予選から1チーム3台、合計1200台のサーバを用意するという空前の規模で、快適な競技環境を用意していただいてありがとうございました。

isucon.net

今回は ISUCON 4 の時の fujiwara組 (@fujiwara, @acidlemon, @handlename) を再結成して、自称社内最強チームで望むことに。1日目には同じくカヤックから参戦のチーム MSA が1位を取っていて、これは予選通過はもちろん、スコアでもできれば負けたくないという戦いでした。

f:id:sfujiwara:20171023114230p:plain

最終的には 48万点越え、両日通してのスコアでも3位ということで、まずまずの結果が残せたと思います。

やったこと

  • あらかじめ用意しておいた Chef recipe で各種ツールや各人のアカウント作成、公開鍵設定
    • さくらのクラウドで用意されている Ubuntu から使われるとすれば今回は 16.04 LTS だろう、ということで決め打ちできたので楽だった
  • Go 実装で行くことに決定
    • 前日1位の MSA は (聞いてないけど面子的に) Go だろう、変にハマることもなさそう、という判断
    • (とかあるので、なんだかんだで2日目の方が毎回微妙に有利なんですよね。運営もトラブルが少ないし…)
  • dstat をみながらベンチを掛け、どう見ても画像が DB に入ってるのがまずいのでそれを外出しすることに
    • @handlename が Perl でさくっとやってくれた
  • my.cnf を軽く調整 (@fujiwara)
    • Slowlog出力、innodb_flush_log_at_trx_commit = 2InnoDB Buffer Pool Warmup の設定のみ
    • 結局これ以外いじらなかった
  • css, js, fonts を gzip_static で配信 (@fujiwara)
    • expires max を追加してここは 304 が返せるようになった
  • 画像がアップロードされたタイミングでファイルに書き出し、それがあったらDBをみないで返す (@acidlemon)
  • index 追加 (@handlename)
  • channel テーブルに messages_count カラムを追加して count(*) をやめる (@acidlemon)

ここまで app 1台でやっていて、16時ぐらい。ボトルネックは /icons のファイル配信での帯域で、ここをクリアしないとどうしようもない。

Expires と Cache-Control max-age では、css 等は 304 を返せるんだけど、なぜか icons では効かない…としばらく悩んで、でもここは絶対 Cache-Control でクリアできるはず。@acidlemon が Cache-Control: public を付けてみては、と閃いたので付けたら効く。10万点ぐらい。

ここで css等と icons でベンチマーカーのキャッシュ挙動が異なったのが、だいぶ難しい上にここを突破できないと先に進めないという一番の難関だった感じがします。

  • GET /message, GET /history のループクエリ解消 (@handlename)
  • pt-query-digest の結果から、prepare, execute が2クエリに分かれているので interpolateParams=true の設定を入れてクライアントサイド prepare に (@acidlemon, @fujiwara)

そろそろ複数台構成を伺いたい。となるとファイルの共有なり分散配置が必要になるので、以下のような戦略を決定 (@fujiwara)

  • アップロードされたホストが自分のホスト名を元にディレクトリを切って icons/01/xxxxxxx.png というファイル名で保存、DB にも 01/xxxxxxx.png を入れる
  • nginx(01)
    • /icons/01/ はローカルファイルを見る (そこに保存されているので必ずある)
    • /icons/02/ は nginx(02) へローカルのネットワークで proxy_pass
  • nginx(02)
    • /icons/02/ はローカルファイルを見る
    • /icons/01/ は nginx(01) へローカルのネットワークで proxy_pass
  • nginx(03)
    • /icons/01, 02 はそれぞれ nginx(01, 02) に振る
    • それ以外は app(01, 02) に均等に振る

このように一カ所にファイルを保管しないでローカルに配置し、表からそれぞれ持っているはずのホストに Proxy するという手法は、 ISUCON 3 の出題をしたときに想定解答の一つとして考案していたもの。ファイルは一カ所にしかないので各種メタデータもずれないし、特定のホストに負荷が集中することもないのでお気に入りの手法です。

そういえば、先日の Fastly Yamagoya meetup でも、Fastly は Cache を持っているホストに内部で Proxy することでヒット率を上げている、という話がありましたね。

これで複数台の帯域を使えるようになり、予選ボーダーの20万点を大きく超えてきたのが18時過ぎ。19時前に最高スコア 54万を記録。

このあたりから、Go のアプリを再起動しないで複数回ベンチを掛けるとアプリが太って swap を使いだし、極端にパフォーマンスが落ちるのを発見。

  • 環境変数 GOGC=50 を設定してメモリ消費を抑える (@fujiwara)
    • 1回のベンチ走行後が 800MB → 450MB ぐらいになって、仮に最後の確認で複数回走行されても swap しづらいので安定する
    • ピーク性能は落ちるので、最終的に 50万を超えられなかったのは多分このため
  • ファイル名を決めるのに SHA1 を全部舐めて求めているのが無駄なので先頭 1024 byte だけで決める (@acidlemon)
    • これは先頭 16KB までで判断(したつもりだったけど多分実装ミスでなってなさそう)、初期チェックは通るもののなぜかベンチ中の整合性チェックで死ぬので revert
  • POST /profile で2発飛ぶ update 分を1個にまとめる (@acidlemon)
  • Session に user 情報を全部入れて DB を引かない (@handlename)
    • この二つはいまいち効果がみられず。ただし revert することもないのでそのまま

最後30分は再起動試験をして、再起動後の一発目のベンチで 48万がでたのでそこで打ち止め。

最後は †空中庭園†《ガーデンプレイス》には及ばなそうと覚悟はしていたものの、スギャブロエックスに逆転されたのがちょっと悔しいですね!

今回もコードを書くのは @acidlemon, @handlename に任せて、それぞれ並行して有効手を打ち込めたのでよかったですね。あと Cache-Control: public が早い段階で突破できたのがだいぶ余裕を生んだ感じ。

ともあれ 3位でフィニッシュできて、晴れて本選に進めることになったので、本選も頑張りたいと思います。

YAPC::Fukuoka で分散 ID 採番機 katsubushi の話をしてきた

初福岡ですが前日は熊本に泊まって馬刺しを食べました。今まで食べてきた馬刺しとはなんだったのか。

発表資料はこちらです。

speakerdeck.com

github.com

開発してから2年、本番で使いまくっていますが大変安定してますし、いろいろ面白い使い方ができる特性を持っているので、是非お試しください。(rausサポートした版はまだ本番に入れてないですが、今後数ヶ月のうちに入れる予定です)

Consulクラスタ内でファイルを分散配布する tuggle を書いた

github.com

これはなに?

HTTPを使って、ファイルを Consul クラスタ内で分散配布する daemon です。Go で書かれています。読みかたは「たぐる」です。

開発動機とユースケース

拙作の Stretcher というデプロイツールがあります。嬉しいことに、自分が勤務しているカヤックだけではなく、他社さんでも使われているようです。 先日、某社の Stretcher をお使いのかたに話を伺う機会があり、デプロイアーカイブの取得時のネットワーク負荷が問題になっているということを聞きました。

カヤックではサーバは基本 AWS にあり、S3 からデプロイアーカイブ(200〜300MB程度)を取得しています。S3はちょっと意味が分からないぐらい堅牢で、stretcherの -random-delay 5 (開始を平均2.5秒、最大5秒ずらす) を設定した状態で100台程度から一斉に200MBを取得しに行っても、平然と各ホストに対して 60〜80MB/sec ぐらいの転送速度でファイルを配ってきますし、エラーになることもほぼありません。(毎日10回deployしていて S3 からの取得が失敗するのは数ヶ月に一度とか)

ところがAWS外部から取得する場合、AWSまでの回線の問題もありますし、delayを大きく取っても結構な確率で失敗するので困っている、という話でした。

ということで、Consul クラスタ内部でファイルを分散配布し、HTTP で取得できる仕組みを作ってみました。

使い方

README に書いてあるとおりですが、HTTP の PUT, GET, HEAD, DELETE に対応しています。

Consul クラスタ内で各 node に tuggle を起動します。(デフォルトではTCP 8900番ポートを listen します)

[node{1,2,3}]$ mkdir /tmp/tuggle
[node{1,2,3}]$ tuggle -data-dir /tmp/tuggle

どこか1台の node で PUT することでファイルを登録できます。

[node1]$ curl -XPUT -H"Content-Type: application/gzip" --data-binary @test.gz localhost:8900/test.gz

登録されたファイルは GET / することで一覧を参照できます。

[node1]$ curl -s localhost:8900 | jq .
[
  {
    "id": "6524a9d7b3bde0f3543f1ead0ae8604f",
    "name": "test.gz",
    "content_type": "application/gzip",
    "size": 8764510,
    "created_at": "2017-02-13T07:46:18.809409122Z"
  }
]

その後、他の node で動いている tuggle から GET することで、ファイルを取得できます。

[node2]$ curl localhost:8900/test.gz > test.gz
[node2]$ ls -l test.gz
-rw-rw-r-- 1 foo bar 8764510 Feb 13 07:55 test.gz

ファイルの上書きは未対応です。同一ファイル名へは一旦 DELETE で消してから PUT しなおしてください。どこの node からでも DELETE 可能です。

[node1]$ curl -X DELETE localhost:8900/test.gz

動作原理

tuggle の動作原理を簡単に説明します。

tuggle は PUT を受け付けると、以下の動作をします。

  • ファイルを data-dir に保存
  • Consul KV にファイルに対応するメタデータを記録
  • Consul Service に name=tuggle tag=ファイル名のMD5 として自分の node を登録
  • (URL引数 sync がついている場合、Consul Event を発行して他の node の tuggle に取得を促す)

つまり、どの node がどのファイルを保持しているのかを Consul Service のタグで管理しています。

tuggleはGETを受け付けると、Consul KVのメタデータを参照した上で

  • 自分の data-dir に存在していればそれを返します
  • 自分が持っていない場合、Consul Serviceを name=tuggle tag=ファイル名のMD5 で検索し、ファイルを持っているnodeにHTTPで取得しに行きます
    • 取得が終わったら data-dir に保存し、自分自身を Service に登録した上でクライアントにファイルを返します

という動作をします。これによって、自分が持っていないファイルはその時点で持っている node を検索して取得し、その後自分自身も配布 node として動作することになります。

DELETEでは、受け付けた node は以下の動作をします。

  • Consul KV からメタデータを削除
  • Consul Eventを発行して、クラスタ内のtuggleにローカルファイルを削除するように通知

Stretcher と組み合わせて使う場合はデプロイアーカイブを tuggle に PUT してから、manifest で src: http://localhost:8900/foo.tar.gz などと指定する想定です。

実装上の工夫

最初にファイルを持っているのは 1 node なので、デプロイ時のように一斉に各 node で取得しようとすると、結局最初の1台に負荷が集中してしまいます。 そこで tuggle は Consul のセマフォの仕組みを利用して、1 nodeに対する取得の並列数を 3 に制限しています。

セマフォが取得できなかった node は、しばらく待ったあとに Consul Service の検索からリトライします。その時点で取得が終わった node は配布 node となっているため、増えた配布 node の中からランダムに選択することで負荷を分散します。

また、Consul 0.6 以降では Consul Agent 間でネットワーク的な距離を測定しています。Serviceを検索するときに near=_agent というクエリをすることで、自分と近い node を優先的に選択することができます。

これによって、AWSの AZ (Availiability Zone)間のようにネットワーク間に距離がある場合でも、自分と近いところから取得することで効率を上げることができます。

また、取得によって帯域を使い尽くさないように -fetch-rate というオプションで、取得に使用する帯域を制限することができます。これは拙作の shapeio というライブラリで実現しています。

https://github.com/fujiwara/shapeio

実際どんな感じ?

ファイルがどのように node 間で伝達していったのをかを Consul KV に保管しておいて、graphviz の dot 形式で出力する機能があります。

$ curl "http://localhost:8900/test.gz?graph" > graph.dot
$ curl "http://localhost:8900/test.gz?graph&format=svg" > graph.svg

node に graphviz (dot コマンド) がインストールされていれば、format=(svg|png) などと指定することで変換後の画像を取得することもできます。

実際に 135MB のファイルを AWS 上で c4.large インスタンス 50台、multi-az 構成で配布 (sync引数付き) してみたグラフは以下のようになりました。

f:id:sfujiwara:20170213180457p:plain

全 node にファイルが配布完了するまでに約18秒でした。c4.large インスタンスではおおよそ 70MB/sec 程度のネットワーク速度しか出ないため、1台に対して全台が取得すると100秒近くかかるはずのところが分散配布によって高速化しているのが分かります。

(手動で) AZ ごとに色を付けてみると以下のように、いいかんじに AZ 内を優先してファイルが流れていってるようです。最初に同 AZ のが集中しているのは、ネットワーク的に近いため Consul Event の伝達が早いものから先にセマフォを取得したためかと思われます。この辺は工夫の余地がありそうです。

f:id:sfujiwara:20170213180333p:plain

制限

  • Consul Service のタグでファイルを管理している都合上、大量のファイルは扱わない方がよさそうです
    • 試しに1000ファイルを登録してみても特に問題は出ませんでしたが、小さいファイルではConsul APIを叩くオーバーヘッドがあるため、普通にHTTPで配るよりもだいぶ遅くなります
  • ファイルにディレクトリ階層は付けられません
    • 面倒だっただけなのでそのうち直すかも

ということで、まだ動き始めたばかりで本番投入もしていませんが、興味のあるかたはお試しいただけると幸いです。

リポジトリの docker ディレクトリ以下で make up とすると、docker-compose で 8 node のクラスタが起動するので、試すのはこちらがお手軽です。

ISUCON6で準優勝でした

ISUCON 6 にチーム「morimoto組」で参加して、最終スコア 36,067 で準優勝しました。

morimoto組は自分と、会社の新卒1,2年目( kasari , id:moshisora ) という歳の差チームです。

お題

  • 匿名お絵かきサービス
    • ログイン、セッション管理などはない
  • SSE (Server Sent Events) で他のユーザの書き込みがストリーミングで流れてくる
  • 一番前に React のサーバサイドレンダリングをする node のプロセスがいる
  • react, 各言語実装のアプリケーションサーバ, MySQL はすべて Docker で起動している

やー、盛りだくさんでしたね…

スコア推移とやったこと

f:id:sfujiwara:20161024114926p:plain

11:02:53   PASS  942
11:21:28   PASS  1159
11:58:31   PASS  1364
12:31:15   FAIL  253
12:36:34   PASS  1616
12:39:18   PASS  2051  nginxをいれて /api 以下を直接 Perl に (fujiwara)
12:43:40   PASS  3175  並列度が高いのでPerlを200プロセスに (fujiwara)
12:46:41   PASS  3543
12:49:26   FAIL  12
12:53:18   PASS  2816
13:03:36   PASS  3314
13:35:14   FAIL  251
13:47:46   FAIL  251
14:07:14   PASS  3211  pointsをstrokesのカラムにJSONで保持 (kasari, moshisora)
14:09:41   FAIL  0  壊れたSVGを返してベンチマーカーがクラッシュしたらしい
14:10:56   FAIL  0
14:11:25   FAIL  0
14:14:25   PASS  3470
14:15:21   FAIL  0
14:16:38   FAIL  0
14:20:25   FAIL  0
14:24:03   PASS  4697  /img/* で返すSVGをPerlでレンダリング (fujiwara)
14:27:05   FAIL  252
14:29:53   PASS  4781
15:17:25   FAIL  106
15:21:32   PASS  7412  /img/* をRedisにCache(Perlで処理) (kasari)
15:31:52   PASS  6040
16:09:04   FAIL  253
16:10:24   FAIL  253
16:12:32   PASS  8020
16:54:56   FAIL  253
16:58:52   FAIL  253
17:10:31   PASS  9339  /api/stream/rooms SSEをGo + Redis PubSub実装に置き換え (fujiwara)
17:41:33   PASS  15241  React, Perl, Goをisu02で動かして2台構成
17:43:36   PASS  30714  React, Perl, Goを全台で動かす5台構成
17:45:12   PASS  29301
17:48:35   PASS  36067  React, Perl, Goを isu02〜05、isu01にnginx, MySQL, Redisの5台構成

全体の方針

全体の方針としては、以下のようなざっくりとしたスケジュールを組みました。

  • まず 1台でチューニングを進める
  • 複数台構成に1時間、再起動確認などに30分を用意する
  • つまりコードフリーズは 16:30 がデッドライン

チームメイト的には Perl のほうが書きやすい、ということでまず Perl 実装を選択。Perlの初期実装は各言語の中でもだいぶスコアが出にくかったようで、ベンチを回して1000前後。

  • MySQLはDockerから剥がす
  • nginx をいれてログを取りつつ /api は react ではなく直接Perl
  • 並列数がだいぶ高いので Perl を200プロセス起動する (無理矢理感ある)

なかなか立ち上がりが早くできず、スコアをあまり上げられずにお昼へ。

アプリケーションの改善

1 Strokeに対して複数保存されるPointsが1点毎に1レコードになっていたので、これはそのままJSONシリアライズしてStorkeのカラムに保存してしまう(kasari)。既存データもマイグレーションするスクリプトで処理(moshisora)。この時点ではスコアはほとんど変わらないが、その後の改善をしたら効いてくるはず。

/img/SVGを返している部分は、初期実装が

という作りになっていたので、ここを直接 PerlSVG を吐き出すように修正(fujiwara)。

my $svg = qq{<?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="${width}" height="${height}" style="width:${width}px;height:${height}px;background-color:white;" viewBox="0 0 ${width} ${height}">};
for my $s (@{ $room->{strokes} }) {
    my ($r, $g, $b, $a) = ($s->{red}, $s->{green}, $s->{blue}, $s->{alpha});
    my ($id, $w) = ($s->{id}, $s->{width});
    $svg .= qq{<polyline id="$id" stroke="rgba($r,$g,$b,$a)" stroke-width="$w" stroke-linecap="round" stroke-linejoin="round" fill="none" points="};
    $svg .= join(" ", map { $_->{x} . "," . $_->{y} } @{$s->{points}});
    $svg .= qq{"></polyline>};
}
$svg .= "</svg>";

ひどいコードだが、動く (4697)。そのあと SVG を Redis に cache するようにして 7412。ここは nginx (OpenResty) から直接 Redis を参照するようにすればもっと伸びたはず、だけど手が回らず未着手。

SSEを処理している部分は初期実装が 500ms sleep してDBに新しいStrokeがあるかどうかをポーリングをくりかえす、という作りで、これは Perl の Prefork server (Starlet) ではプロセスが専有されてしまうので並列度が上がらず不利。

PerlとGoのハイブリッド構成へ

既に15:30なので、手を打つとしたらここが最後の判断ポイント。Goを混ぜることを決断。

  • /api/stream/rooms の SSE だけ Go 実装にする
    • nginxで振り分け
  • 500msのポーリングをやめて、Redis PubSub を使う
    • Perlで保存した新しいStrokeをPublish
    • GoはSubscribeして降ってくるJSONをそのままイベントとして流す

実装としては、以下のようなコード。

  • Redisはgoroutineを起動してそこでsubscribe、イベントが来たらchannelに流す
  • contextを使って3秒で全体をタイムアウトさせる
    • これは出題者にあとで聞いたところ、もっと長くても問題なかったそうです
  • 特にイベントが来なくても 500ms ごとに watcher_count は送信する
    • 最後の case <-time.After(500 * time.Millisecond): のところ
// func getAPIStreamRoomsID(ctx context.Context, w http.ResponseWriter, r *http.Request) {
// ...
    ch := make(chan *redis.Message, 10)
    nctx, cancel := context.WithTimeout(ctx, 3*time.Second)
    defer cancel()
    go func(ctx context.Context) {
        redisClient := redis.NewClient(&redis.Options{
            Addr: os.Getenv("REDIS_HOST") + ":6379",
            DB:   0, // use default DB
        })
        defer redisClient.Close()
        log.Println("starting psubscribe")
        pubsub, err := redisClient.PSubscribe(fmt.Sprintf("%d", room.ID))
        defer pubsub.Close()
        if err != nil {
            log.Println("psubscrie err", err)
            return
        }
        for {
            msg, err := pubsub.ReceiveMessage()
            if err != nil {
                log.Println("recv err", err)
                return
            }
            select {
            case <-ctx.Done():
                return
            default:
                ch <- msg
            }
        }
    }(nctx)
    for {
        select {
        case <-nctx.Done():
            return
        case msg := <-ch:
            var s Stroke
            err := json.Unmarshal([]byte(msg.Payload), &s)
            if err != nil {
                log.Println(err)
                return
            }
            d, _ := json.Marshal(s)
            printAndFlush(w, "id:"+strconv.FormatInt(s.ID, 10)+"\n\n"+"event:stroke\n"+"data:"+string(d)+"\n\n")
        case <-time.After(500 * time.Millisecond):
        }
// ...

たいした変更でもないし1時間あればいけるだろう、と思って一人で書いたものの(fujiwara) 、やはり焦りからかなかなかベンチを通過できず。

17時をまわってしまったので、これで通らなければ Perl のまま複数台構成にするしかないか…というところで最後、kasari に「イベントがなくても 500ms ごとに watcherを送る必要があるのでは?」という指摘をもらってなんとか 17:10 にベンチを通すことに成功!(9339)。

複数台構成へ

ここまでチューニングしてきたホストには netdata をいれていたので、ベンチを回しつつまだまだアプリケーション (React, Perl, Go) がCPUを使っていることは確認済み。

そこで、Dockerで動いていて分散が容易な React, Perl, Go を 2〜5台目のホストで動作させ、1台目は nginx, Redis, MySQL という構成へ。1台目のnetwork転送量がちょっと心配だったけど、そこを詰めている時間的余裕がなかった…

5台構成にしたところ、MySQL が too many connections のエラーを吐いて接続できない現象を確認。

  • my.cnf では max-connections = 10000 になっている
  • 実際に値を見ると 214

...??? と一瞬パニクりかけたが、あこれは systemd から起動して limit が掛かってるな、という見当が付いたので /etc/systemd/system/mysql.service.d/limits.conf を適当に設定して再起動で解決。

[Service]
LimitNOFILE=1000000
LimitNPROC=1000000

1台ずつ再起動テストをして、02〜05 は 01 にあった docker-compose でのOS起動時のアプリケーション起動設定がない、というのも発見したので /etc/systemd/system/multi-user.target.wants/isu.service /etc/systemd/system/isu.service を01からコピーして反映。

結果

最終的には 17:48:35 に記録した 36,067 が提出スコアとなり、運営の再起動テストも通過。2位で準優勝しました。

他チームにスコアが見られる17時までは1万も行かない状態だったので、最後の1時間でだいぶ跳ねた感じでしたが、ここまで書いたとおり決して余裕があって潜行してたわけではありません…

予選も本選も、素晴らしい問題とイベントを提供していただいた出題者の皆様、運営の皆様に感謝します。ありがとうございました!

API Gateway + Lambdaでcatch allした処理をApex + Goでnet/httpで扱える ridge を書いた

タイトル長い。 LambdaでGoが正式サポートされるのを首を長くして待ちつつ、Apex で Go を実行しています。

先日、API Gatewayで受けたすべてのリクエストをLambdaに丸投げすることができるようになりました。

これまではAPI Gatewayでいちいちマッピング定義を作るのが面倒で、いまいち普通のWebAPI的なものをLambdaで作る気がしなかったわけですが、これで行けるのでは…? と思って、catch all されたリクエストとレスポンスを net/http.Request と net/http.ResponseWriter で扱えるようにする ridge というライブラリを書いてみました。

github.com

Readmeそのままですが、以下のような Go のコードが API Gateway (プロキシ統合)+ Lambda + Apex で動きます。

package main

import (
    "encoding/json"
    "fmt"
    "log"
    "net/http"
    "os"

    "github.com/apex/go-apex"
    "github.com/fujiwara/ridge"
)

var mux = http.NewServeMux()

func init() {
    mux.HandleFunc("/", handleRoot)
    mux.HandleFunc("/hello", handleHello)
}

func main() {
    if os.Getenv("APEX") == "" {
        // ローカルで動かしたい場合はこっち
        log.Println("starting up with local httpd")
        log.Fatal(http.ListenAndServe(":8080", mux))
    }
    // Lambdaで動く場合はこっち
    apex.HandleFunc(func(event json.RawMessage, ctx *apex.Context) (interface{}, error) {
        r, err := ridge.NewRequest(event)
        if err != nil {
            log.Println(err)
            return nil, err
        }
        w := ridge.NewResponseWriter()
        mux.ServeHTTP(w, r)
        return w.Response(), nil
    })
}

func handleHello(w http.ResponseWriter, r *http.Request) {
    w.Header().Set("Content-Type", "text/plain")
    fmt.Fprintf(w, "Hello %s\n", r.FormValue("name"))
}

func handleRoot(w http.ResponseWriter, r *http.Request) {
    w.Header().Set("Content-Type", "text/plain")
    fmt.Fprintln(w, "Hello World")
    fmt.Fprintln(w, r.URL)
}
  • 入力の JSON*net/http.Request に変換してアプリケーションに渡す
  • ridge.ResponseWriternet/http.ResponseWriter interfaceを持っているのでそれに対してレスポンスを書き込む

とすると、普通に Lambda で Go の webapp らしきものが動きます。

ユーザの書くコードは普通の Go の webapp と同様 func(http.ResponseWriter, *http.Request) で行けるので、ローカルでは http を直接 listen するサーバとして動かしつつ、API Gateway + Lambda でも同じコードを動かせる……これはもしかして凄く便利なのでは!

制限とか

  • URL引数に同名の値 (foo=1&foo=2 みたいなの) があると、入力Eventの時点でひとつになってしまう
  • HTTPリクエスト/レスポンスヘッダで複数同じものがあっても同様
  • バイナリの入出力ができるのかどうか良く分からない

という現時点の制約があります。ちゃんとバイナリが扱えれば、画像変換サーバみたいなものにも使えて夢が広がる感じなのですが…

ともあれ現時点でも、普通にHTMLやJSONを返すAPIを実装するのには使えるはずですので、是非お試しください。