たごもりすメモ

コードとかその他の話とか。

RubyKaigi 2018 で仙台に行ってきた&しゃべってきた

今年もRubyKaigiでしたねー。実によいカンファレンスでした。

rubykaigi.org

f:id:tagomoris:20180531102321j:plainf:id:tagomoris:20180602180507j:plain

仙台は東京からも新幹線で1.5〜2時間で着けるというアクセスの良さ、加えてちょうど新緑の時期で街中も郊外も美しいし、日本酒も酒に合う魚もおいしい場所だし、地方開催のカンファレンスは本当にすばらしいなって話をずっとしてた。そういうところに隔離されてずっとソフトウェアの話ができるの、本当に良いと思う。

しゃべってきた

今年は去年のRubyKaigiから間が短いこともあってトークの応募どうしようかなと思ってたんだけど、最近Asakusa.rbで @joker1007 さんとよく盛り上がる技術ネタがあって、それを共同で応募してみたら通ったから話してきた。(jokerさんのエントリ)

Hijacking Ruby Syntax in Ruby - RubyKaigi 2018

スライドはこちら。

内容はBindingとかTracePointとかRefinementsとかmethod hookとかを使いまくってやりたい放題やる、みたいな話だけど、実際の狙いは「有用なアイデアRubyの機能だけを使って実現してみる」に近い。ちゃんと実装しようと思うとMRIにCでパッチを書くことになるんだけど、まず実装してみて有用性を確かめる(あるいはRuby的にこれで良いかと見てみる)、というステップは重要だと思っていて、このためにやれることを全部やったのだ、と思ってもらえれば嬉しい。

実のところトーク後にMatz含めたRubyコミッタの人々とも話してて defer みたいなのはあってもいいかもねえ、という話になった*1ので、Proof of Concept は重要だと思うし、それをRubyでやるためには今回のトークに含まれる技術要素は学んでおいて損は無いと思う。デバッグ大変だけどね!

また今回たまたま時間がなかったのでこういう内容だったが、今までproduction systemの話ばっかりしてた自分としてはRubyKaigiで非常によく行われる言語機能や言語実装に深く入っていく類のトークをしたことがなく、ちょっとコンプレックスに思っていたところだった。今回は思いっきりRubyの機能や面白ライブラリの話をしまくって、そういう部分で実績解除できて嬉しかったなと思ってる。こういうネタを普段からいろいろ議論できる Asakusa.rb はホンマええところやで。みんなもおいで。*2

f:id:tagomoris:20180531134945j:plain

会場の聴衆の入りはめちゃくちゃよかった。今回サブ会場もだいぶ席数があったのにあんなにぎっしりになるとは。楽しめてもらえてたら良かったなあ。
@joker1007 さん、いっしょにできて楽しかったです! ありがとう!!

ところでRubyKaigiに向かう共同登壇者の息の合いっぷりをごらんください。


参加してきた

今年のRubyKaigiもJITと型の話がアツかったですね! あとGuildの動くブランチ公開はまだですか!?!?

f:id:tagomoris:20180531212002j:plainf:id:tagomoris:20180531212745j:plainf:id:tagomoris:20180531215721j:plain

RubyにOptionalな型を入れる件については自分の意見はここに書いてあるようにコードにrespond_to?(:name)が通る集合を書く、みたいなやつですね。これがRubyのduck typingといちばん相性がいいと思うんだけどなあ。外部に型宣言ファイルを持つっていっても、クラスベースの型 + ジェネリクス的なやつで次の2行を共に安全にするのは無理じゃない?

obj = [1, "two", 3, "four"]
obj.select{|v| v.respond_to?(:upcase) }.map(&:upcase).join
obj.reject{|v| v.respond_to?(:upcase) }.sum

まあこれはともかく、JITとかはMRIの実装もどんどん進んでるし、他の実装の詳細が紹介されるトークからMRIが取り込めそうなのもあれこれあったりで議論が楽しいし、実にすばらしい。他のトークも聞いたものはみんなそれぞれの書いたコードについてしゃべりまくってて超面白かった。

f:id:tagomoris:20180601215016j:plainf:id:tagomoris:20180531223549j:plainf:id:tagomoris:20180601220104j:plain

RubyKaigiは明確に「自分が書いたコードの話をするトークがacceptされる」カンファレンスなので、こうやって超面白い話ばっかりになるのはすばらしい。
んだけど、次のRubyKaigiでまたトークをしなければまた話のネタになるコードを書かないといけないわけで、いやー、どうしよっかなーと今から思いますね。

f:id:tagomoris:20180531213102j:plainf:id:tagomoris:20180601214322j:plainf:id:tagomoris:20180601231026j:plain

あと3日目に恒例の(?)サイン会があったけど、技術評論社WEB+DB PRESS総集編、記事を書いたことがある人が集められて巨大サインパイプラインみたいになってた。なかなか愉快な体験でした。ちゃんと買ってサインをもらいに来てくれる人がいて売り上げに貢献したぞ!!!


Partyなど

f:id:tagomoris:20180602194812j:plain

今回はTreasure Dataが After Party のスポンサーをやらせてもらったので、そのあたりはちょっとあれこれやったり。人が大勢来てくれて、でもぎゅうぎゅう詰めという感じでもなくて、ちょうどよかったかなと思います。ちょっと食べ物が少なかったのはみなさんにその後に仙台のおいしいものを食べてほしかったから!!!!*3


なんか面白ネタがあるならAfter Partyでどうすか、みたいに雑に振ってみたら出てきたのがこれで、まじやばかった。みんな超楽しんでたRubyKaigiの最終トークでしたね。正確にはその後にnobuのライブコミットがあったけど、なんかもう本人が酔っ払ってて何言ってるのかもよくわからず、超カオスであれはあれで面白かったw *4

f:id:tagomoris:20180601231605j:plainf:id:tagomoris:20180602220516j:plainf:id:tagomoris:20180602222041j:plain

Pre Partyから1日目、2日目は自分もあれこれのパーティーにお世話になっていた。あれやこれやの人と話したり、そこから別の店に流れたり。特に仙台行く前に会った @maciejmensfeld ‏と何度も話してポーランドの Kraków Ruby meetup について聞いたりとか。いいなあポーランド、行ってみたい。Tech Talk やりに行きたい。

f:id:tagomoris:20180602220908j:plainf:id:tagomoris:20180603020205j:plainf:id:tagomoris:20180602232927j:plain

After Partyのあとの川は……しばらく経ってから見にいってみたらだいぶ人数少なくなってて、その後に日が変わるあたり? であっさり解散していた。仙台の川は平和だった。

まとめ

超楽しかった! 上に書き忘れてたけどWi-Fiまじ快適で @sora_h 先生ありがとう! オーガーナイザーのみなさん(特に @a_matsuda さん)ありがとう!

f:id:tagomoris:20180602232536j:plainf:id:tagomoris:20180602222527j:plainf:id:tagomoris:20180603020345j:plain

来年の福岡も楽しみですね! またしても、日本酒も魚もうまい街だぞ!!!!

*1:いっぽう defer というキーワードをぶちこむのは難易度が高いのでどうしようかねえ、といういつもの話にもなった。きびしい。うーん……。

*2:いっぽう便利な人に「モリスさんともあろう人がproductionで使えない話なんかをするなんて!」とか煽られた、ぜったいにゆるさない

*3:いま考えた

*4:該当のcommitはこれかな? ruby-trunk-changesでも「うーん謎だ。」などと評されており大変面白い。

Nginx 1.13 の http_mirror_module を試す

みなさんにも、さまざまな過去の経緯からくる微妙挙動を満載した外部ユーザ向けのHTTPサーバをリプレイスしたりするとき、実際にガツンとやっちまう前にちょっとリクエストを分岐して挙動と性能を確認したい、と思うことがあると思います。考えるだけでつらい気分になってくるやつ。でもやったほうが100倍マシなやつ。
どうしよっかなとちょっと考えたところ、少し前にこんな話があったのを思い出すはずですね*1

asnokaze.hatenablog.com

とはいえヨッシャ使うぞといきなりぶちこむこともできないので、まずいくつか試してみることにする。

準備

前提としては以下のように、元のアプリケーションと同じにホストにリバースプロキシが立っており、そこのnginxで http_mirror_module を使う、という想定*2。ミラー先はどこか適当なアプリケーションサーバ(あるいはロードバランサ)で、元アプリとまったく同じ機能を提供する、はず、ということにする。このNginxでstatic fileを扱うなどの処理については今回は考えない(すべてのリクエストがproxyされる)。

--->[nginx (port 8080)]--->[app P (port 8081)]
       |
  [http_mirror_module]
       |
       +------------------>[app Q (port 8082)]

ここでは簡単のため、全プロセスを同一ホストで起動、それぞれ port 8080, 8081, 8082 で実行する。

Nginxのdownloadページからおもむろに現在の mainline version であるところの 1.13.10 をダウンロードして適当なディレクトリに展開、あとは普通にビルドする。http_mirror_moduleはなんとデフォルトで有効。

$ ./configure --prefix=/usr/local/nginx-1.13.10
$ make
$ sudo make install
$ sudo chown -R tagomoris /usr/local/nginx-1.13.10 # 自分のユーザ名で

Nginxの設定としてはできるだけ簡単にして、最初は以下のように。proxy先の状況もちゃんとわかるよう、アクセスログには $request_time と $upstream_response_time の両方を記録しておく。

worker_processes  1;
error_log  logs/error.log;
events {
    worker_connections  1024;
}


http {
    include       mime.types;
    default_type  application/octet-stream;

    log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                      '$status $body_bytes_sent "$http_referer" '
                      '"$http_user_agent" "$http_x_forwarded_for" '
                      '$request_time $upstream_response_time';
    access_log  logs/access.log  main;

    sendfile        on;
    keepalive_timeout  65;

    server {
        listen       8080;
        server_name  localhost;

        location /a {
            proxy_pass http://127.0.0.1:8081/a; # P
            mirror /mirror;
        }
        location /b {
            proxy_pass http://127.0.0.1:8081/b; # P
            mirror /mirror;
        }
        location /mirror {
            internal;
            proxy_pass http://127.0.0.1:8082; # Q
        }
    }
}

なお /mirror はリクエストの複製にのみ使う internal redirect 用のlocationなので、外部からアクセスされないようinternalディレクティブを有効にしておく。
設定内容を確認してnginxを起動。

$ /usr/local/nginx-1.13.10/sbin/nginx -t
nginx: the configuration file /usr/local/nginx-1.13.10/conf/nginx.conf syntax is ok
nginx: configuration file /usr/local/nginx-1.13.10/conf/nginx.conf test is successful
$ /usr/local/nginx-1.13.10/sbin/nginx

プロキシ先のアプリケーションは以下のようなものをrubyで適当に書く。環境変数で設定をいじれるようにしとく。

# app.rb
require 'sinatra'

port = ENV.fetch("PORT", "8080").to_i
sleep_time = ENV.fetch("SLEEP_INTERVAL", "0").to_i

configure do
  set :port, port
end

get '/a' do
  p(time: Time.now, here: "a")
  sleep sleep_time
  "ok #{sleep_time}"
end

post '/b' do
  p(time: Time.now, here: "b", body: request.body.read)
  sleep sleep_time
  "ok #{sleep_time}"
end

gem i sinatra してあれば ruby app.rb で起動できる。これを以下のようにふたつ起動する。

$ PORT=8081 SLEEP_INTERVAL=0 ruby app.rb # P
[2018-04-02 18:13:24] INFO  WEBrick 1.4.2
[2018-04-02 18:13:24] INFO  ruby 2.5.1 (2018-03-29) [x86_64-darwin17]
== Sinatra (v2.0.1) has taken the stage on 8081 for development with backup from WEBrick
[2018-04-02 18:13:24] INFO  WEBrick::HTTPServer#start: pid=19491 port=8081

$ PORT=8082 SLEEP_INTERVAL=0 ruby app.rb # Q
(省略)

準備完了。

普通にmirror proxyする

まず設定は上記の設定に入っていたこの部分から。/a および /b に来たリクエストを 8081 のupstream に流すが、同時にmirrorして 8082 にも流す。

        location /a {
            proxy_pass http://127.0.0.1:8081/a;
            mirror /mirror;
        }
        location /b {
            proxy_pass http://127.0.0.1:8081/b;
            mirror /mirror;
        }
        location /mirror {
            internal;
            proxy_pass http://127.0.0.1:8082;
        }

これでリクエストを流してみる。

$ curl -v http://localhost:8080/a
*   Trying ::1...
* connect to ::1 port 8080 failed: Connection refused
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /a HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.45.0
> Accept: */*
> 
< HTTP/1.1 200 OK 
< Server: nginx/1.13.10
< Date: Mon, 02 Apr 2018 09:14:13 GMT
< Content-Type: text/html;charset=utf-8
< Content-Length: 4
< Connection: keep-alive
< X-Xss-Protection: 1; mode=block
< X-Content-Type-Options: nosniff
< X-Frame-Options: SAMEORIGIN
< 
* Connection #0 to host localhost left intact
ok 0

当たり前だけど普通に返ってくる。アクセスログを見てみると、やっぱり普通。

127.0.0.1 - - [02/Apr/2018:18:14:13 +0900] "GET /a HTTP/1.1" 200 4 "-" "curl/7.45.0" "-" 0.011 0.009

が、このときアプリケーション側のログを見てみるとおかしい。Pの側は普通にリクエストを処理しているがQは /mirror/a というパスのリクエストを受け取ってエラーを出してる。

# P
{:time=>2018-04-02 18:14:13 +0900, :here=>"a"}
127.0.0.1 - - [02/Apr/2018:18:14:13 +0900] "GET /a HTTP/1.1" 200 4 0.0067
- -> /a

# Q
127.0.0.1 - - [02/Apr/2018:18:14:13 +0900] "GET /mirror HTTP/1.1" 404 464 0.0074
- -> /mirror

このとき、error_log には何も出ていない。
これは /mirror 側でproxyするとき、pathをいじったのを元に戻さなかったからですね……ということで以下のように設定を変更。

        location /mirror {
            internal;
            proxy_pass http://127.0.0.1:8082$request_uri;
        }

なおこれはNginxのhttp_mirror_moduleのドキュメントを見ると冒頭に例でちゃんと $request_uri が指定されていて、見落としちゃダメですよ、という心遣いを感じる。
これで nginx -s reload して curl してみると、PとQで全く同じリクエストを受け取れるようになった。

# nginx access.log
127.0.0.1 - - [02/Apr/2018:18:20:36 +0900] "GET /a HTTP/1.1" 200 4 "-" "curl/7.45.0" "-" 0.003 0.003

# P
{:time=>2018-04-02 18:20:36 +0900, :here=>"a"}
127.0.0.1 - - [02/Apr/2018:18:20:36 +0900] "GET /a HTTP/1.1" 200 4 0.0008
- -> /a

# Q
{:time=>2018-04-02 18:20:36 +0900, :here=>"a"}
127.0.0.1 - - [02/Apr/2018:18:20:36 +0900] "GET /a HTTP/1.1" 200 4 0.0010
- -> /a

パスを /b にしてPOSTしてみても大丈夫。

$ curl -v -X POST --data-ascii '{"num":1}' http://localhost:8080/b
Note: Unnecessary use of -X or --request, POST is already inferred.
*   Trying ::1...
* connect to ::1 port 8080 failed: Connection refused
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> POST /b HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.45.0
> Accept: */*
> Content-Length: 9
> Content-Type: application/x-www-form-urlencoded
> 
* upload completely sent off: 9 out of 9 bytes
< HTTP/1.1 200 OK 
< Server: nginx/1.13.10
< Date: Mon, 02 Apr 2018 09:25:43 GMT
< Content-Type: text/html;charset=utf-8
< Content-Length: 4
< Connection: keep-alive
< X-Xss-Protection: 1; mode=block
< X-Content-Type-Options: nosniff
< X-Frame-Options: SAMEORIGIN
< 
* Connection #0 to host localhost left intact
ok 0

# access.log
127.0.0.1 - - [02/Apr/2018:18:25:43 +0900] "POST /b HTTP/1.1" 200 4 "-" "curl/7.45.0" "-" 0.003 0.003

# P
{:time=>2018-04-02 18:25:43 +0900, :here=>"b", :body=>"{\"num\":1}"}
127.0.0.1 - - [02/Apr/2018:18:25:43 +0900] "POST /b HTTP/1.1" 200 4 0.0006
- -> /b

# Q
{:time=>2018-04-02 18:25:43 +0900, :here=>"b", :body=>"{\"num\":1}"}
127.0.0.1 - - [02/Apr/2018:18:25:43 +0900] "POST /b HTTP/1.1" 200 4 0.0007
- -> /b

content body も両方にわたってて、あれ mirror_request_body を指定しなくてもいいの? と先述のblogエントリを読んだ印象からは受ける、が、そもそも mirror_request_body は default on だった。これはちゃんと該当ディレクティブのドキュメントを読んで、性能問題について考慮した上で必要な場合は off にしましょう。*3

mirror upstream を落としてみる

方法は簡単、単にプロセスを停止させる。この場合は Q のプロセスを止める。
で、その状態でアクセスしてみる。元々のproxy先である P は生きていることに注意。

$ curl -v http://localhost:8080/a
*   Trying ::1...
* connect to ::1 port 8080 failed: Connection refused
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /a HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.45.0
> Accept: */*
> 
< HTTP/1.1 200 OK 
< Server: nginx/1.13.10
< Date: Mon, 02 Apr 2018 09:36:32 GMT
< Content-Type: text/html;charset=utf-8
< Content-Length: 4
< Connection: keep-alive
< X-Xss-Protection: 1; mode=block
< X-Content-Type-Options: nosniff
< X-Frame-Options: SAMEORIGIN
< 
* Connection #0 to host localhost left intact
ok 0

# access.log
127.0.0.1 - - [02/Apr/2018:18:36:32 +0900] "GET /a HTTP/1.1" 200 4 "-" "curl/7.45.0" "-" 0.003 0.002

# P
{:time=>2018-04-02 18:36:32 +0900, :here=>"a"}
127.0.0.1 - - [02/Apr/2018:18:36:32 +0900] "GET /a HTTP/1.1" 200 4 0.0006
- -> /a

フツーに動いている……が、唯一、error.log に以下のようなログが出ていた。状況はわかる。

2018/04/02 18:36:32 [error] 19539#0: *19 kevent() reported that connect() failed (61: Connection refused) while connecting to upstream, client: 127.0.0.1, server: localhost, request: "GET /a HTTP/1.1", subrequest: "/mirror", upstream: "http://127.0.0.1:8082/a", host: "localhost:8080"

これをもうちょっとわかりやすくするため log_subrequest ディレクティブを有効にしてみる。これは http_core_module のディレクティブ。

    access_log  logs/access.log  main;
    log_subrequest on;

$ /usr/local/nginx-1.13.10/sbin/nginx -t
nginx: the configuration file /usr/local/nginx-1.13.10/conf/nginx.conf syntax is ok
nginx: configuration file /usr/local/nginx-1.13.10/conf/nginx.conf test is successful
$ /usr/local/nginx-1.13.10/sbin/nginx -s reload

この状態でもう一度 curl してみると、アクセスログに、処理に失敗しているリクエストがひとつ出てくる。んー、本来のリクエストとちょっと見分けがつかないな、これ。$upstream_addr でも入れますかね。*4

127.0.0.1 - - [02/Apr/2018:18:41:15 +0900] "GET /a HTTP/1.1" 502 0 "-" "curl/7.45.0" "-" 0.000 0.001
127.0.0.1 - - [02/Apr/2018:18:41:15 +0900] "GET /a HTTP/1.1" 200 4 "-" "curl/7.45.0" "-" 0.008 0.008

mirror upstream を遅くしてみる

今度は Q のプロセスを SLEEP_INTERVAL=5 で起動してみる。同じリクエストを投げてみると、同じレスポンスが即座に返ってくる。

$ curl -v http://localhost:8080/a
*   Trying ::1...
* connect to ::1 port 8080 failed: Connection refused
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /a HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.45.0
> Accept: */*
> 
< HTTP/1.1 200 OK 
< Server: nginx/1.13.10
< Date: Mon, 02 Apr 2018 09:49:07 GMT
< Content-Type: text/html;charset=utf-8
< Content-Length: 4
< Connection: keep-alive
< X-Xss-Protection: 1; mode=block
< X-Content-Type-Options: nosniff
< X-Frame-Options: SAMEORIGIN
< 
* Connection #0 to host localhost left intact
ok 0

が、アクセスログの方は、なんとQの処理が終わるまで表示されない。5秒経つと2行出力された。P側を処理したリクエストは $upstream_response_time は 0.003 なのに $request_time はQ側にひっぱられて 5.015 になっている。うーん。あとQ側の $body_bytes_sent がなんかおかしい数字。261bytesってなんだ。

# access.log
127.0.0.1 - - [02/Apr/2018:18:49:12 +0900] "GET /a HTTP/1.1" 200 261 "-" "curl/7.45.0" "-" 5.015 5.015
127.0.0.1 - - [02/Apr/2018:18:49:12 +0900] "GET /a HTTP/1.1" 200 4 "-" "curl/7.45.0" "-" 5.015 0.003

なおこの挙動とログ表示は log_subrequest off; でも変わらない。というか $upstream_response_time 0.003 なのに $request_time 5.015 な行だけが表示されてかなり不気味なことになる。実際のレスポンスはクライアントに返っているとはいえ、なかなか、どうしようかなこれ、という挙動だ。
またこの場合、PとQでは返しているレスポンスボディが異なる、が、特にそのことについて何らかのログが表示されたりはしない。コードもざっと読んだ*5が、そのような処理は書かれていないので当たり前だと言える。

primary upstream を落としてみる

逆にPが死んでるときQへのリクエストはどうなんの? というのもやってみる。Qは5秒sleepを入れたまま。

$ curl -v http://localhost:8080/a
*   Trying ::1...
* connect to ::1 port 8080 failed: Connection refused
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /a HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.45.0
> Accept: */*
> 
< HTTP/1.1 502 Bad Gateway
< Server: nginx/1.13.10
< Date: Mon, 02 Apr 2018 10:00:41 GMT
< Content-Type: text/html
< Content-Length: 174
< Connection: keep-alive
< 
<html>
<head><title>502 Bad Gateway</title></head>
<body bgcolor="white">
<center><h1>502 Bad Gateway</h1></center>
<hr><center>nginx/1.13.10</center>
</body>
</html>
* Connection #0 to host localhost left intact

# access.log
127.0.0.1 - - [02/Apr/2018:19:00:46 +0900] "GET /a HTTP/1.1" 200 332 "-" "curl/7.45.0" "-" 5.006 5.006
127.0.0.1 - - [02/Apr/2018:19:00:46 +0900] "GET /a HTTP/1.1" 502 174 "-" "curl/7.45.0" "-" 5.006 0.001

# Q
{:time=>2018-04-02 19:00:41 +0900, :here=>"a"}
127.0.0.1 - - [02/Apr/2018:19:00:46 +0900] "GET /a HTTP/1.1" 200 4 5.0043
- -> /a

やはりレスポンスは即座に 502 Bad Gateway として返ってくる。アクセスログはQ側を5秒待ってから表示される。
Q側のターミナルには普通にリクエストが投げられてきたのが表示されている。まあ自然といえば自然な挙動ではある、けど……。

雑感

とりあえずリクエストを複製する、という目的には十分使えそう。ただしmirror upstream側がトラブルで性能低下したりしたとき、ログ出力だけとはいえ通常の処理も影響を受けるというのは気をつけておいた方がよさそう。ログ上では $request_time の数字が遅くなるというのも、知らないでトラブル時のログを見ると混乱しそう。
また当然だけど worker_connections の数字を mirror upstream 側の接続についても当然消費するだろうから、この数字をきっちりに設定している場合は修正する必要があるはず。

mirror側のリクエストについてnginx上でどうログっておくかはなかなか悩ましい気がする。何も表示させないというのもひとつの手ではあるけど、レスポンスが遅くなったりしたときに $request_time の数字が突如低下することになる。これはどう考えても混乱要因になる……が、nginxのアクセスログを直接何かに使ってなければ無視できるかも。
log_subrequest on; しておくのはこれはこれで、いきなりアクセスログの行数が倍*6になる、というのはちょっときびしいような気もする。悩ましい。

mirror_request_body on; の場合に proxy_request_buffering が無効になる。これは性能面での特性の変化と、あとはドキュメントによると proxy_next_upstream が使えなくなる、という感じかな。これは機能的に容認できないという人がいるかもしれない。
性能面はまたひとつの懸案だけど、これは手元でちょっと試すというのにほとんど意味がないので割愛。しかし実際のところ、あまり心配しなくてもいいんじゃないか、というような予感はある。根本的にイベント駆動モデルをベースにしたサーバだしね。

さて、どうしよっかなー。そういえばみなさん nginx mainline version をproduction投入するの、最近は心理的にどうなんすかね。

*1:とやって思い出せるので、こういうのを書いてくれる人は本当にすばらしい

*2:ロードバランス等はそこより上流で適当に行われている

*3:自分の例では off にしたら何も検証できなくなるので、しない

*4:http_mirror_moduleのコードを読んだ限り、この区別に使えそうな変数は特に増えてはいない様子だった

*5:超短くてわかりやすい!

*6:他の用途における internal redirect などを含めればもっと?

MANABIYA.tech にいってきた&しゃべってきた

manabiya.tech

こちらのMANABIYA.techというカンファレンスでインフラ方面のセッションオーナーであるさくらインターネットの田中さんから何かどう? というお誘いがあったので、最近考えてたことを話すいい機会だと思ってひと枠しゃべってきた。あと、同トラックの前佛さん、長野(kazeburo)さんといっしょにパネルディスカッション的なやつも(モデレーターは田中さん)。

会場は以前にTDの社内イベントで使ったことがある、秋葉原の3331というところで、小学校跡地をイベントスペースに改装したところ。こういうところ、いいよなー。雰囲気があって。とはいえ元の建物がモノだけにひと部屋のサイズは小さめになってて、これはカンファレンス会場としてはちょっときびしいですね。

しゃべってきた

DockerとKubernetesの名前はおそらく多くのソフトウェアエンジニアが知っていると思うけど、Kubernetesというのは実際には分散処理基盤のコントローラに他ならなくて、これらはポッと出てきたものでもなんでもなくて、過去に分散ストレージあるいは分散処理などの流れがあって発展してきたものだと思うんですよー、みたいな話。このあたりを広めに見られていない人にとって、ざっくばらんな教養めいたものになるといいなと思って話した。
これはKubernetesがGoogleにおけるBorgのOSS版であることを考えれば明らか*1とはいえ、まあ、まあ、誰にでも公開されているものをベースに明らかな歴史として組み立てるのって大事だと思うんですよね。

またタイトルやトレンドへの名前のつけかたに困って "Modern Systems" というデカい単語を使ってしまった。話したときに最初にちょっと言ったけど、誰しもがこういうツールあるいは考え方を採用すべきだと思っているわけではなくて、とはいえそれでも「全体として進んできた/これからも進んでいく方向」みたいなところに分散処理やコンテナ化みたいなものが(今のところ)あるとは思っていて、それらをひっくるめて "Modern Systems" と言ってしまった。これはここにも注記しておく。

面白かったという反応をいくつか見聞きできたので、やれてよかった。40分の制限時間のところを5分オーバーしたのは反省しております。動画は公開されるのかな?

そのほか

パネルディスカッション的なのは、そもそも現代におけるITシステムの「インフラ」ってのはなんなんですかねー、みたいな話を多くしていた気がする。まあ、もうハードウェアをがんがんいじるお仕事も少ないですからねえ。
これは自分がそこで言ったことでもあるけど、ソフトウェアの割合が大きくなってくると、昔は会社に所属して案件ベースでしか試せなかったこと(ハードウェアをあれこれいじり倒す)よりも自分のPCででも動くものが仕事の中心になってくるので、個人でやれる範囲が広くなっている、ということだ。これは歓迎すべきだと思う。面白いこといろいろやっていきましょう。

で、お昼を挟んでふたつ話したら気力も体力も尽きて、あとはだいぶダラダラしていた。おしまい。

*1:……なんだけどこのあたりは話しはじめるとGoogle内タイムラインとOSS的タイムラインで矛盾が生じるのでしなかった、しはじめたら時間がいくらあっても足りない

Golangの defer をRubyでも使いたい

前にRubyでtry-with-resourcesが使いたいという話を書いてそのときにリリースしたgemもあるが、人類の安全に・便利にリソースを解放したいという欲求には際限がない。
try-with-resources は便利なんだけど欠点がないわけではなくて、リソースの確保と解放を一ヶ所でまとめてやらないとネストが深くなる。複数箇所に分けて書くならネストも2段になってしまう。
これはこれで整理されたコードを書く圧力になるので悪くない面もあるんだけど、とはいえもうちょっと自由にやりたい、いい方法は無いもんか、という話。

defer

ある。Golangの defer が便利そう。defer foobar って書いとくと、そのスコープを外れるときに自動的に foobar の内容が実行される。あるスコープのどこに何度書いてもいい。これは便利。

# GolangのdeferのままRubyにもってきたの図(イメージ)

def my_method
  # ...
  file = File.new("filename.txt", "w")
  defer file.close
  # ...
end

ただし上記のコードはRubyでは実現できない……syntaxに本当に手を入れない限りは。defer の後が即座に評価されてしまう。

なお try-with-resource ほしいよーって話をRubyのbugsに上げたときにライブラリとして実装できるじゃんって話があったけど、これじゃダメなんですよ。なおその例はこちら(引用)。

  Deferred.new do |d|
    r0 = Resource.new
    d.defer {r0&.close}

    r1 = Resource.new
    d.defer r1

    r2 = d.defer Resource.new
    abort unless Resource === r2

    r3 = d.defer(Resource.new) {|r|r.delete}
  end

defer 使いたいときにいちいちブロックで囲わないといけないのは、元の golang の defer と較べると圧倒的に使いにくいし、見た目も理想的ではない。deferしとけば必要なときに実行されるのがいいのに、この例だとわざわざブロックの終端という deferred な処理が発動する場所を明示してやらないといけないってことじゃないですか。コレジャナイんですよ。defの内側で必ずもう1段 Deferred.new do ... end でネストするとかイヤでしょ。

deferral

というわけでgemを作った。名前は空いてたところで deferral にした。

defer に与えるのがブロックであるところが元のgolangのと少し違うが、あとは同じような挙動になるはず。スコープを外れるとdeferredな処理が自動的に実行される。複数登録する場合は登録したのの逆順で実行される。例外が発生した場合でも実行される。

require "deferral/toplevel"
using Deferral::TopLevel

def my_method_name
  # ...
  file = File.open("my_file", "r")
  defer { file.close }

  file.write "data..."
  # ...
end

ほーら便利っしょ。あと記述がシンプル。余計なネストも作らないし。

実装

TracePoint 使って実装しているので本番環境で使い倒すのはオススメできません。またRubyの最適化処理をいろいろ台無しにする可能性があります。

あとdeferredな処理内で例外が起きたときには全部握り潰すようになってます。これはイマイチ。本当は例外が起きるならそれをそのまま上げる + 複数例外が起きた場合は suppressed な形にしてひとつの例外に他のをぶら下げる、みたいにするべきなんだけど、今はやってない。
これは何故かというと、メソッド(やブロック)内から例外が上がって強制的に脱出するとき、それがTracePointで捕捉できないことによる。メソッドから出ようとしていることはわかるが、それが通常のreturnによるものなのか例外によるものなのかの区別ができない + 上がってきた例外オブジェクトもつかまえられない。
これ、どうにかなんないかなあと思っているので、そのうち bugs に報告しようと思っている。忘れなければ。

で、TracePoint使えば実装できなくはないけど、ちゃんとやるにはやっぱり言語側でサポートしてほしいなあ、と思っている。ライブラリでいいじゃんというコミッタの意見で#13923が止まっちゃったけど、いや、ここに示した通り、ライブラリじゃダメなんですよ。

ライブラリじゃ駄目なわけ (追記)

某所で指摘されたけど、ブロックが参照する変数の中身が書き変わったときもこのライブラリでは手当できません。たとえば以下のコードだと "fileB.txt" を開いた File オブジェクトが2回閉じられちゃう(いっぽう fileA.txt を開いたほうはリークする……GCの回収を待つ)。

require "deferral/toplevel"
using Deferral::TopLevel

def my_method_name
  f = File.open("fileA.txt", "w")
  defer { f.close }
  # ...

  f = File.open("fileB.txt", "w")
  defer { f.close }
  # ...

これは block で書く以上どうにもならないすね。

ライブラリじゃ駄目なわけがひとつ消滅 (追記2)

ローカル変数の中身を binding 経由で強制的に保存・再生するという悪魔的発想により上記コード例もちゃんと動く deferral v0.1.2 がリリースされました。

というわけで

興味がある人はぜひどうぞ。

Ruby誕生25周年記念イベントでしゃべった & After Partyやった

Ruby誕生から25周年を祝うイベントが開催され、そこの「Rubyの今」というセッションでデータ処理について話さないかという依頼があり、受けたので、話してきた。

Ruby25 | Top

本当にいろんな人が参加していて、みんなでわいわいとお祝いをする、という感じ。高橋会長やまつもとさんの話はあちこちのメディアに出ているから良いとして、Matzのご息女が出てきてMatzが壇上でものすごく動揺してたのがちょっと面白かった。いやあ、これこそがコンテンツだな。

他にスポンサー企業のブースがあったり、いろんなプロジェクト・コミュニティのポスター展示があったり。ポスター展示はよかったなー。あんなふうに自分のプロジェクトをアピールできるのはすごく良いと思う。見て回ったけどじつに楽しかった。

しゃべってきた

ということで、データ処理とは何を指すのか、どのようなプロダクトやサービスがあって、またその界隈を経由してどういうところでどのようにRubyが使われているかについてしゃべった。
自分が書いたコードについてではないスピーチ*1をするのはずいぶん久し振りで、また「お祝いをする」場だというのにあわせて内容もマインドセットも作ったものだから、15分弱という時間もあってだいぶ緊張した。が、まあまあうまくやれたと思う。他の人のプロダクトやプロジェクトを紹介するの、できるだけ紹介はしたいけど間違ったことを言うのは怖い、ということでけっこうキツい。今回はやれるだけのことはやった。

終わったあとで色々な人に良かったと言ってもらえたのはじつに嬉しいんだけど、ふたことめがだいたい「あんな話しかたもできたんですねえ」「酒が足りなかったのでは」などという感想で、複雑な気分というか普段のキャラクターが浸透しているというか、ううむ。

After Partyやった

Ruby25 After Party|IT勉強会ならTECH PLAY[テックプレイ]

気付いたときにはRuby25の大きいスポンサー枠は全部埋まってて、Treasure Dataとして何かできないかなーという検討の結果がこちらのイベント。180人定員のところ、最終的に170人弱は入っていたみたい。思ったよりだいぶ混雑した会場になっていたけど、やらないよりはだいぶ良かったかなという気がする。楽しんでもらえたかなあ。
技術評論社さんから最新号のWEB+DB PRESSを3冊いただいていたので、そこに著者陣のサインをいただいて会場プレゼント大会をやったりとかもしていた。わいわい。

ということで

じつにいいイベントでした。特に @_ko1 さんは本当にお疲れさまでした&ありがとうございました。
終わったあとも飲みにいってハシゴして、しかし疲れていたのか、最終的にはいっしょに飲んでいた人にちょっと迷惑をかけたかもしれぬ。君の名は。を途中まで観たところまでしか覚えてない……。おつかれさまでした。

*1:いや、幸運なことに自分が書いたコードのあるプロダクトも入ってはいるのだが

TD Tech Talk PLAZMAでBigdamについてしゃべった

今年はTreasure Dataの東京オフィスができて5年ということも兼ねてPLAZMAというイベントをやっているんだけど、その併催ということで TD Tech Talk をなんと2日間、初めて平日の午後の開催で行った。TD発のOSSが中心になるOSS Dayと、TDの内部実装についてあれこれ話すTD Internal Day。

techplay.jp
techplay.jp

あれこれ裏方もやっていたんだけど、多くの人に来ていただけたし、楽しんでもらえたような感じだった。またOSS DayとTD Internal Dayともに外部からの人にもしゃべっていただく時間を設けて*1みた。こっちも普段TDのエンジニアだけだと出てこない話がいろいろあって、本当によかったと思う。

しゃべった

ここ1年(!)やっているBigdamというプロジェクトがあるんだけど、そのプロジェクトの概要と全体の設計において重要なポイントをいくつか紹介する内容にしてみた。

これでも内容をだいぶ簡素化したんだけどそれでも30分に収まりそうにない分量になっちゃって、しょうがないからだいぶ早口でやりました。これは明らかによくないんだけど、うーん、他にどうにもならなかった。削れる場所がない。
分散システムをどういう目的で・何を達成するために設計するかという話はあまり聞いたことがない気がしたので、これはこれで新鮮な内容だったんじゃないかなという気はする。いっぽうでどうしても時間の制約から実装上のポイントとか他に検討した選択肢への言及(例えば、Kafkaを使わないの? などなど)が内容から漏れちゃうので、それは自分にとっても少し残念だった。懇親会ではけっこうそういう話をしていた。

なんにしろ疲れた、が、まあ、やっている話ができたのはよかった。

*1:これは実は昨年にあったFastly Yamagoya Meetupがすごくよかったので、これをパクらせてもらった

SENDAI IT COMMUNE #2にいってきた&しゃべってきた

こちらのイベントでしゃべらないかという依頼をいただきまして、いい機会だったのでお受けしていってきました。いやー、地方都市での登壇依頼、いつもたいへん嬉しいです。ありがとうございました。

techplay.jp

仙台市さんが仙台でITな感じを盛りあげよう、みたいな感じで行われているよう(雑な理解)で、東京でも既に一度あったようだしこの後も東京で行われるようですが、今回は仙台市内。ナイスな時に呼んでもらえました。

f:id:tagomoris:20180122132624j:plain

仙台、新幹線で早ければ東京から1時間半で着くという、とにかく圧倒的に近いのがすばらしいですね。あと酒と魚がうまい(重要)。個人的に楽しいおでかけでした。

しゃべってきた

データ分析基盤のことについて、ということだったんだけど他の方がサービス運営で使われるデータ分析の話をがっつりしてくれそうな感じだったので、自分はちょっと目先を変えてそういう基盤を作るときに必要な技術について話してた。ということはつまり、リトライと冪等性についてである。

特にTreasure Dataの主要な顧客層であるところの非IT専業企業の人が使うデータ分析基盤にはどういう特徴が必要で、それを満たすためには何について考えられていないといけないかを話したつもり。
結果としてものすごく地味な技術の話になったけど、会場で熱心に聞いてくれる人も多く、後から感想を聞くに身につまされて聞いていたという人もいたので、少なくとも全くポカーンという感じではなかったようだった、ので、それだけでも良かった。自分としても久々にこういうことをちゃんと整理して考えるいい機会になった。

聞いてきた

全体としてふたつのトピックがあって、前半がデータ分析基盤、後半はクラウドという感じ。
内容としては都内にいてもよく聞く……けど、楽天さんの話は面白かったな、具体的に発生した事件とその対処としてのデータ分析の利用の話で、やっぱり具体性のあるユースケースは常に参考になるし、面白い。しかしアホみたいにでかいHiveQLを書くよりはMapReduce書いたほうがいいと思う。w

会場が仙台市内の繁華街にあるライブハウスで、普段しゃべるよりもだいぶ高い位置にステージがあるのがちょっと面白い感じだった。面白会場での勉強会、良いと思います。

いってきた

仙台なー、最高だよな、酒も魚がうまい(重要なことなのでもう一度)。せっかくなので前日入り、翌日帰宅ということで2泊していろいろ食べてきた。

f:id:tagomoris:20180122133225j:plain
f:id:tagomoris:20180122133557j:plain

なにしろ5月末にはRubyKaigiが仙台でもあるということで、その下見も兼ねt

f:id:tagomoris:20180122134232j:plain

仕事! お仕事の一環で行ったんですよ!!!!!!

よいイベントでした。