builderscon 2018に行ってきたよ

builderscon.io

builderscon 2018 に 参加してきたので、レポート。

buildersconの良いところ

  • 知識欲を満たせる豊富なカテゴリのセッション!
  • その道に詳しい人によるハイレベルなセッション!
  • 「知らなかった!」を絶対聞ける!
  • 普段(使ってない|知らない)技術でも「ちょっと聞いてみよ」ができる
  • 開催してる場所が日吉駅で、個人的にそこそこアクセスが良い

buildersconのイマイチなところ

  • ステッカーいらない問題(後述します)
  • 人気のセッションが聞けなかったり、座れなかったりする(とはいえ、大体のセッションがYouTubeで公開されるはずなので、後で見れたりできるはず)
  • ゆえに、発表後のQ&Aを聞かずに待機列に並ぶ人も・・・

空間による制約のせいなので、全員VR上でカンファレンスすればいいのでは????(極端

自分のよかったところ

  • チケットの販売が始まった瞬間に、前売り券を買ったこと
  • 遅刻せずに(懇親会を覗く)全日程をこなした

自分の悪かったところ

  • スポンサーチケットを買わなかったところ(名札欲しいっていろいろなセッション聞いてめっちゃ思った・・・)
  • LTしたいな〜と思っていたら、いつの間にか登録終わってたみたい(というか、どこからどのタイミングでLT申し込みできたのかよくわからなかった。)
  • 懇親会に行ったりして、知らない人と話すみたいなムーブをしなかった

聞いたセッション

  • Envoy internals deep dive
  • ランチセッション (サイボウズ株式会社): Kubernetes で実現するインフラ自動構築パイプライン
  • Building and operating a service mesh at mid-size company
  • Webサービスにて200週連続で新機能をリリースする舞台裏
  • 実録!ある担当者がみた「謎ガジェット」開発1年史
  • JavaCardの世界
  • ブロックチェーン(DApp)で作る世界を変える分散型ゲームの世界
  • 次世代通信プロトコルにおけるセキュリティ・プライバシー保護・パフォーマンス (Security, privacy, performance of the upcoming transport protocols)

  • 高集積コンテナホスティングにおけるボトルネックとその解法

  • ブログサービスのHTTPS化を支えたAWSで作るピタゴラスイッチ

  • Webアプリケーションエンジニアが知るべきDNSの基本

  • なぜ私はキーボードを作るのか

私的ベストスピーカー

意見

完全に余談です。超個人的な意見ですが、主催者がフィードバックを求めているとおっしゃっていたので書きます。

企業ステッカーいらない問題

って書いたけど、よく考えたらスポンサー企業によって支えられてるから、受け取る義務があるのかな・・・。

各企業の方は、本当にステッカー需要あるか考えたほうがいいかも・・・。

少なくとも僕にとっては本当にいらないし、捨てるのもかわいそうだけど、全部捨てました・・・。

他のノベルティは大体嬉しいけど、ステッカー本当にいらない・・・。

まとめ

buildersconに関わるすべての皆様、ありがとうございました!

控えめにいって、これ以上最高のカンファレンスはないだろうっていうぐらい最高でした。

この記事を読んだ人で、buiidersconに参加したことない人は絶対1度参加してみることを強くオススメします!

Evernoteより100倍便利なメモサービス「Notion」を今すぐ使おう

こんばんは、今日*1は歴史的な台風ですが、皆様いかがおすごしでしょうか。

今朝、たまたまTwitterを見ていて発見したメモツール「Notion」が今までのメモツールの100倍は軽く超えてくるレベルで良いので紹介したい。

f:id:serinuntius:20180904230110p:plain

今までのメモツールの歴史を覆す「Notion」

今までのメモツールってどれも基本的には画一的で、メモ帳の粋を超えることが出来ていなかった

しかし、「Notion」 は違う。 メモ帳2.0 だと思う。明らかにバージョンが上がった。

何が今までのメモ帳と違うのかサクッと紹介したい。

従来型のメモ帳ツールとの違い

個人的に感じた違いを3つほど紹介する。

本当に全部入り

基本的にメモ帳、タスク管理系のツール、スプレッドシートWikiやカレンダーって

  • 得意な分野
  • 特定の機能

があったりするから、それぞれ別のツールを使っているはずだ。

しかし、基本的に他のツールの全機能がNotionにあるので、他のツールを使う必要はあんまりなくなるかもしれない。*2

情報の探しやすさ

知識を集約させる系のメモ帳ツールでは、情報の探しやすさはかなり大事だ。

Notionは情報に対するIndexの構築をユーザがかなり自由に設定できる。 特定の情報のIndexページを作るもよし、タグを付けるもよし、スプレッドシートで管理するもよし。

コンポーネントの分離の美しさ

各オブジェクトがキレイに分離されていて、直感的に使いやすい

情報共有の容易さ、権限を絞るの容易さ

全てのオブジェクトに対して、リンクを発行してハイパーリンクが出来る。

そのハイパーリンクには、1つ1つ権限を付けたり、付けなかったりが容易です。

全てがDBとして扱える

皆さん、無理やりスプレッドシートをDBのように使いますよね。

けど、それってかなり無理やり使っていてDB本来の旨味を享受できていないんですよね。

Notionはあらゆるデータに対するインターフェースとなり、DBを意識せずとも扱えるようになっています。

どういう用途に向いているか

  • 社内Wiki(個人的に一番向いているかなと)
  • Webクリップとして
  • タスク管理ツールとして(Trelloの代替)
  • UIの美しいスプレッドシートとしてw
  • 企画書として(スプレッドシートの企画書なんてどう考えても間違っている)
  • ブログとして
  • カレンダーとして
  • リマインダーとして

とりあえず、なんでも使える!

何がいいのか

ドキュメントに階層構造を持てる

階層構造にできるので、なんか書いてて膨らんできちゃったな〜と思ったら別ノートにすればいい。

全てがここにまとまる

よくあるのが、資料や企画書にリンクが貼ってあって、別のタブ、アプリケーションで開く羽目になるというのがあるが、それがなくなる。

画像も貼れるし、スプレッドシートも貼れるし、カンバンも貼れるのであっちゃこっちゃしない。

使用例

適当にいろいろなテストをしたノートを公開する。

www.notion.so

まとめ

便利なのでどんどん使っていこう。

まだ1日目なので、ロクな使用例がなくて申し訳ないが、1ヶ月ぐらい立ったらまたレポート書きたい。

*1:2018年9月4日

*2:流石に言いすぎかも

「Linuxのしくみ ~実験と図解で学ぶOSとハードウェアの基礎知識」を買った

最近、低レイヤーなことに興味を持ち始めたので買った。

技術書って、今読むか後で読むかの違いなので、迷ったら買うのが良いと思っている。

技術書読むの昔は大嫌いだったけど、 YAPCkindle oasisもらってからかなり読むようになった。

やっぱり、技術書って自分の知らないことがまとまって書いてあるので、良い。

一歩踏み込んだnginxのプロファイリングをする

ISHOCON2で惨敗して、悔しくてたまらなくてhttp2やnginxのことについてずっと調べたので、調査記録として残しておく。

serinuntius.hatenablog.jp

一番手軽で万能な「strace」

straceとはprocessに直接アタッチして、システムコールを調査するためのコマンドです。

インストールも簡単で、使うのも簡単です。 しかも、どんなツールにも使うことができます。

しかし、読み解くのは難しいです。(個人的な感想です。)

使い方

ざっくりと集計してボトルネックを探す

まず、調査対象のpidが必要なので、 ps aux|grep nginx とかで nginxのpidを調べます。

ubuntu@ip-172-31-21-29:~$ ps aux|grep nginx
root     20904  0.0  0.0  42976   852 ?        Ss   04:22   0:00 nginx: master process /usr/sbin/nginx -g daemon on; master_process on;
root     20905  0.0  0.1  48424  6848 ?        S    04:22   0:00 nginx: worker process
root     20906  0.0  0.0  47752  3664 ?        S    04:22   0:00 nginx: worker process
ubuntu   22510  0.0  0.0  13136   972 pts/0    S+   11:54   0:00 grep --color=auto nginx

masterプロセスではなく、worker processのpidをメモしておきます。 この例だと、20905か20906ですね。どちらでも良いです。

strace -c -S time -p 20905

オプションの意味は

-c で集計
-S で集計結果を何でソートするか(今回はtime)
-p pid

だと理解しています。

この状態で、ベンチマーカーを回します。*1

ベンチマーカーを回して、もう良いかな〜というタイミングで ctrl-c で止めます。すると、こんな感じで集計結果が見れます。 f:id:serinuntius:20180826210931p:plain

readを占める割合が一番多いですね。あと、エラーがめっちゃ出ているのも気になります。

集計結果を元にあたりをつけて調査する

先程の集計結果で、 read を占める割合が一番多かったので、 readシステムコールだけ追ってみます。

sudo strace -T -s 1024 -e read -p 22773 -k -o /tmp/strace.read.stack

オプションの意味は次のような感じだと理解しています。

-T 時間を出す
-s 1024 (デフォルトだと、1行の長さが省略されてしまうので、適当に長くする)
-e read (システムコールを絞り込む。)
-p pid
-k (スタックトレースを出す)
-o /tmp/strace.read.stack (ファイルに出力する)

このログを見ていると、

read(10, "\26\3\1\0\237\1\0\0\233\3\3\312\323\257.\224\3\2750C.\374os\302\343\16\310\7\214\2104\341\332\252\7\204\362\355#,v)\0\0 \300/\3000\300+\300,\314\250\314\251\300\23\300\
t\300\24\300\n\0\234\0\235\0/\0005\300\22\0\n\1\0\0R3t\0\0\0\5\0\5\1\0\0\0\0\0\n\0\n\0\10\0\35\0\27\0\30\0\31\0\v\0\2\1\0\0\r\0\22\0\20\4\1\4\3\5\1\5\3\6\1\6\3\2\1\2\3\377\1\0\1\
0\0\20\0\16\0\f\2h2\10http/1.1\0\22\0\0", 16709) = 164 <0.000035>
 > /lib/x86_64-linux-gnu/libpthread-2.27.so(read+0xe) [0x1134e]
 > /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1(BIO_sock_should_retry+0x5e) [0xa0a2e]
 > /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1(BIO_read+0x63) [0x9b613]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_rstate_string+0x148) [0x1c3e8]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_rstate_string+0x3e67) [0x20107]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_rstate_string+0x17d3) [0x1da73]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_in_before+0x850d) [0x3f40d]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_in_before+0x6aa) [0x375aa]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_do_handshake+0x41) [0x2f901]
 > /usr/sbin/nginx(ngx_ssl_handshake+0x3d) [0x5418d]
 > /usr/sbin/nginx(ngx_http_process_request+0x1364) [0x6a024]
 > /usr/sbin/nginx(ngx_os_specific_status+0x56c) [0x4f89c]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x54) [0x44934]
 > /usr/sbin/nginx(ngx_dlerror+0xe85) [0x4d7e5]
 > /usr/sbin/nginx(ngx_spawn_process+0x1a1) [0x4bc11]
 > /usr/sbin/nginx(ngx_dlerror+0x560) [0x4cec0]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x1ce) [0x4e58e]
 > /usr/sbin/nginx(main+0xab6) [0x22506]
 > /lib/x86_64-linux-gnu/libc-2.27.so(__libc_start_main+0xe7) [0x21b97]
 > /usr/sbin/nginx(_start+0x2a) [0x226fa]
read(10, 0x56235cb4d0a3, 16709)         = -1 EAGAIN (Resource temporarily unavailable) <0.000029>
 > /lib/x86_64-linux-gnu/libpthread-2.27.so(read+0xe) [0x1134e]
 > /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1(BIO_sock_should_retry+0x5e) [0xa0a2e]
 > /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1(BIO_read+0x63) [0x9b613]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_rstate_string+0x148) [0x1c3e8]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_rstate_string+0x3e67) [0x20107]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_rstate_string+0x17d3) [0x1da73]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_in_before+0x850d) [0x3f40d]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_in_before+0x6aa) [0x375aa]
 > /usr/lib/x86_64-linux-gnu/libssl.so.1.1(SSL_do_handshake+0x41) [0x2f901]
 > /usr/sbin/nginx(ngx_ssl_handshake+0x3d) [0x5418d]
 > /usr/sbin/nginx(ngx_http_process_request+0x1364) [0x6a024]
 > /usr/sbin/nginx(ngx_os_specific_status+0x56c) [0x4f89c]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x54) [0x44934]
 > /usr/sbin/nginx(ngx_dlerror+0xe85) [0x4d7e5]
 > /usr/sbin/nginx(ngx_spawn_process+0x1a1) [0x4bc11]
 > /usr/sbin/nginx(ngx_dlerror+0x560) [0x4cec0]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x1ce) [0x4e58e]
 > /usr/sbin/nginx(main+0xab6) [0x22506]
 > /lib/x86_64-linux-gnu/libc-2.27.so(__libc_start_main+0xe7) [0x21b97]
 > /usr/sbin/nginx(_start+0x2a) [0x226fa]

まぁ、本当はもっとあるんですが、だいたいこれが並んでいます。

これ見て気づくのは、libssl.so とか libcrypto.so とか、重そうなやつが並んでますね〜。

つまりこれは TLSのハンドシェイクが負荷となっているわけです。(たぶん)

なのでいい感じの対策を考えなければなりません。

対策は、後ろでまとめます。

出すのは面倒だけどわかりやすい「FlameGraph」

straceとは別のアプローチとして、FlameGraphを出してみるというのがある。

nginx profilingでググると、一番上にOpenRestyの記事がヒットする。

The most useful tools are

C-land on-CPU Flame Graph tool: https://github.com/openresty/nginx-systemtap-toolkit#sample-bt

C-land off-CPU Flame Graph tool: https://github.com/openresty/nginx-systemtap-toolkit#sample-bt-off-cpu

Lua-land on-CPU Flame Graph tool: https://github.com/openresty/stapxx#lj-lua-stacks

そこで紹介されているのが、 openresty/nginx-systemtap-toolkit というやつです。

今回はそれを使ってみます。

インストール方法

sudo apt-get install -y systemtap gcc
git clone https://github.com/openresty/nginx-systemtap-toolkit
git clone https://github.com/brendangregg/FlameGraph

使い方

まず、 .bt っていうのを生成するらしい

cd nginx-systemtap-toolkit
sudo ./sample-bt -p 17084 -t 10 -u > /tmp/a.bt

オプションの意味は、

-p nginxのpid
-t 10(時間、僕の環境だと長くするとエラーでちゃう)

次に、さっきの .bt から .cbt を生成する。 その、.cbt から .svg を生成する。

# cloneしたFlameGraphのリポジトリに移動する。
cd ../FlameGraph

# btからcbtを生成する
./stackcollapse-stap.pl /tmp/a.bt > /tmp/a.cbt

# cbtからsvgを生成する
./flamegraph.pl /tmp/a.cbt > /tmp/a.svg

あとは、これをscpとかでローカルに持ってくるなりして、ブラウザなりで開いてみるといい感じのFlameGraphが表示されるはずです。

読み解き方は、僕の雑な記事や、Deeeeetさんの神記事GolangでFlame Graphを描く を読むと良いかもしれません。

HTTP 1.1 のときのグラフ

sslで絞り込みして、紫になっているのですが、それがssl周りのスタックです。 結構な回数呼び出されてますね。 f:id:serinuntius:20180826110704p:plain

HTTP 2 のときのグラフ

劇的に、sslの呼び出し回数が減っています。 f:id:serinuntius:20180826110957p:plain

2つの調査結果から考えられる対策

http2にする。

    listen 443 ssl http2;

http2にすると、いい感じにコネクションを使いまわしてくれるみたい。(あんまりわかってないのでちゃんと勉強する。)

(そもそも、keep aliveの設定をちゃんとしていなかったので、それを設定しても効果あるのかな?ここもよくわかってないので、また今度調べる)

まとめ

  • 簡単にざっくり調べるには、 strace が便利
  • いい感じに負荷がかかっている理由等を調べるには FlameGraph が便利
  • コネクションの負荷、TLSの負荷を考えるの大事
  • http2

参考

strace の -k オプションでスタックトレースを出す - hibomaの日記

OpenResty - Profiling

https://wiki.ubuntu.com/Kernel/Systemtap

GitHub - openresty/openresty-systemtap-toolkit: Real-time analysis and diagnostics tools for OpenResty (including NGINX, LuaJIT, ngx_lua, and more) based on SystemTap

GitHub - brendangregg/FlameGraph: Stack trace visualizer

*1:今回はISUCON(ISHOCON)だったので、ベンチですが、実業務ではtmuxでしばらく放置でしょうか?

ISHOCON2というISUCONの個人大会で惨敗してきました【優勝スコアと同等の参考実装付き】

昨日(2018年8月25日)、ISHOCON2というISUCONの個人競技バージョンの大会に参加してきたのでレポートです。スコアが思うように伸びなかった方はぜひ読んでみてください。

ISHOCONとは

github.com

f:id:serinuntius:20180826113155p:plain

ISHOCON2

iikanjina showwin contest 2nd (like ISUCON)

ISHOCONとは Iikanjina SHOwwin CONtest の略で、ISUCONと同じように与えられたアプリケーションの高速化を競うコンテスト(?)です。

らしいです。

ISHOCONの特徴

ISHOCONの特徴は、個人的に3つあると思います。

問題がコンテスト開催前からオープンであること

これ、ISUCONでは絶対ありえないと思うのですが、開催する前からオープンです

なので、自分はgraqtのテスト、またISUCONの練習として、1週間ぐらい前に取り組みました!

おかげで、モチベがあがってgraqtの実装がだいぶ進みました!

個人参加であること

ISUCONはチームで参加を前提としていますが*1、ISHOCONはむしろ個人同士のコンテストです。

なので、どれだけ幅広い知識を持っているかが求められていると思います。

僕は、アプリやDB周りはなんとか出来ますが、インフラ系は経験が浅く苦手意識があります・・・。

ベンチマーカーもオープンであること

これもISUCONでは絶対ありえないのですが、なんとベンチマーカーまでオープンになっています。

ベンチマーカーの気持ちがわかれば、スコアが伸びるかも??

Go実装を選択してやったこと

本当に勘違いして欲しくないのですが、事前回答時にmysqlである程度高速化してこれ以上速くならないな〜と思ったので最初からRedisに載せるという攻略方針でやっています。

最初から全部cacheさせる、Redisに載せるは本番のISUCONでは通用しないと思います。

この記事を読んでくださった学生さんや、ISUCON初学者の方にそこは勘違いして欲しくないです。*2

事前回答時のmysqlを一部捨てて、redisに載せるぞというp-rを一応貼っておきます。

Feature/cache by serinuntius · Pull Request #4 · serinuntius/ISHOCON2 · GitHub

CSSをNginxで返す

Goで静的ファイルを返してたので、Nginxで返すようにしました。 プロファイリングツールの導入 & css => nginx by serinuntius · Pull Request #2 · serinuntius/ishocon2-2 · GitHub

プロファイリングツール入れる

graqtをサクッと入れて、見てみるとこんな感じでした。

https://user-images.githubusercontent.com/10571219/44613717-e3f3f200-a852-11e8-9379-5b1da0f49d17.png

普通のISUCONより、デフォルト状態で圧倒的に速いんですよね〜w Maxで0.43ってw

「別にチューニングするほど遅くないやん」 って内心思っちゃいました。

スコア「10:36:49 score: 6460, success: 5380, failure: 0」

templateを外に出す

GolangのWAFとしてginが使われているのですが*3、それのwarningが気になったので修正しました。

詳しくは覚えてないですが、「Handlerの中でSetHTMLTemplateするのマジやめろ」 みたいな内容だったと思います。

r.SetHTMLTemplate(template.Must(template.ParseFiles(layout, "templates/vote.tmpl")))

templateを外に出す & sessionなくす by serinuntius · Pull Request #3 · serinuntius/ishocon2-2 · GitHub

なので、mainの中で登録してあげました。

スコア「10:59:06 score: 6604, success: 5452, failure: 0」

mysqlとnginxのコンフィグをgit管理するように

適当に、いい感じにしました。(したつもり)

ガバガバチューニングなので、 innodb_log_file_size = 1G のせいでバカでかいログファイルが2つも出来て、あとでディスク容量で苦しみます。

スコア「11:09:19 score: 6714, success: 6082, failure: 0」

GETのレスポンスは全部cacheする

アクセスログ見てるとベンチマーカーがアクセスするパターンがわかるのですが、 ざっくりいうと大量の POST /vote が来て、その後に各GETが来るという感じになっていて、POSTが来たときにcacheを消すということをしておけばOKだった。

なので実質、「GETのロジックとかどうでもよくてcache返すのでそこがある程度重くても特に問題ない」 というのが今回のポイントです。*4

その対応がこちら。 Feature/response cache by serinuntius · Pull Request #5 · serinuntius/ishocon2-2 · GitHub

ここはginのおかげでデフォルトでcache機構があってかなり楽できた。 イマイチdocとか実装みても使い方のイメージが掴めなかったので、いろいろ調べているとherokuの公式記事が出てきた。これが参考になった。

devcenter.heroku.com

この記事は、メモリストアをmemcacheにしているけど、オンメモリ実装が普通にあって、それを利用した。

スコアworkload20で「11:28:44 score: 23474, success: 15962, failure: 0」

POST /vote のレスポンスもcacheする

エラーメッセージがいくつかあるのですが、そこもメッセージごとにcacheしてしまえば、テンプレートレンダリングが各種1回だけで済むのでいい感じです。

正常時のレスポンスもcacheできます。

ここは事前に準備してたときに、どうやったら1度呼び出したテンプレートのレスポンスボディが取得できるかいろいろ調べてたどり着いた答えは、 「gin.ResponseWriter の interfaceを実装した structを作って差し替える案」です。

Goはこういうのがサクッと効率良くできるので良いですね。

具体的にはこんな感じです。

type bodyCacheWriter struct {
    gin.ResponseWriter
        // cache用のbody
    body *bytes.Buffer
}

 func (w bodyCacheWriter) Write(b []byte) (int, error) {
    w.body.Write(b)
    return w.ResponseWriter.Write(b)
}

使い方はこんな感じ

bcw := &bodyCacheWriter{
    body:           &bytes.Buffer{},
    ResponseWriter: c.Writer,
}

// cはgin.Context
// 差し替える
c.Writer = bcw

// あとは普通に返す
c.HTML(http.StatusOK, "vote.tmpl", gin.H{
    "candidates": candidates,
    "message":    "投票に成功しました",
})

// このあとでbcw.bodyをメモリに載せれば OK

実際には、bcw.bodyからRedisに載せる作業がありますが、本質ではないので省略します。後で気づくのですが、別にRedisに載せなくても普通にmapにcacheした方が良いですね。

スコア workload20で「11:54:47 score: 24550, success: 16950, failure: 0」

はい、ここまで破壊的な変更は一切行っておりません。 かなり安全に書き換えるだけで、24550点になります。

投票をRedisに載せる

これはかなり破壊的な変更になります。

今までvoteテーブルに1レコードずつ、mysqlにInsertしていたのですが、それをやめてRedisのsorted setや普通の文字列型とかでいろいろ持つようにします。

ここのロジック本当に汚くて、自分でも嫌気がさすのですが、こうなってしまいました。もっと効率の良い持ち方があると思いますが、1度思いついてしまうと中々その考えが離れず、最後まで変えることが出来ませんでした。

// goroutineで並列にしてるけどあんまり意味ないかも
var eg errgroup.Group

eg.Go(func() error {
    _, err := rc.ZIncrBy(politicalParty, float64(voteCount), keyword).Result()
    if err != nil {
        return errors.Wrap(err, "")
    }
    return nil
})

eg.Go(func() error {
    _, err := rc.ZIncrBy(candidateZKey(candidateID), float64(voteCount), keyword).Result()
    if err != nil {
        return errors.Wrap(err, "")
    }
    return nil
})

eg.Go(func() error {
    _, err := rc.ZIncrBy(kojinKey(), float64(voteCount), candidateVotedCountKey(candidateID)).Result()
    if err != nil {
        return errors.Wrap(err, "")
    }
    return nil
})

eg.Go(func() error {
    _, err := rc.IncrBy(candidateKey(candidateID), int64(voteCount)).Result()
    if err != nil {
        return errors.Wrap(err, "")
    }
    return nil
})

eg.Go(func() error {
    _, err := rc.IncrBy(userKey(userID), int64(voteCount)).Result()
    if err != nil {
        return errors.Wrap(err, "")
    }
    return nil
})

eg.Go(func() error {
    sex := candidateIdMap[candidateID].Sex
    _, err := rc.IncrBy(sexKey(sex), int64(voteCount)).Result()
    if err != nil {
        return errors.Wrap(err, "")
    }
    return nil
})


if err := eg.Wait(); err != nil {
    return errors.Wrap(err, "Failed to wait")
}

Sorted Set

  • 政党に対する支持者の声ランキング(zincrby)
key: 政党名
member: 支持者の声
increment: 投票数
  • 候補者に対する支持者の声ランキング(zincrby)
key: 候補者のid
member: 支持者の声
increment: 投票数
  • 候補者の投票数ランキング(zincrby)
key: "候補者の投票数ランキング"
member: 候補者のid
increment: 投票数

文字列型

  • 候補者の投票数(incr)
key: 候補者のid
increment: 投票数

(あれ?これ、候補者の投票数ランキング(zincrby)使えば削れそう)

  • ユーザの投票数(incr)
key: ユーザのid
increment: 投票数
  • 性別別投票数
key: 性別("男"、"女")
increment: 投票数

なんか削れそうなやつも発見しましたが、createVoteはこういう感じになりました。こんだけの数incrするの遅いに決まってるけどmysqlにinsertしないってたぶんこういうことなんでしょうね・・・。厳しいw

けど、これのおかげで GET /がシンプル(大嘘)になるんですよね。

1~10位、それと最下位っていうの、SQLだとかなり厳しいですが、Redisのsorted setを使えば2発でサクッと(?)取ってこれますね。

ZREVRANGEBYSCOREとZRANGEBYSCOREを使います。

// 1 ~ 10 の取得
results, err := rc.ZRevRangeWithScores(kojinKey(), 0, 9).Result()
if err != nil {
    log.Println(err)
}

// 最下位
resultsWorst, err := rc.ZRangeWithScores(kojinKey(), 0, 0).Result()
if err != nil {
    log.Println(err)
}
// これで1〜10位と最下位のsliceの出来上がり
results = append(results, resultsWorst...)

Redisのsorted setあんまりちゃんと使ったことがなかったので、コマンド名が呪文みたいだな〜と思っていたのですが、ちゃんと意味を理解すると簡単ですね。

ベースのコマンドがzrange(昇順)で、startとendのmemberを取ってくるというコマンドになっています。それにスコアをつけてほしかったら、withscoresになる。

で逆順だと、zrevrange になる!それだけのシンプルな話でした。

あとは、ゴリゴリRedis実装に差し替えていくだけです。 詳しくはp-r見てください。特に変わったことはしてないつもりです。

Feature/fix vote by serinuntius · Pull Request #7 · serinuntius/ishocon2-2 · GitHub

スコア workload20で「13:05:49 score: 40228, success: 31964, failure: 0 」

このあたりで、完全にnginxがボトルネックに変わります。 topで見ているとNginxが70%ぐらいを占めています。

都度メモリのアロケーションが走ると重そうなので、 POST /vote を中心にsync.Pool計画

nginxでTLSのキャッシュとか入れてるし、静的ファイルもgzipで返してるし、ベンチマーカーはETAGとか、cache-control ヘッダは見てくれないし、nginxの負荷を落とすのは無理ゲーやろと思って、nginxがボトルネックになっているとはわかってはいつつもアプリを直します。

メモリのアロケーションって結構重い処理みたいで、structとか使い回すと良いみたいですね。その使い回しを楽にやってくれるパッケージが syncにあります。

その名も 「sync.Pool」!

こいつを使えばいい感じにオブジェクトをpoolしてくれるのでメモリのアロケーションが減ります。*5

雑に書いても他のLLと比べたらかなり速いのに、もっとちゃんと書いたら更に速くなるGoはやっぱり最高。

使い方はこんな感じです。

type User struct {
    ID       int
    Name     string
    Address  string
    MyNumber string
    Votes    int
}

// Poolを作る
var userPool = sync.Pool{
    New: func() interface{} {
        return &User{}
    },
}

func newUser() *User {
    return userPool.Get().(*User)
}

// 適当ですけどこんな感じの使用感
func hoge() {
  u := newUser()
  defer u.close()
  u.Name = "hoge"
  fmt.Println(u)
}

// なんとなくファイルみたいにcloseにしておいた
// ここでまっさらにしておかないと不都合がある場合はゼロ値で埋めるみたいな処理があったほうが良いかも
func (u *User) close() {
    userPool.Put(u)
}

実際の対応 Feature/user pool by serinuntius · Pull Request #8 · serinuntius/ishocon2-2 · GitHub

スコア workload 30「2018/08/25 06:21:42 {"score": 41714, "success": 32482, "failure": 0}」

ベンチマーカーとの戦い ~リアルISUCON~

このちょっと前ぐらいから、アプリケーションが高速化しすぎて、ベンチマーカーが荒ぶるという事件が起こりだしました。

運営さんのリアルISUCONです。

僕は、事前に問題を解いていたこともあり、ボトルネックがnginxにありこれ以上スコアを上げることは厳しそうなので、運営にコミットしてベンチマーカーを直すという選択肢を選びました💪*6

アプリへの接続のコネクションの使い回しをせずに、ガンガンリクエストしているとエフェメラルポートが枯渇するという問題だと勝手に思っていたのですが、どちらかというとベンチマーカーもmysqlを持っていてそれをベースにリクエストしているみたいなのですが、どうやらそこのmysqlの接続するところで Too many connections が出ているということがわかりました。

なんでだろうと思って、ベンチマーカーのコード読んだら、都度openしてるじゃないですか〜、ヤダ〜w

f:id:serinuntius:20180826153212p:plain

dbのクライアントを使い回すようなp-rを出しました。

https://github.com/showwin/ISHOCON2/pull/25github.com

最新のcontestブランチから切ったもつもりが、古いブランチでコンフリクト解消しようと思ったら変な差分出てしまって、手間取ったので、このp-rはcloseにして、showwinさんに変更だけ入れていただきました。

テンパって手間取っていたのを優しく待ってくれたshowwinさんは優しい方でした。僕のp-rが入らないのも「良いのか?」と聞いてくださいましたし。

僕としては、とりあえず速くベンチ直って走るようになればどうでも良かったので、速い方でお願いしました!

このとき、焦って、MaxIdleConnectionや、MaxOpenConnectionの設定を忘れました・・・😇

で、なんだかんだしてたら、終了です。 最後までベンチマーカーに嫌われ*7、top10入りさえ出来ませんでした。 手元のベンチマーカーインスタンスでベンチ回すとスコアは4万ぐらいは出ていたので、top10には入れるはずだったのですが。

ボトルネックを解消する意義

ISUCONって本当にボトルネックを改善しないとスコアは思うように伸びないようにできていて、ボトルネックを解消するのが大事です。

こんなツイートもしています。

かなり、ブーメランだ・・・。 nginxがボトルネックなのに、それの改善を出来なかった人が言うことじゃないw

ちなみに、競技終了後に優勝した方にnginxのconfigのについて聞きました。

細かい違いはあれど、大事なhttp2の設定がありました。

    listen 443 http2;

はい、これを書くだけでhttp2になるみたいです。

ちなみに自分はこの対応を入れるだけで、優勝スコアと同等の25万点に到達しました。

く、悔しい・・・。

アプリケーションの改善はほぼ完璧だったということでしょう。

自分のインフラ力のなさが露呈する結果となってしまいました。

ですが、自分のボトルネックがわかるのもISUCONの面白いところで、どういう知識を増やせばアプリケーションを高速化できるかっていうのがかなり客観的にわかります。

実際のISUCONはチームなので、得意な分野がそれぞれ違う3人が集まったほうが強いでしょうね。

なぜhttp2にするとnginxのボトルネックが解消するのか

これは別記事で書こうと思います。

2018年8月28日21時追記しました

serinuntius.hatenablog.jp

優勝スコア25万点に到達できる実装

ここにあります!!

github.com

優勝した方との差分

おそらくですが、優勝された方のコードは公開されていないので優勝インタビューから推測するしかないですが、差分は以下ぐらいだと思います。

  • レスポンスをcacheするんじゃなくて、静的なファイルとして書き出して、nginxで返す

っていうのは斬新でした。僕は思いつきもしなかったです。

謝辞

改めて、問題を作成されたshowwinさん、会場提供、最高の弁当提供、インスタンス提供してくださったscoutyさん ありがとうございました!

まとめ

  • やっぱりISUCONは楽しい
  • ISHOCONも楽しい
  • 得意不得意があるので、お互いをカバーできるチーム構成が良さそう

*1:今年からお一人様枠が出来ましたが

*2:といいつつ、自分もISUCONに参加したことのない初学者ですが・・・

*3:これ系のコンテストで、デファクトじゃない実装使われるのだいぶ厳しい・・・。GolangはうすいWAFが使われるイメージがある。

*4:1人で8時間のコンテストだから別に良いけど、本家ISUCONだとこうはいかないだろうな〜と・・・

*5:趣味Gopherなので、お目にかかる機会はあんまりありませんでした。便利ですね

*6:これができるのもオープンなベンチマーカーのおかげ

*7:まだ、Too many connectionsが出ていたようです

Goのボトルネック調査にgo-torchがめっちゃ良い

こんばんは〜。

ISUCONの練習に励んでいる @_serinuntiusです。

自作のWebアプリケーションのボトルネック調査アプリケーションgraqtを書いていますが、もっと便利(?)なツールがあることを僕は知ってしまいました。

それがgo-torchです。

f:id:serinuntius:20180821212032p:plain

go-torchとは

Tool for stochastically profiling Go programs. Collects stack traces and synthesizes them into a flame graph. Uses Go's built in pprof library.

とのことで、goの組み込みのpprofというツールを使って、スタックトレースをプロファイリングして、炎のグラフ(?)を作成してくれるツールです。

このグラフが慣れると超読みやすくてボトルネックが簡単にわかります!(たぶん)

go-torchの読み方をちゃんと日本語で説明してくれている記事はとても少なく、deeeetさんのGolangでFlame Graphを描く | SOTA という記事ぐらいでしかちゃんと解説されていません。

このグラフを雰囲気で読むと痛い目にあう(すごいxy軸が独特)ので、自分なりにグラフの読み方を書きたいと思います。

go-torchのすごいところ

go-torchの読み解き方

軸の解説をしておきますと、x軸(幅)は出現回数で、y軸はstackされている数です。

要注意なのは、各軸が長いからといって遅いとは限らないということです。

x軸が長い、つまり幅が長いということはその関数が、他の関数に比べて多く呼ばれているということを表しています。

y軸が長い、つまりたくさんの関数がスタックされているところは、関数が多いだけで遅いわけではありません。

そして、もう1つ注意なのが、 色は全く関係ありません。

大事なので、もう一度言います!

色は全く関係ありません。

これは図を読みやすくするための手段らしいです。

まとめ

正直自分の記事を読むより、deeetさんの記事を繰り返し読むほうが良いw

10回ぐらい読み直して、ちょっと理解できた。

参考

GitHub - uber/go-torch: Stochastic flame graph profiler for Go programs GolangでFlame Graphを描く | SOTA Profiling Go Applications with Flamegraphs

【3,4日目】graqt開発日誌 ~PercentileとStddev(標準偏差)~

f:id:serinuntius:20180820080328p:plain

「べ、別に土日早起き出来なかったからブログ書けなかったわけじゃないんだからね。。。」

冗談はさておき、土日はISHOCON2やgraqtの開発に力を入れてしまい、記事を書けませんでした。

いろいろ機能が追加されたので、紹介したいと思います。

新機能

Percentileが見れるようになりました

graqtはbetter than alpを標語として、作っているのですが、alpにあるPercentileを移植しました。

P1, P50, P99とかのことです。

なんで、これが必要なのか調べていると、レスポンスタイムの平均(Avg)だけ見てしまうと、スロークライアントの結果に引っ張られる可能性があるからです。

参考 takeshiyako.blogspot.com

Nginxの$request_timeは、nginxがリクエストを受けてからレスポンスをクライアントに返しきるまでの時間なので、変に遅いクライアントが居ないとも限らない・・・。 平均値だと、極端な異常値が少しでもあったばあい、これに引きづられて数字が大きくなったりして、あまり信用できなくなったりします。 測定誤差をできるだけ減らしたいので、平均値ではなくてパーセンタイルを取ろうという考え方です。

ベンチマーカー相手だとあんまり考えなくてもいいかもですが(わざわざスロークライアントになるようなベンチマーカーって過去のISUCONでないよね?)、本番のアプリケーションでは重要ですね。

Stddev(標準偏差)が見れるようになりました

標準偏差も、かなりわかりにくい指標なのですが、こちらの記事にわかりやすく書いてありました。詳しく知りたい方はこちらの記事をお読みください。

atarimae.biz

この機能もalpについている機能で、そのままパクリましたリスペクトして実装しました。

Pathを集約して見れるようになりました

これもalpリスペクトの機能で、alpではAggregate機能として実装されています。

例えばですけど、

/diary/entry/1
/diary/entry/2
/diary/entry/3

こういう感じのリクエストがあると、集約しないとそのまま3行で表示されてしまいますが、設定ファイルに正規表現を書いておくと集約して1行でまとめて表示できます。

graqt.yaml

aggregates:
  - /diary/entry/\d+

このように書いておくと、集約され表示されるようになります。

実際の例を見たほうがわかりやすいと思うので、貼っておきます。

これが、 f:id:serinuntius:20180820074544p:plain

こうなります!!! f:id:serinuntius:20180820074624p:plain

けど、これ使うと「一部のページだけ異様に遅い!」みたいなのがあった場合わかりにくいので気をつけてください。

レスポンスボディのサイズが表示されるようになりました

今まで項目としてはちゃんと用意されていたのですが、ロガーの方で取得していなかったので、ちゃんとレスポンスボディのサイズを取得してロガーに載せるようにしました。

f:id:serinuntius:20180820075216p:plain

やったぜ!

ginというフレームワークに(一部)対応しました

ginというフレームワークは、http.Handlerを準拠して作られているわけではないので、それようのmiddlewareを作るしかありませんでした。(たぶん)

個人的には、http.Handlerに準拠しないフレームワークはgo wayじゃないと思っていて、いろいろな制約がつきまとって非常に面倒くさいことになります。

会社の先輩方が、「Go書くときは薄いフレームワークしか使わなくて良い」とおっしゃっていた理由が今回とても身にしみました。

具体的には、Ginのmiddlewareのシグネチャーにあわせて書いてあげるという感じです。めっちゃ処理が増えるとかではないですが、わざわざ1つのフレームワークのためにどんどんを作るのは非常に面倒です・・・。

func RequestIdForGin() gin.HandlerFunc {
    return func(c *gin.Context) {
        t1 := time.Now()

        id := newRequestID()

        c.Set(string(RequestIDKey), id)

        c.Next()

        RLogger.Info("",
            zap.Duration("time", time.Since(t1)),
            zap.String("request_id", id),
            zap.String("path", c.Request.RequestURI),
            zap.String("method", c.Request.Method),
            zap.Uint64("content_length", uint64(c.Writer.Size())),
        )

    }
}

https://github.com/serinuntius/graqt/blob/master/middleware.go#L38-L57

今回は、ISHOCON2でGinが利用されていたので、実装せざるおえませんでした。

一部対応と書いたのは、クエリのロガーの方で、contextに仕込んでいるはずのrequest id(uuid)が取れてないので、クエリのログは出ているのですが、紐付けることができていません 。たぶん、改善できるはずなので、いずれ改善いたします。

まとめ

やっぱり、実際のISUCON(ISHOCON2)を解きながら、graqtの開発をすると、

「うおぉぉぉぉ〜、この情報知りたいんだけどぉ!!!!」

とか

「ginに対応してないやん!!!対応せねば!!」

みたいな気持ちがわいてきて、モチベーションになりやすいです。

どんどん開発して、素晴らしいソフトウェアにするので、今後共よろしくお願いいたします。