Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -5,3 +5,4 @@ erl_crash.dump
*.ez
.local.plt
doc/
.elixir_ls
70 changes: 42 additions & 28 deletions lib/plug/logger_json.ex
Original file line number Diff line number Diff line change
Expand Up @@ -80,6 +80,7 @@ defmodule Plug.LoggerJSON do
def call(conn, level_or_opts) when is_atom(level_or_opts) do
call(conn, level: level_or_opts)
end

def call(conn, opts) do
level = Keyword.get(opts, :log, :info)
start = :os.timestamp()
Expand All @@ -95,50 +96,53 @@ defmodule Plug.LoggerJSON do
def log(conn, :error, start, opts), do: log(conn, :info, start, opts)
def log(conn, :info, start, opts), do: log_message(conn, :info, start, opts)
def log(conn, :warn, start, opts), do: log(conn, :debug, start, opts)

def log(conn, :debug, start, opts) do
log_message(conn, :info, start, Keyword.put_new(opts, :include_debug_logging, true))
end

@spec log_error(atom(), map(), list()) :: atom()
def log_error(kind, reason, stacktrace) do
_ = Logger.log :error, fn ->
%{
"log_type" => "error",
"message" => Exception.format(kind, reason, stacktrace),
"request_id" => Logger.metadata[:request_id],
}
|> Poison.encode!
end
_ =
Logger.log(:error, fn ->
%{
"log_type" => "error",
"message" => Exception.format(kind, reason, stacktrace),
"request_id" => Logger.metadata()[:request_id]
}
|> Jason.encode!()
end)
end

@spec log_message(Plug.Conn.t(), atom(), time(), opts) :: atom()
defp log_message(conn, level, start, opts) do
Logger.log level, fn ->
Logger.log(level, fn ->
conn
|> basic_logging(start)
|> Map.merge(debug_logging(conn, opts))
|> Map.merge(phoenix_attributes(conn))
|> Map.merge(extra_attributes(conn, opts))
|> Poison.encode!
end
|> Jason.encode!()
end)
end

defp basic_logging(conn, start) do
stop = :os.timestamp()
duration = :timer.now_diff(stop, start)
req_id = Logger.metadata[:request_id]
stop = :os.timestamp()
duration = :timer.now_diff(stop, start)
req_id = Logger.metadata()[:request_id]
req_headers = format_map_list(conn.req_headers)

log_json = %{
"api_version" => Map.get(req_headers, "accept", "N/A"),
"date_time" => iso8601(:calendar.now_to_datetime(:os.timestamp)),
"duration" => Float.round(duration / 1000, 3),
"log_type" => "http",
"method" => conn.method,
"path" => conn.request_path,
"request_id" => req_id,
"status" => conn.status
"api_version" => Map.get(req_headers, "accept", "N/A"),
"date_time" => iso8601(:calendar.now_to_datetime(:os.timestamp())),
"duration" => Float.round(duration / 1000, 3),
"log_type" => "http",
"method" => conn.method,
"path" => conn.request_path,
"request_id" => req_id,
"status" => conn.status
}

Map.drop(log_json, Application.get_env(:plug_logger_json, :suppressed_keys, []))
end

Expand All @@ -156,6 +160,7 @@ defmodule Plug.LoggerJSON do
|> case do
"N/A" ->
Map.get(headers, "user-agent", "N/A")

accept_value ->
accept_value
end
Expand All @@ -166,11 +171,13 @@ defmodule Plug.LoggerJSON do
case Keyword.get(opts, :include_debug_logging) do
true ->
req_headers = format_map_list(conn.req_headers)

%{
"client_ip" => format_ip(Map.get(req_headers, "x-forwarded-for", "N/A")),
"client_version" => client_version(req_headers),
"params" => format_map_list(conn.params),
"client_ip" => format_ip(Map.get(req_headers, "x-forwarded-for", "N/A")),
"client_version" => client_version(req_headers),
"params" => format_map_list(conn.params)
}

_ ->
%{}
end
Expand All @@ -179,6 +186,7 @@ defmodule Plug.LoggerJSON do
@spec filter_values({String.t(), String.t()}) :: map()
defp filter_values({k, v}) do
filtered_keys = Application.get_env(:plug_logger_json, :filtered_keys, [])

if Enum.member?(filtered_keys, k) do
%{k => "[FILTERED]"}
else
Expand All @@ -190,6 +198,7 @@ defmodule Plug.LoggerJSON do
defp format_ip("N/A") do
"N/A"
end

defp format_ip(x_forwarded_for) do
hd(String.split(x_forwarded_for, ", "))
end
Expand All @@ -199,7 +208,7 @@ defmodule Plug.LoggerJSON do
list
|> Enum.take(20)
|> Enum.map(&filter_values/1)
|> Enum.reduce(%{}, &(Map.merge(&2, &1)))
|> Enum.reduce(%{}, &Map.merge(&2, &1))
end

defp format_value(value) when is_binary(value) do
Expand All @@ -211,14 +220,19 @@ defmodule Plug.LoggerJSON do
end

defp iso8601({{year, month, day}, {hour, minute, second}}) do
zero_pad(year, 4) <> "-" <> zero_pad(month, 2) <> "-" <> zero_pad(day, 2) <> "T" <>
zero_pad(hour, 2) <> ":" <> zero_pad(minute, 2) <> ":" <> zero_pad(second, 2) <> "Z"
zero_pad(year, 4) <>
"-" <>
zero_pad(month, 2) <>
"-" <>
zero_pad(day, 2) <>
"T" <> zero_pad(hour, 2) <> ":" <> zero_pad(minute, 2) <> ":" <> zero_pad(second, 2) <> "Z"
end

@spec phoenix_attributes(map()) :: map()
defp phoenix_attributes(%{private: %{phoenix_controller: controller, phoenix_action: action}}) do
%{"handler" => "#{controller}##{action}"}
end

defp phoenix_attributes(_) do
%{"handler" => "N/A"}
end
Expand Down
27 changes: 16 additions & 11 deletions mix.exs
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@ defmodule PlugLoggerJson.Mixfile do
def project do
[
app: :plug_logger_json,
build_embedded: Mix.env == :prod,
build_embedded: Mix.env() == :prod,
deps: deps(),
dialyzer: [
plt_add_deps: true
Expand All @@ -15,11 +15,16 @@ defmodule PlugLoggerJson.Mixfile do
homepage_url: "https://github.com/bleacherreport/plug_logger_json",
name: "Plug Logger JSON",
package: package(),
preferred_cli_env: ["coveralls": :test, "coveralls.detail": :test, "coveralls.post": :test, "coveralls.html": :test],
preferred_cli_env: [
coveralls: :test,
"coveralls.detail": :test,
"coveralls.post": :test,
"coveralls.html": :test
],
source_url: "https://github.com/bleacherreport/plug_logger_json",
start_permanent: Mix.env == :prod,
start_permanent: Mix.env() == :prod,
test_coverage: [tool: ExCoveralls],
version: "0.6.0",
version: "0.6.0"
]
end

Expand All @@ -29,13 +34,13 @@ defmodule PlugLoggerJson.Mixfile do

defp deps do
[
{:credo, "~> 0.8.10", only: [:dev]},
{:dialyxir, "~> 0.5.1", only: [:dev]},
{:earmark, "~> 1.2.4", only: [:dev]},
{:ex_doc, "~> 0.18.0", only: [:dev]},
{:excoveralls, "~> 0.8.0", only: [:test]},
{:plug, "~> 1.0"},
{:poison, "~> 1.5 or ~> 2.0 or ~> 3.0"}
{:credo, "~> 0.8.10", only: [:dev]},
{:dialyxir, "~> 0.5.1", only: [:dev]},
{:earmark, "~> 1.2.4", only: [:dev]},
{:ex_doc, "~> 0.18.0", only: [:dev]},
{:excoveralls, "~> 0.8.0", only: [:test]},
{:plug, "~> 1.0"},
{:jason, "~> 1.1"}
]
end

Expand Down
7 changes: 5 additions & 2 deletions mix.lock
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
%{"bunt": {:hex, :bunt, "0.2.0", "951c6e801e8b1d2cbe58ebbd3e616a869061ddadcc4863d0a2182541acae9a38", [:mix], [], "hexpm"},
%{
"bunt": {:hex, :bunt, "0.2.0", "951c6e801e8b1d2cbe58ebbd3e616a869061ddadcc4863d0a2182541acae9a38", [:mix], [], "hexpm"},
"certifi": {:hex, :certifi, "2.0.0", "a0c0e475107135f76b8c1d5bc7efb33cd3815cb3cf3dea7aefdd174dabead064", [:rebar3], [], "hexpm"},
"credo": {:hex, :credo, "0.8.10", "261862bb7363247762e1063713bb85df2bbd84af8d8610d1272cd9c1943bba63", [:mix], [{:bunt, "~> 0.2.0", [hex: :bunt, repo: "hexpm", optional: false]}], "hexpm"},
"dialyxir": {:hex, :dialyxir, "0.5.1", "b331b091720fd93e878137add264bac4f644e1ddae07a70bf7062c7862c4b952", [:mix], [], "hexpm"},
Expand All @@ -8,11 +9,13 @@
"exjsx": {:hex, :exjsx, "4.0.0", "60548841e0212df401e38e63c0078ec57b33e7ea49b032c796ccad8cde794b5c", [:mix], [{:jsx, "~> 2.8.0", [hex: :jsx, repo: "hexpm", optional: false]}], "hexpm"},
"hackney": {:hex, :hackney, "1.10.1", "c38d0ca52ea80254936a32c45bb7eb414e7a96a521b4ce76d00a69753b157f21", [:rebar3], [{:certifi, "2.0.0", [hex: :certifi, repo: "hexpm", optional: false]}, {:idna, "5.1.0", [hex: :idna, repo: "hexpm", optional: false]}, {:metrics, "1.0.1", [hex: :metrics, repo: "hexpm", optional: false]}, {:mimerl, "1.0.2", [hex: :mimerl, repo: "hexpm", optional: false]}, {:ssl_verify_fun, "1.1.1", [hex: :ssl_verify_fun, repo: "hexpm", optional: false]}], "hexpm"},
"idna": {:hex, :idna, "5.1.0", "d72b4effeb324ad5da3cab1767cb16b17939004e789d8c0ad5b70f3cea20c89a", [:rebar3], [{:unicode_util_compat, "0.3.1", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm"},
"jason": {:hex, :jason, "1.1.2", "b03dedea67a99223a2eaf9f1264ce37154564de899fd3d8b9a21b1a6fd64afe7", [:mix], [{:decimal, "~> 1.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm"},
"jsx": {:hex, :jsx, "2.8.3", "a05252d381885240744d955fbe3cf810504eb2567164824e19303ea59eef62cf", [:mix, :rebar3], [], "hexpm"},
"metrics": {:hex, :metrics, "1.0.1", "25f094dea2cda98213cecc3aeff09e940299d950904393b2a29d191c346a8486", [:rebar3], [], "hexpm"},
"mime": {:hex, :mime, "1.2.0", "78adaa84832b3680de06f88f0997e3ead3b451a440d183d688085be2d709b534", [:mix], [], "hexpm"},
"mimerl": {:hex, :mimerl, "1.0.2", "993f9b0e084083405ed8252b99460c4f0563e41729ab42d9074fd5e52439be88", [:rebar3], [], "hexpm"},
"plug": {:hex, :plug, "1.4.3", "236d77ce7bf3e3a2668dc0d32a9b6f1f9b1f05361019946aae49874904be4aed", [:mix], [{:cowboy, "~> 1.0.1 or ~> 1.1", [hex: :cowboy, repo: "hexpm", optional: true]}, {:mime, "~> 1.0", [hex: :mime, repo: "hexpm", optional: false]}], "hexpm"},
"poison": {:hex, :poison, "3.1.0", "d9eb636610e096f86f25d9a46f35a9facac35609a7591b3be3326e99a0484665", [:mix], [], "hexpm"},
"ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.1", "28a4d65b7f59893bc2c7de786dec1e1555bd742d336043fe644ae956c3497fbe", [:make, :rebar], [], "hexpm"},
"unicode_util_compat": {:hex, :unicode_util_compat, "0.3.1", "a1f612a7b512638634a603c8f401892afbf99b8ce93a45041f8aaca99cadb85e", [:rebar3], [], "hexpm"}}
"unicode_util_compat": {:hex, :unicode_util_compat, "0.3.1", "a1f612a7b512638634a603c8f401892afbf99b8ce93a45041f8aaca99cadb85e", [:rebar3], [], "hexpm"},
}
28 changes: 14 additions & 14 deletions test/plug/logger_json_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,7 @@ defmodule Plug.LoggerJSONTest do
plug Plug.Parsers,
parsers: [:urlencoded, :multipart, :json],
pass: ["*/*"],
json_decoder: Poison
json_decoder: Jason
plug :passthrough

defp passthrough(conn, _) do
Expand All @@ -39,7 +39,7 @@ defmodule Plug.LoggerJSONTest do
plug Plug.Parsers,
parsers: [:urlencoded, :multipart, :json],
pass: ["*/*"],
json_decoder: Poison
json_decoder: Jason
plug :passthrough

defp passthrough(conn, _) do
Expand All @@ -54,7 +54,7 @@ defmodule Plug.LoggerJSONTest do
plug Plug.Parsers,
parsers: [:urlencoded, :multipart, :json],
pass: ["*/*"],
json_decoder: Poison
json_decoder: Jason
plug :passthrough

defp passthrough(conn, _) do
Expand Down Expand Up @@ -91,7 +91,7 @@ defmodule Plug.LoggerJSONTest do
map =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert map["api_version"] == "N/A"
assert map["client_ip"] == "N/A"
Expand All @@ -115,7 +115,7 @@ defmodule Plug.LoggerJSONTest do
map =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert map["api_version"] == "N/A"
assert map["client_ip"] == "N/A"
Expand All @@ -140,7 +140,7 @@ defmodule Plug.LoggerJSONTest do
map =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert map["client_ip"] == nil
assert map["client_version"] == nil
Expand All @@ -156,7 +156,7 @@ defmodule Plug.LoggerJSONTest do
map =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert map["client_ip"] == "209.49.75.165"
assert map["client_version"] == "ios/1.5.4"
Expand All @@ -172,7 +172,7 @@ defmodule Plug.LoggerJSONTest do
map =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert map["api_version"] == "N/A"
assert map["client_ip"] == "N/A"
Expand All @@ -195,7 +195,7 @@ defmodule Plug.LoggerJSONTest do
"type" => "emoji",
"user_id" => "a2e684ee-2e5f-4e4d-879a-bb253908eef3"
}}
|> Poison.encode!
|> Jason.encode!

{_conn, message} =
conn(:post, "/", json)
Expand All @@ -205,7 +205,7 @@ defmodule Plug.LoggerJSONTest do
map =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert map["api_version"] == "N/A"
assert map["client_ip"] == "N/A"
Expand Down Expand Up @@ -237,7 +237,7 @@ defmodule Plug.LoggerJSONTest do
map =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert map["api_version"] == "N/A"
assert map["client_ip"] == "209.49.75.165"
Expand All @@ -260,7 +260,7 @@ defmodule Plug.LoggerJSONTest do
map =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert map["client_version"] == "ios/1.5.4"
end
Expand All @@ -274,7 +274,7 @@ defmodule Plug.LoggerJSONTest do
map =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert map["user_id"] == "123"
assert map["other_id"] == 456
Expand Down Expand Up @@ -309,7 +309,7 @@ defmodule Plug.LoggerJSONTest do
error_log =
message
|> remove_colors
|> Poison.decode!
|> Jason.decode!

assert error_log["log_type"] == "error"
assert error_log["message"] == "** (RuntimeError) ERROR\n web/controllers/reaction_controller.ex:53: Plug.LoggerJSONTest.MyDebugPlug.index/2\n web/controllers/reaction_controller.ex:1: Plug.LoggerJSONTest.MyDebugPlug.action/2\n web/controllers/reaction_controller.ex:1: Plug.LoggerJSONTest.MyDebugPlug.phoenix_controller_pipeline/2\n lib/reactions/endpoint.ex:1: Plug.LoggerJSONTest.MyDebugPlug.instrument/4\n lib/phoenix/router.ex:261: Plug.LoggerJSONTest.MyDebugPlug.dispatch/2\n web/router.ex:1: Plug.LoggerJSONTest.MyDebugPlug.do_call/2\n lib/plug/error_handler.ex:64: Plug.LoggerJSONTest.MyDebugPlug.call/2\n lib/reactions/endpoint.ex:1: Plug.LoggerJSONTest.MyDebugPlug.phoenix_pipeline/1\n lib/reactions/endpoint.ex:1: Plug.LoggerJSONTest.MyDebugPlug.call/2\n (plug) lib/plug/adapters/cowboy/handler.ex:15: Plug.Adapters.Cowboy.Handler.upgrade/4\n src/cowboy_protocol.erl:442: :cowboy_protocol.execute/4\n"
Expand Down