このブログはURLが変更になりました

新しいブログはこちら→ https://matsuu.hatenablog.com/

ISUCON8予選1日目にチーム「SELinuxはEnforcing以外あり得ない」で参加して最終スコアは26,221でした

もはやこのブログはISUCON参加記に成り下がってしまってますが。

今年も@ishikawa84g 、@netmarkjp、@matsuuの3人でISUCON8に挑んできました。このスコアじゃ今年も本選進出は難しそうですね。がっくし。

チーム名のとおり、DisabledだったSELinuxはEnforcingにしてフィニッシュです。

やったこと

3人で作業分担をしてたので、基本的に自分がやったことをまとめます

  • ベンチ前の準備スクリプトとベンチ後の集計スクリプト(kataribe, pt-query-digest)を用意
  • getEvent内のN+1をやっつける
  • ORDER BY RAND()を消してみたもののランダムじゃないと怒られるので差し戻し
  • sheetsは増減しない上にsheet_idから算出できるので、できるだけ利用しないように実装変更(sheetsひっぺがし)
  • /api/users/:id のN+1をやっつける
  • 残席数(remain)はeventsにカラムを追加して格納するように変更したものの、デッドロックが発生するのでremainsテーブルを別途作成して格納するように（しかし最終的にfailになるので差し戻し）
  • /api/events/:id/actions/reserve 内の ORDER BY RAND() をやらないために全sheetに乱数のカラムとインデックスを追加してソートするように（しかし最終的にfailになるので差し戻し）
  • 1台目のh2oとwebappとmariadbはそのまま、2台目と3台目にwebappを稼働させ、/initializeのアクセス以外は2台目と3台目に振るように実装変更（しかし最終的にfailになるので差し戻し）

まとめ


上記スクリーンショットにもあるとおり、直前でもsuccess/failしておりなかなか厳しい内容でした。

今回はトランザクションをきちんと意識した上で改修できるかが肝だったとの認識なのですが、ある程度性能が上がってくるとfailが発生してしまい、結局古いコミットにまで差し戻して（それでもたまにfailが出る）無難なスコアでフィニッシュせざるを得ない苦しい展開でした。つらい。

自分で変更した実装に問題があった可能性が9割以上あるのですが、もしかしたらGo実装でgetEvents内のgetEvent呼び出しが同一トランザクションになっていなかったのがある種の罠になっていたのではないかと考えています。もしかしたらgetEventsのN+1を退治すれば結果として解消したのではと思うと、うーん悔しい。問題が公開されたら追試しようと思います。

手を抜く実装にしたらしっかりベンチマーカーが検知しててムムムやるな、と思わず唸る良い実装だったと思います。すべてのサーバーサイドプログラマーはトランザクション処理とはどういうことかというのを学ぶ良い教材になるのではないでしょうか。みんな過去問やろうな。

ISUCON7予選1日目にチーム「ババウ」で参加して最終スコアは205148でした

Webサービスをいい感じにパフォーマンスチューニングするコンテスト

ISUCON7予選1日目に @netmarkjp, @ishikawa84g, @matsuu でチーム「ババウ」にとして参加しました。最終スコアは 205148 でした。

考察

netmarkjp
  • 例年通りの役割分担がしっかり機能して気持ちよくできた
  • 視点を変えたり休憩とったりがいい感じにできた
  • 去年の何もできなかった無念は多少供養できた
  • 練習をきちんと活かせた
  • ベンチが安定しててすごくよかった
  • BGMは東京スカパラダイスオーケストラでした
matsuu
  • トラフィックがボトルネックになる問題をなかなか解決できずにいたが、Cache-Controlにpublicを入れることを思いつけた
  • 304応答が安定して発生しない理由が生成される画像の更新日時がサーバ毎に異なるためであることに気づけた自分を褒めてあげたい
  • Pixiv社内ISUCONを使ってじっくりチューニングしたときの経験がとても役に立った。ありがとうPixiv
  • Discordチャットが結構よかった。ゲームじゃなくてもこういったイベントにとても向いていると思うのでオススメ
  • NEW GAME!!を初めて見たがエンジニアあるあるでグッときた。なるほど。
ishikawa84g
  • Microsoft Wireless Display Adapter は便利。
    • ただし、6時間くらい連続稼働するとハングすることもあるようです。しばらく寝かせると復活した。
  • 開始時間が伸びていたが慌てずリラックスして開始で来た。(流石みんなトラブル慣れしているぜ！)
    • DiscordでおすすめされたNEW GAME!は3話まで見ました。
    • 常に緊張状態ある必要はなく、締めるところを締めれば問題なし！
  • DiscordのコマンドにFF14のWikiを検索するとかあった。
最終構成
[nginx -- (varnish) -- gunicorn]x2 -- [mysql]x1
  • 当初構成からあまり変えず
    • ベンチ先は先頭2台
    • ネットワークボトルネックの間は3台に振ったけど、結局DBサーバのCPUが足りず戻した
  • 投稿された画像は静的ファイルとして出力し、nginxで静的ファイルを返却
    • /icons/* はファイルに出力し基本的にnginxから。なければvarnishを経由してアプリでファイル生成
    • その他のパスへのリクエストはvarnishを経由せず直接gunicornへ
  • varnishは /icons/* のThunerding Herd対策として導入
  • その他MySQL、nginx、アプリのチューニングを実施

事前準備

チーム内体制の構築
  • チャットはSlackで
  • gitリポジトリは Gitlab.com で
  • 使ったことがないツールを使ってみようということで環境構築はitamaeでプロビジョニング
    • 初期構築以降は短期決戦のためitamaeで管理しない
  • git pushベースのCIプロビジョニングは実施しない
    • 事前練習で試したものの短期決戦ではどうやっても遅い
  • サーバで直接Vimを使って編集
    • 他の人が編集してる場合は vim -R で参照
環境構築用レシピを用意

itamaeを使って以下のプロビジョニングを自動化

  • githubからSSH公開鍵を取得、設定
  • 以下の解析ツールをインストール
  • 以下のミドルウェアをインストール
  • ベンチマークをかける前の初期化処理/かけた後の解析処理を実行するスクリプトを用意
    • 初期化処理
      • MySQLスロークエリーログを削除してmysqladmin flush-logs
      • nginxのアクセスログを削除してsystemctl reload nginx
      • アプリプロファイラの出力を削除してアプリケーションプログラムの再起動
    • 解析処理
      • MySQLスロークエリーに対してpt-query-digestを実行
      • MySQLTunerを実行
      • nginxのアクセスログに対してkataribeを実行
      • pythonプロファイラWerkzeugの出力に対してgprof2dotとgraphvizを実行してグラフ生成
sshrc環境整備

sshrcでvim、tmux環境一発セットアップできるよう調整

過去問を解いて予行演習
事前公開のレギュレーションを熟読

大事

当日作業

9:00 - 10:00

集合

電源、椅子、モニターの設営までやって、あとはマッタリ
大事なのは横並びに座ること


11:30 昼食

落ち着いて美味しい昼食。ハンバーガー画像を参加者チャットに投下

12:00 - 13:00 ※開始前

ISUCON参加者専用チャットでNEW GAME!!の話題が盛り上がったためAmazonビデオで視聴開始

13:00 開始予定時刻

ポータルサイトが...オープンしない

13:10 運営よりDiscordで緊急連絡
methane - 今日 午後1時10分
もうちょっと、ごめん！
13:13 開始

SSH接続できないトラブルに見舞われるものの、その間に初回ベンチマーク実行と当日レギュレーションを熟読

13:30 ログイン後

予め用意していた環境構築レシピを実行
並行して、各マシンのスペックと、使われているミドルウェアを確認
サービスの画面を見たりコードを読んで、どんなアプリなのかざっくり把握

ポータル上でサーバが降順で並んでて、「先頭2台」がどれなのかちょっと混乱した

MySQLのチューニングで/dev/shmに格納しようとしたところAppArmorに引っかかったため、AppArmorを調整

/etc/apparmor.d/usr.sbin.mysqld に以下を追記

  # ISUCON2017
  /dev/shm/ r,
  /dev/shm/** rw,
  /proc/** r,
  /sys/devices/system/node/ r,
  /sys/devices/system/node/** r,

変更後、Profileをリロードし、MySQLを再起動する。

sudo apparmor_parser -r /etc/apparmor.d/usr.sbin.mysqld
sudo systemctl restart mysql.service
14:01 webapp配下をgit管理に

pythonで実装する方針にしたため、publicディレクトリとpythonディレクトリをgitに突っ込みcommit

14:08 インデックス追加

スロークエリーから遅いリクエストを調べてインデックス追加

ALTER TABLE image ADD INDEX (name);
ALTER TABLE message ADD INDEX (channel_id);
14:30

一瞬だけ1位獲得

https://twitter.com/matsuu/status/921609614881202178

netdata見たのはこの頃までで、あとはdstatとtop

tmuxで3台分並べて表示。操作はtmuxのsynchronized-paneで楽々実施

14:33 /icons/の静的ファイル化

DBに格納されている画像データを静的ファイルとして出力する実装を行う

def get_images():
    cur = dbh().cursor()
    cur.execute("SELECT name, data FROM image")
    for row in cur.fetchall():
        output = "/home/isucon/images/{}".format(row['name'])
        with open(output, 'wb') as file:
            file.write(row['data'])

出力した画像はnginxから直接応答するように変更

location /icons/ {
        expires 60s;
        alias /home/isucon/images/;
        try_files $uri @upstream;
}

location @upstream {
        proxy_set_header Host $http_host;
        proxy_pass http://127.0.0.1:5000;
}
14:34頃 DBとアプリ間のトラフィック改善

dstatで見ているとDBとWEBの間のトラフィックが多いのにベンチマーカーとWEBの間のトラフィックが少ないことに気づく。

同じ内容の画像が同じファイル名で重複登録されており無駄にDBからの取得が発生していることに気づいたので1行だけ取得するよう修正

    cur.execute("SELECT * FROM image WHERE name = %s", (file_name,))
    cur.execute("SELECT * FROM image WHERE name = %s LIMIT 1", (file_name,))
14:57 静的ファイルのgzip_static化

静的ファイルを予めgzipして保存しておき、nginxの gzip_static で応答するように

gzip_static on;
gzip_types image/svg+xml text/css text/javascript application/javascript application/font-wof
f application/vnd.ms-fontobject;
15:21頃 画像を生成する

画像をINSERT時やSELECT時に出力するよう変更。
しかしサーバごとに画像を生成する実装のためこの後しばらくスコアが伸び悩む

  • 画像にexpiresを付けてみる→多少改善するものの根本解決にはならず
  • /fetchの1秒待機を外してみる→効果なし
  • 206レスポンスを返してRangeヘッダーで返せばいいのでは？→206応答を簡単に実装する方法がわからず
  • limit_rateで代用したらタイムアウト
  • 302リダイレクトで応答を遅らせればいい？→302リダイレクトはエラーになった
17:24頃 /fetchのチューニング

SQLを見直してN+1を解消

SELECT
  channel.id AS channel_id,
  CASE WHEN message_id IS NULL THEN
    (SELECT COUNT(*) FROM message WHERE channel_id = channel.id)
  ELSE
    (SELECT COUNT(*) FROM message WHERE channel_id = channel.id AND message_id < id)
  END AS unread
FROM channel
LEFT JOIN haveread
  ON channel.id = haveread.channel_id AND user_id = ?
18:17頃 画像ファイル生成時に更新日時を合わせる

ベンチマークからのHTTPリクエストをtcpdumpで記録してどのようなリクエストが届いている確認してみる

tcpdump -w dump tcp port 80

その結果をWiresharkに食わせて確認していたところ、If-Modified-Sinceヘッダーを見つけて思いついた。
「画像ファイルの更新日時を合わせてないから304応答を返せていないのだ」と。エウレカ！

def write_image(data, name):
    output = "/home/isucon/images/{}".format(name)
    with open(output, 'wb') as file:
        file.write(data)
    os.utime(output, (1508559193, 1508559193))

1508559193 は 2017/10/21 13:13:13 、ISUCON7予選1日目の開始日時。

18:33

帯域が多少マシになったのでwebサーバのCPU負荷を下げるために gzip off

18:51頃 /messageのチューニング

SQLを見直してN+1を解消

    if last_message_id > 0:
        cur.execute("SELECT message.id, name, display_name, avatar_icon, message.created_at, content FROM message JOIN user ON message.user_id = user.id WHERE message.id > %s AND channel_id = %s ORDER BY message.id DESC LIMIT 100",
                (last_message_id, channel_id))
    else:
        cur.execute("SELECT message.id, name, display_name, avatar_icon, message.created_at, content FROM message JOIN user ON message.user_id = user.id WHERE channel_id = %s ORDER BY message.id DESC LIMIT 100",
                (channel_id, ))
19:00頃 画像ファイル生成時の出力先を/dev/shm/にする
            with tempfile.TemporaryFile(dir="/dev/shm/") as f:
19:10 PythonプロファイラWerkzeugの導入

打つ手が少なくなってきたのでWerkzeugでのプロファイルを実施。

from werkzeug.contrib.profiler import ProfilerMiddleware
app.wsgi_app = ProfilerMiddleware(app.wsgi_app, profile_dir="/tmp/profile")

gprof2dotを使ってdotファイルを生成し、graphvizを使ってpngファイルを生成。

gprof2dot -f pstats --colour-nodes-by-selftime --show-samples /tmp/profile/* > profile.dot
dot -Tpng profile.dot > profile.png

生成結果がこちら。

gprof2dot最高ですね。

19:48頃 rapidjsonの導入

Werkzeugによるプロファイルの結果、JSON生成に時間がかかっていることが判明したため、flask.jsonify()をrapidjsonに差し替え。

20:15頃 WSGIサーバをmeinheldに差し替え→差し戻し

WSGIサーバをgunicornからmeinheldへ差し替えてみたものの大幅に性能が下がり断念。

20:27

sleep対応でgunicornのワーカーを減らしてスレッドを大幅にUP

  • /etc/systemd/system/isubata.python.service で --workers=1 --threads=1000 と設定
20:31 MySQLパラメータ調整

アプリ側で Too many connections が出ていたのでMySQL設定変更

  • max_connections = 8192 と open_files_limit を設定
  • /lib/systemd/system/mysql.service に LimitNOFILE=65535 を追記
20:35頃 テンプレートエンジンJinja2のチューニング

jinja2のbytecode_cacheを有効に

app.jinja_options = app.jinja_options.copy()
app.jinja_options['bytecode_cache'] = jinja2.FileSystemBytecodeCache()
20:49 画像データの設置周りを修正

アップロードされた画像をtmpファイルに出力した際に最終的な設置場所にハードリンク

os.link(f.name, output)
20:50過ぎ 再起動テスト

再起動テスト実施

再起動後にベンチ実行したらスコアが乱高下したのでいい感じになるまで繰り返しベンチ実行

与負荷側が安定してて高速で助かった

21:07　ベストスコアがでるまでベンチマークを繰り返す

本日のベストスコア 205148 が出て歓声

21:13 終了

お疲れ様でした。

書籍「Linuxステップアップラーニング」

著者である @ryosuke927 さんからご恵贈に与りました。感謝。

Linuxステップアップラーニング

Linuxステップアップラーニング

Ubuntu 16.04 LTSをベースにLinuxの基本操作を学べる初心者向け書籍ですが、この本の素晴らしいところはほぼすべてシェルでの操作方法をまとめ上げてるところ。現場主義の一冊として素晴らしい。
環境構築としてVirtualBoxを紹介するのも理にかなってるんですよね。ドライバなど本筋とは異なる部分で躓くのは実にもったいないので現実的で良いと思います。

ただ、この書籍の1つ残念なところは、pp.12-13の「主なLinuxディストリビューション」にGentooがないところですね。マジか。今やChromebook*1やDockerホスト*2、Pepper君*3などで世界を席巻しつつあるGentoo系OSが紹介されないなんて、私は悲しい。

4/11発売です。季節柄、新人教育にも最適だと思います。是非ともご検討ください。

*1:Gentooと同じportageが使われている

*2:CoreOSや先日Googleから発表されたContainer-Optimized OSなど

*3:Pepper君のベースOSはGentoo

ISUCON6本選で名誉運営としてお手伝いしてきました

この話を頂いた時は正直「名誉運営とは」と思ったのですが、本選に進むつもりで予定も開けてたしと二つ返事で引き受けることにしました。
本選運営のお手伝いとしてやったことは以下のとおり。

  • Azure関連
  • CIの構築
  • Python実装
  • 自分の知見に基づくアドバイスなど

Azure関連

Azureの特性を踏まえた上での構成検討やワンクリックデプロイのためのテンプレート作成などを行いました。

予選ではデプロイの仕組みにcustomData使われていましたが、customDataは実行スクリプトをbase64に変換する必要があり、変更のたびに手間がかかるので、カスタムスクリプト拡張機能を用いてデプロイすることにしました。
customDataはUbuntuなど一部のLinuxでしか動作しないため、カスタムスクリプト拡張を利用するのがオススメです。

また、せっかくだからAzureのサービスを有効活用しようとの流れから、AzureのLog Analyticsを用いて競技者の各サーバにメトリックス情報を収集する拡張機能もインストールするようにしました。

そうそれそれ。でも実は私のミスでOMS側がうまく動かなかったんですけどね…。

CIの構築

本選の準備はGitHubのプライベートリポジトリで進めていたのですが、Azureのワンクリックデプロイを実現するためには公開領域にテンプレートを置く必要があることと、デプロイ用のファイル一式を固めたファイルを生成する必要があったため、CI環境を作成しました。
CIサービスはプライベートリポジトリでも無料で使えるWerckerを採用しました。

また、今回の本選はDocker環境だったのですが、Dockerのビルドおよび動作テストを行うために別途Jenkinsサーバも用意しました。DockerのテストにWerckerを使用しなかったのは、現状Dockerのビルド環境としてWerckerは使えないためです*1。

Python実装

本選のPython実装は私が担当させていただきました。
私が本職プログラマーだった頃は主にPerl/PHPを生業としており、インフラエンジニアな今はちょっとしたツール作成にPythonを書くことが多いもののPythonでWebアプリケーションを実装した経験はほぼゼロ。とても不安でしたがなんとか実装することができました。
当初はTwistedベースの実装を依頼されたのですが、着手してみたところ自分の力量では無理だと判断し、Flaskで実装しなおしています。
また、Python3+Gunicorn(sync)だとServer Side Eventsの実装でyield周りがうまく動かず、ギリギリになって急遽Python2+Gunicornに置き換えたりしました。
残念ながらPythonで予選を通過したチームはいなかったようなので誰からも試されていない可能性があります。もし良かったらPython実装で問題を解いてみてくださいね。

自分の知見に基づくアドバイス

その他、自分の知見に基づいたアドバイスをいくつかさせていただきました。
途中からの運営参加で色々と口を挟むと快く思わない人もいるかもしれないと思い、あまり出しゃばらないように心がけてました。
でも結果として出しゃばってましたね。ごめんなさいごめんなさい。

いやぁ運営ってこんなに大変だったんですね


私はただのお手伝い要員でしたが、それでも結構大変でした。ISUCON運営ってこんなに大変だったんですね。
ただのお手伝いでこれだけ大変なのに、メインの運営の皆様がどれだけ大変かは想像もつきません。
皆さん運営の方々に感謝しましょう。ありがとうありがとう。🙏

*1:できなくはない。QiitaにWerckerでDockerビルドをやる記事あります

ISUCON6予選で敗退しましたがAzureに詳しくなれました

AppArmor Goとして @netmarkjp, @ishikawa84g, @matsuu で参戦しましたが残念ながら去年に続き予選敗退（推定）となりました。最終スコアは24000ぐらいです。

序盤

  • デプロイが終わって何も変更していない状態(デフォルトのperl実装)でベンチマーク回す
    • →スコア0
  • Go言語に切り替えてベンチマーク回す
    • →スコア0
  • MySQLに適切なインデックス追加、htmlifyの正規表現生成を切り出してentryの追加/削除があるまで正規表現をキャッシュして使いまわす
    • →スコア0

えーこれでもダメかーと思いつつ昼食で気分転換。

中盤

昼食で思いつきました。

  • 初期状態でentryごとにマッチするキーワードを予め抽出してキャッシュし、entryの追加/削除があるごとにentryごとのキーワードキャッシュをいい感じに調整することで正規表現生成のコストを下げようとする
    • →キーワード一覧を生成したものの、Goでregexp.Regexpの生成があまりに遅く事前キャッシュが全然終わらない
  • Goのregexp.Regexpの利用を諦めてPCRE実装を試みようとする
    • →実現可能性を疑ってしまいあまり手が進まない
  • このあたりから右往左往

ヤバイヤバイとこのあたりで少し焦り始める。

終盤

この時点で16:30、未だスコア0のまま。

  • Goを一旦諦めPerlに切り替え、htmlifyの正規表現生成をキャッシュするところまで実装
    • →スコア10000ちょいを記録。まじかよF***。Goつらい。
  • ようやくスタートラインだ、Perlでボトルネックを調べて潰していこう
    • 久々のPerlですっかりDevel::NYTProfの使い方を忘れてしまっており、ボトルネックをきちんと把握できないままの悪戦苦闘

最後にスコア24000ぐらいを記録してフィニッシュでした。つらい。

反省会

Goで正規表現のCompileが遅いのは事前に把握していたのですが、それをどうにかする方法が思いつかず惨敗でした。またGoを諦める判断も遅かったしGo以外も勉強しておけばよかった。複数の言語に対応できるようにしておくことは大事ですね。

あとで聞いた話によるとgolangであればstrings.Replacer が使えるらしいです。なるほどー。しかし自分の知識とググラビリティではその情報にたどり着くことはできなかったでしょう。南無。

まとめ

予習のおかげでAzureに随分詳しくなれました。今後の仕事に大いに役立ちそうな気がします。
ISUCONでは負けましたが、大きな戦果を得ることができました。ありがとう運営さんありがとうISUCON!

ISUCON6予選の過去問Vagrantも作り始めてます。乞うご期待。

ISUCONの練習に使える環境を各種ご用意しております

前回の記事もISUCONネタだったmatsuuです。ISUCONのことしか書いてないがな。

ISUCONで良いスコアを叩き出すためには過去問を解くことが大事と1年前にも書かせて頂きましたが、今回も様々な環境で過去問にチャレンジできるようにしました。どうぞご査収ください。

Microsoft Azure

今回のISUCON6はMicrosoft Azure上で行われるということで、Azure用テンプレートを用意しました。クリックするだけでAzure環境にデプロイが可能です。
https://github.com/matsuu/azure-isucon-templates
ISUCON5予選とPixivさんの社内ISUCONをデプロイするテンプレートを用意しております。
内部的には真っさらなOS上でAnsibleによるプロビジョニングを行っているため構築に1時間弱かかりますのでご了承下さい。

今回初めてテンプレートを作ったので抜け漏れがあるかもしれません。問題があれば随時ご指摘ください。

Vagrant

前回のVagrant環境も更新しました。
https://github.com/matsuu/vagrant-isucon
https://github.com/matsuu/vagrant-pixiv-isucon2016
vagrant upを実行すればAnsibleによるプロビジョニングが始まります。boxの配布までは行っておりません。ごめんなさい。

Ansible

同様にAnsible環境も更新しています。
https://github.com/matsuu/ansible-isucon
Pixivさんの社内ISUCONは公式リポジトリのAnsibleをご利用ください。

Terraform

過去問の本家AMIなどを起動するためのTerraformも用意しています。
https://github.com/matsuu/terraform-isucon
https://github.com/matsuu/terraform-pixiv-isucon2016
移植版も含まれてます。移植版はプロビジョニングにAnsibleが使われるので構築に時間がかかります。ご注意ください。

Docker

今回テスト的にDocker環境も用意してみました。
https://github.com/matsuu/docker-isucon
とりあえず作りやすそうなISUCON4予選で作ってみましたが、AnsibleからDockerfileへの書き換えでかなり疲弊したためもう作りたくありません。
Docker HubでAUTOBUILDを回しているのでdockerコマンドでダウンロード可能です。各言語ごとのdocker-compose.ymlも用意しています。

まとめ

環境構築ばかりやっていて過去問を解く時間がないです。何やってんだ。
みなさんのお役に立てば幸いです。