mmag

ハマったことメモなど

Ectoのカスタムロガー

github.com

3.0-rc.1がもっぱら話題のEctoですが、ロガーを追加する方法をたまたま見つけたので書いておきます。Ecto.Repouseするときにloggersっていうオプションを渡します。

defmodule MyApp.Repo do
  use Ecto.Repo,
    otp_app: :my_app,
    loggers: [
      {Ecto.LogEntry, :log, []},
      {MyApp.CustomLogger, :log, []}
    ]
end

loggersのデフォルト値は[{Ecto.LogEntry, :log, []}]なので、今の挙動を変えたくないときはこんな風に追加するとよさそ。試しにこんなlog/1で動かしてみると、

defmodule MyApp.CustomLogger do
  def log(entry) do
    IO.inspect entry, structs: false
  end
end
[debug] QUERY OK source="nippoes" db=8.3ms
SELECT n0."id", n0."date", n0."content", n0."user_id", n0."inserted_at", n0."updated_at" FROM "nippoes" AS n0 WHERE (n0."date" = $1) ORDER BY n0."inserted_at" DESC [{2018, 10, 17}]
%{
  __struct__: Ecto.LogEntry,
  ansi_color: :cyan,
  caller_pid: #PID<0.599.0>,
  connection_pid: nil,
  decode_time: 11000,
  params: [{2018, 10, 17}],
  query: "SELECT n0.\"id\", n0.\"date\", n0.\"content\", n0.\"user_id\", n0.\"inserted_at\", n0.\"updated_at\" FROM \"nippoes\" AS n0 WHERE (n0.\"date\" = $1) ORDER BY n0.\"inserted_at\" DESC",
  query_time: 8328995,
  queue_time: 68000,
  result: {:ok,
   %{
     __struct__: Postgrex.Result,
     columns: ["id", "date", "content", "user_id", "inserted_at", "updated_at"],
     command: :select,
     connection_id: 15165,
     num_rows: 0,
     rows: []
   }},
  source: "nippoes"
}

こんなログが出ました。引数はEcto.LogEntryの構造体ですね。query_timeナノ秒)を見て、時間かかってたらLogger.warnしたりとか良いんじゃないでしょうか。本番環境だとNewRelicだなんだありますけど、開発環境とかテストとかで。