pixiv insideは移転しました! ≫ https://inside.pixiv.blog/

gate第二弾 〜流れるログが見たい〜

こちらはピクシブ株式会社Advent Calendar 12/14分の記事です。


インフラチームの @catatsuy です.

f:id:catatsuy:20141114192037p:plain

以前の記事で gate を紹介しました.

gateを使って手軽に認証を導入する - pixiv inside

今回の記事は gate 第二弾です.

以前にも紹介しましたがピクシブ社内ではデプロイツールとして edvakf/pploy を採用しています. しかし pploy ではデプロイ時に実行されるログをブラウザからリアルタイムに見られるようになっていましたが,実際のインフラ構成では以下のように pploy のレスポンスはプロキシされていきます.

pploy --> gate --> Nginx --> User

このように pploy からユーザーに辿り着くまでに Nginx と gate の 2 つのプロキシサーバーを通る必要があります.その際にどこかでログがバッファリングされていてログがストリーミングされないという問題が発生しました.

なんとしてもログをストリーミングにして流れるところが見たい,その気持ちで @edvakf さんを中心に今回色々調べました.

今回の記事の前半は以下の記事と重複している部分もあるので是非参考にしてください.

PlayでOSコマンドの出力をリアルタイムに返したい - Qiita

行バッファリングではなくフルバッファリングになる

pploy ではコマンドを exec していますが,libc の実装では出力先がターミナルでない場合は行バッファリングではなく4096バイトのフルバッファリングになるという問題がありました.

shell - Turn off buffering in pipe - Unix & Linux Stack Exchange

これを解消するにはいくつか方法があるようですが,script コマンドで実行するようにすることにしました.script コマンドは Mac(BSD) と Linux でコマンドの使い方が異なるので pploy では OS 毎に実行されるコマンドを変えています.

script コマンドを使って command というコマンドを実行する場合は以下の様に実行できます.

# Linux
script -c command -q /dev/null
# BSD
script -q /dev/null command

こうすることでコマンドの実行結果は行バッファリングされるだけになります.これで pploy 単体ではログがストリーミングされるようになりました.

Transfer-Encoding: chunked

当初は HTTP1.1 で定義された Transfer-Encoding: chunked を使用してログをストリーミングにしようとしていました.

pploy + Nginx の構成ではログがストリーミングされたので gate 側でバッファリングされていないか調査をしました.そこで net/http/httputilReverseProxy では FlushInterval を指定ができ,そこで指定をしなければバッファリングは Go 側に完全に任されてしまっていつバッファリングを解放してくれるかわからないことがわかりました.そこで以下のプルリクのようにバッファリングを解放するタイミングを指定するパッチを当てました.

Set FlushInterval when initializing httputil.ReverseProxy by edvakf · Pull Request #12 · typester/gate

これにより Nginx と gate を通る検証環境ではうまく動きましたが,実環境に反映したところストリーミングされませんでした.当初は実環境で動かない原因を究明することができず,Transfer-Encoding: chunked を使う方法を一旦断念しました.

WebSocket

gate は WebSocket に対応しているので、 WebSocket を使って pploy のログを流すように変更しました.

しかし Nginx はそのままでは WebSocket をプロキシしてくれません.なので以下の記事を参考に設定しました.

NGINX as a WebSockets Proxy - NGINX

実際に行った設定は以下の様な設定です.

map $http_upgrade $connection_upgrade {
    default upgrade;
    '' close;
}

server {
    listen 443 ssl;
    server_name gate.example.com;

    # sslの設定
    include include-confs/ssl.conf;

    location / {
        satisfy any;

        # officeのIP
        allow ***.***.***.***;
        deny all;

        auth_basic "Please enter user / password";
        auth_basic_user_file htpasswd;

        proxy_read_timeout     300;
        proxy_connect_timeout  300;
        proxy_set_header       Upgrade            $http_upgrade;
        proxy_set_header       Connection         "Upgrade";
        proxy_http_version 1.1;
        proxy_pass http://127.0.0.1:9999;
    }

    error_log /var/log/nginx/gate.example.com_error.log error;
    access_log /var/log/nginx/gate.example.com_access.log;
}

これで Nginx は WebSocket を通してくれます.これで終わり…と思いきや,今度は gate 側に問題が見つかりました.gate では WebSocket の実装にバグがあり,ソケットのファイルディスクリプタを close してくれないのでデプロイが終了してログが止まってもコネクションが切れないという問題がありました.通常はあまり WebSocket の接続を切ることはないので問題になりませんが、 pploy ではこれが問題になるため、原因を突き止めて gate に以下のプルリクのような変更を加えて対応しました.

Fix bug where WebSocket's close wasn't sent to client by edvakf · Pull Request #14 · typester/gate

これによりデプロイのログがストリーミングされるようになり,デプロイ時のログを気持ちよく流すことに成功しました.

Transfer-Encoding: chunked 再び

WebSocket でログを流すことには成功しましたが,今回の用途では一方的にログを流したいだけなので WebSocket の双方向性は必要ありません.そこでなぜ chunked で成功しなかったのかもう一度調べることにしました.

本番環境と検証環境の差異は HTTPS 通信であるかないかの違いしか見当たらなかったので検証環境でオレオレ証明書を作成して検証してみました.

Apache/SSL自己証明書の作成とmod sslの設定 - maruko2 Note.

そして HTTPS で通信させたところ実環境で確認されたログがストリーミングされない現象を再現することができました.そこで下のページを参考に proxy_buffering off; の設定を Nginx に追加しました.

node.js - nginx 1.4.4 + https + chunk encoding - Stack Overflow

これで HTTPS 通信を使っていてもログがストリーミングされるようになりました.SSL で Transfer-Encoding: chunked をきちんとプロキシする Nginx の設定は以下のようになります.

server {
    listen 443 ssl;
    server_name gate.example.com;

    # sslの設定
    include include-confs/ssl.conf;

    location / {
        satisfy any;

        # officeのIP
        allow ***.***.***.***;
        deny all;

        auth_basic "Please enter user / password";
        auth_basic_user_file htpasswd;

        proxy_http_version 1.1;
        proxy_buffering off;
        proxy_pass http://127.0.0.1:9999;
    }

    error_log /var/log/nginx/gate.example.com_error.log error;
    access_log /var/log/nginx/gate.example.com_access.log;
}

これで edvakf/testploy をデプロイしてみるとこのようにログがストリーミングされます.

https://embed.gyazo.com/a3a9e05cc004657b0b801fe84fca41b2.gif

まとめ

デプロイ時のログをストリーミングしたい!という強い思いでやっと pploy で gate と Nginx を通してもうまくログをストリーミングさせることができました.今回は 2 つのプロキシサーバーを通さなければならない上に HTTPS 通信をする必要があるという特殊な環境でしたが,参考になれば幸いです.

明日は @consomme72 さんが Android の話をしてくれると思うのでご期待ください!!