[phoenix][elixir] Phoenixのログ周りの調査
リクエスト受付時のログ(コントローラーレイヤー)
- PhoenixでのPlugの定義(https://github.com/phoenixframework/phoenix/blob/master/lib/phoenix/controller/logger.ex)
- Plugでは.callの第2引数がlevelになっている
- PhoenixでのPlugの設定場所(https://github.com/phoenixframework/phoenix/blob/master/lib/phoenix/controller.ex#L126)
- __using__のoptsをそのままPhoenix.Controller.Loggerに渡している
- サーバアプリでレベルをdebugではなくinfoにしたい場合
- Phoenix.Controllerのusingに引数で設定する(https://github.com/ndruger/hello_phoenix/commit/276537e8386e9b2a0e27009fa449644bd59f3e2b)
リクエスト受付時・レスポンス時のログ
- Plug.Loggerの定義(https://github.com/phoenixframework/phoenix/blob/4b8b92da6f7692b0b2ed0e31c0511cd92d18afaf/lib/phoenix/controller/logger.ex)
- .callでリクエスト受付時のログを出力している
- Conn.register_before_send()にてレスポンス時のログ出力をコールバックで設定している
- request_idはPlug.RequestId(https://github.com/elixir-lang/plug/blob/master/lib/plug/request_id.ex)にてLogger.metadata()で設定。なるほど。これでどの場所のログでもrequest_idが付くわけだ。
- config.exsにて"config :logger"の"metadata: [:request_id]が指定されているので有効になる( https://github.com/phoenixframework/phoenix/blob/4b8b92da6f7692b0b2ed0e31c0511cd92d18afaf/installer/templates/new/config/config.exs#L24 )
- デフォルトだとdev環境ではformatが指定されておりrequest_idが付かなくなっている(https://github.com/phoenixframework/phoenix/blob/4b8b92da6f7692b0b2ed0e31c0511cd92d18afaf/installer/templates/new/config/dev.exs#L28)ので、dev環境でもrequest_idを出したい場合はdev.exsを修正する。
- PhoenixでのPlug.Loggerの設定場所(https://github.com/phoenixframework/phoenix/blob/4b8b92da6f7692b0b2ed0e31c0511cd92d18afaf/installer/templates/new/lib/application_name/endpoint.ex)
- ログだけあってPlugの中でも大分前の方に設定されている
サーバアプリでcontrollerのアクション後にログを出したい場合
- 最初"plug action"を指定してその後にPlugの設定を記述してみたが、これは古い方法で、少なくともPhoenix0.14.0では間違っている(https://github.com/ndruger/hello_phoenix/commit/c6d289c411fabafcc97d1c58afae8349348e5a64)
- Phoenix 0.14.0 だと"[deprecated] plug :action is no longer required in controllers, please remove it from HelloPhoenix.BooksController"の警告が出る。最新masterだとその警告が消えてる(https://github.com/phoenixframework/phoenix/commit/e6b792be398db71f4ffcddb94f66fde01bc62f3e)が、このPRのコメント( https://github.com/phoenixframework/phoenix/issues/888#issuecomment-127768123 )のコメントによるとPlug.Conn.register_before_send/2 を使うの正しい模様。
- register_after_actionが一時追加されたが消されている(https://github.com/phoenixframework/phoenix/commit/d85f59cc42157fffeb0b041a07ceed591ac0df30)
- Phoenix 0.14.0 だと"[deprecated] plug :action is no longer required in controllers, please remove it from HelloPhoenix.BooksController"の警告が出る。最新masterだとその警告が消えてる(https://github.com/phoenixframework/phoenix/commit/e6b792be398db71f4ffcddb94f66fde01bc62f3e)が、このPRのコメント( https://github.com/phoenixframework/phoenix/issues/888#issuecomment-127768123 )のコメントによるとPlug.Conn.register_before_send/2 を使うの正しい模様。
- register_before_sendで修正してみた( https://github.com/ndruger/hello_phoenix/commit/7b48d973415885141addf249b0f6584a68359d32 )
- コードの見た目がひどすぎる。Plugとタイミングを独立させて、Plug使う側が明示的にタイミングを指定したい場合もあると思うので、Plugをregister_before_sendに登録するマクロを作ってそれを利用するのが綺麗な形なのだろうか?
サーバアプリでuser_idの出力をmetadataを追加したい場合
- 下記のようにログイン時にput_sessionして、plugでget_sessionしてLogger.metadata()に設定して、default.conf.exsでloggerのmetadataにも入れればいい