|
1 | | -defmodule LoggerJSON.Plug do |
2 | | - @moduledoc """ |
3 | | - A telemetry handler that logs request information in JSON format. |
| 1 | +if Code.ensure_loaded?(Plug) do |
| 2 | + defmodule LoggerJSON.Plug do |
| 3 | + @moduledoc """ |
| 4 | + A telemetry handler that logs request information in JSON format. |
4 | 5 |
|
5 | | - This module is not recommended to be used in production, as it can be |
6 | | - costly to log every single database query. |
7 | | - """ |
8 | | - require Logger |
| 6 | + This module is not recommended to be used in production, as it can be |
| 7 | + costly to log every single database query. |
| 8 | + """ |
| 9 | + require Logger |
9 | 10 |
|
10 | | - @doc """ |
11 | | - Attaches the telemetry handler to the given event. |
| 11 | + @doc """ |
| 12 | + Attaches the telemetry handler to the given event. |
12 | 13 |
|
13 | | - ### Available options |
| 14 | + ### Available options |
14 | 15 |
|
15 | | - * `:level` - log level which is used to log requests. Defaults to `:info`. |
| 16 | + * `:level` - log level which is used to log requests. Defaults to `:info`. |
16 | 17 |
|
17 | | - ### Dynamic log level |
| 18 | + ### Dynamic log level |
18 | 19 |
|
19 | | - In some cases you may wish to set the log level dynamically |
20 | | - on a per-query basis. To do so, set the `:level` option to |
21 | | - a tuple, `{Mod, Fun, Args}`. The query and map of time measures |
22 | | - will be prepended to the provided list of arguments. |
| 20 | + In some cases you may wish to set the log level dynamically |
| 21 | + on a per-query basis. To do so, set the `:level` option to |
| 22 | + a tuple, `{Mod, Fun, Args}`. The query and map of time measures |
| 23 | + will be prepended to the provided list of arguments. |
23 | 24 |
|
24 | | - When invoked, your function must return a |
25 | | - [`Logger.level()`](`t:Logger.level()/0`) or `false` to |
26 | | - disable logging for the request. |
| 25 | + When invoked, your function must return a |
| 26 | + [`Logger.level()`](`t:Logger.level()/0`) or `false` to |
| 27 | + disable logging for the request. |
27 | 28 |
|
28 | | - ### Examples |
| 29 | + ### Examples |
29 | 30 |
|
30 | | - Attaching the telemetry handler to the `MyApp.Repo` events with the `:info` log level: |
| 31 | + Attaching the telemetry handler to the `MyApp.Repo` events with the `:info` log level: |
31 | 32 |
|
32 | | - # in the endpoint |
33 | | - plug Plug.Telemetry, event_prefix: [:myapp, :plug] |
| 33 | + # in the endpoint |
| 34 | + plug Plug.Telemetry, event_prefix: [:myapp, :plug] |
34 | 35 |
|
35 | | - # in your application.ex |
36 | | - LoggerJSON.Plug.attach("logger-json-requests", [:myapp, :plug, :stop], :info) |
| 36 | + # in your application.ex |
| 37 | + LoggerJSON.Plug.attach("logger-json-requests", [:myapp, :plug, :stop], :info) |
37 | 38 |
|
38 | | - To make plug broadcast those events see [`Plug.Telemetry`](https://hexdocs.pm/plug/Plug.Telemetry.html) documentation. |
| 39 | + To make plug broadcast those events see [`Plug.Telemetry`](https://hexdocs.pm/plug/Plug.Telemetry.html) documentation. |
39 | 40 |
|
40 | | - You can also attach to the `[:phoenix, :endpoint, :stop]` event to log request latency from Phoenix endpoints: |
| 41 | + You can also attach to the `[:phoenix, :endpoint, :stop]` event to log request latency from Phoenix endpoints: |
41 | 42 |
|
42 | | - LoggerJSON.Plug.attach("logger-json-phoenix-requests", [:phoenix, :endpoint, :stop], :info) |
43 | | - """ |
44 | | - def attach(name, event, level) do |
45 | | - :telemetry.attach(name, event, &__MODULE__.telemetry_logging_handler/4, level) |
46 | | - end |
| 43 | + LoggerJSON.Plug.attach("logger-json-phoenix-requests", [:phoenix, :endpoint, :stop], :info) |
| 44 | + """ |
| 45 | + def attach(name, event, level) do |
| 46 | + :telemetry.attach(name, event, &__MODULE__.telemetry_logging_handler/4, level) |
| 47 | + end |
47 | 48 |
|
48 | | - @doc """ |
49 | | - A telemetry handler that logs requests in a structured format. |
50 | | - """ |
51 | | - @spec telemetry_logging_handler( |
52 | | - event_name :: [atom()], |
53 | | - query_time :: %{duration: non_neg_integer()}, |
54 | | - metadata :: %{conn: Plug.Conn.t()}, |
55 | | - level :: Logger.level() | {module :: module(), function :: atom(), arguments :: [term()]} | false |
56 | | - ) :: :ok |
57 | | - def telemetry_logging_handler(_event_name, %{duration: duration}, %{conn: conn}, level) do |
58 | | - duration = System.convert_time_unit(duration, :native, :microsecond) |
59 | | - |
60 | | - if level = level(level, conn) do |
61 | | - Logger.log( |
62 | | - level, |
63 | | - fn -> |
64 | | - %{ |
65 | | - method: method, |
66 | | - request_path: request_path, |
67 | | - state: state, |
68 | | - status: status |
69 | | - } = conn |
70 | | - |
71 | | - [ |
72 | | - method, |
73 | | - ?\s, |
74 | | - request_path, |
75 | | - ?\s, |
76 | | - "[", |
77 | | - connection_type(state), |
78 | | - ?\s, |
79 | | - status(status), |
80 | | - "in ", |
81 | | - duration(duration), |
82 | | - "]" |
83 | | - ] |
84 | | - end, |
85 | | - conn: conn, |
86 | | - duration_μs: duration |
87 | | - ) |
| 49 | + @doc """ |
| 50 | + A telemetry handler that logs requests in a structured format. |
| 51 | + """ |
| 52 | + @spec telemetry_logging_handler( |
| 53 | + event_name :: [atom()], |
| 54 | + query_time :: %{duration: non_neg_integer()}, |
| 55 | + metadata :: %{conn: Plug.Conn.t()}, |
| 56 | + level :: Logger.level() | {module :: module(), function :: atom(), arguments :: [term()]} | false |
| 57 | + ) :: :ok |
| 58 | + def telemetry_logging_handler(_event_name, %{duration: duration}, %{conn: conn}, level) do |
| 59 | + duration = System.convert_time_unit(duration, :native, :microsecond) |
| 60 | + |
| 61 | + if level = level(level, conn) do |
| 62 | + Logger.log( |
| 63 | + level, |
| 64 | + fn -> |
| 65 | + %{ |
| 66 | + method: method, |
| 67 | + request_path: request_path, |
| 68 | + state: state, |
| 69 | + status: status |
| 70 | + } = conn |
| 71 | + |
| 72 | + [ |
| 73 | + method, |
| 74 | + ?\s, |
| 75 | + request_path, |
| 76 | + ?\s, |
| 77 | + "[", |
| 78 | + connection_type(state), |
| 79 | + ?\s, |
| 80 | + status(status), |
| 81 | + "in ", |
| 82 | + duration(duration), |
| 83 | + "]" |
| 84 | + ] |
| 85 | + end, |
| 86 | + conn: conn, |
| 87 | + duration_μs: duration |
| 88 | + ) |
| 89 | + end |
88 | 90 | end |
89 | | - end |
90 | 91 |
|
91 | | - defp connection_type(:set_chunked), do: "Chunked" |
92 | | - defp connection_type(_), do: "Sent" |
| 92 | + defp connection_type(:set_chunked), do: "Chunked" |
| 93 | + defp connection_type(_), do: "Sent" |
93 | 94 |
|
94 | | - defp status(nil), do: "" |
95 | | - defp status(status), do: [status |> Plug.Conn.Status.code() |> Integer.to_string(), ?\s] |
| 95 | + defp status(nil), do: "" |
| 96 | + defp status(status), do: [status |> Plug.Conn.Status.code() |> Integer.to_string(), ?\s] |
96 | 97 |
|
97 | | - def duration(duration) do |
98 | | - if duration > 1000 do |
99 | | - [duration |> div(1000) |> Integer.to_string(), "ms"] |
100 | | - else |
101 | | - [Integer.to_string(duration), "µs"] |
| 98 | + def duration(duration) do |
| 99 | + if duration > 1000 do |
| 100 | + [duration |> div(1000) |> Integer.to_string(), "ms"] |
| 101 | + else |
| 102 | + [Integer.to_string(duration), "µs"] |
| 103 | + end |
102 | 104 | end |
103 | | - end |
104 | 105 |
|
105 | | - defp level({m, f, a}, conn), do: apply(m, f, [conn | a]) |
106 | | - defp level(level, _conn) when is_atom(level), do: level |
| 106 | + defp level({m, f, a}, conn), do: apply(m, f, [conn | a]) |
| 107 | + defp level(level, _conn) when is_atom(level), do: level |
| 108 | + end |
107 | 109 | end |
0 commit comments