From 81dd6790a6df5fe3b0156cbed8ba4e170cf9ff65 Mon Sep 17 00:00:00 2001 From: falood Date: Sun, 12 Feb 2017 18:38:21 -0800 Subject: [PATCH] update log level setting, close #44 --- lib/maxwell/middleware/logger.ex | 100 +++++++++++++++++++----- test/maxwell/middleware/logger_test.exs | 76 +++++++++++++++--- 2 files changed, 144 insertions(+), 32 deletions(-) diff --git a/lib/maxwell/middleware/logger.ex b/lib/maxwell/middleware/logger.ex index ea62759..b4c6975 100644 --- a/lib/maxwell/middleware/logger.ex +++ b/lib/maxwell/middleware/logger.ex @@ -16,47 +16,105 @@ defmodule Maxwell.Middleware.Logger do use Maxwell.Middleware require Logger + @levels [:info, :debug, :warn, :error] + def init(opts) do - check_opts(opts) - Keyword.get(opts, :log_level, :info) + case Keyword.pop(opts, :log_level) do + {_, [_|_]} -> + raise ArgumentError, "Logger Middleware Options doesn't accept wrong_option (:log_level)" + {nil, _} -> [default: :info] + {options, _} when is_list(options) -> parse_opts(options) + {level, _} -> parse_opts([{level, :default}]) + end end - def call(request_env, next_fn, level) do + def call(request_env, next_fn, options) do start_time = :os.timestamp() new_result = next_fn.(request_env) method = request_env.method |> to_string |> String.upcase case new_result do {:error, reason, _conn} -> error_reason = to_string(:io_lib.format("~p", [reason])) - Logger.log(level, "#{method} #{request_env.url}>> #{IO.ANSI.red}ERROR: " <> error_reason) + Logger.error("#{method} #{request_env.url}>> #{IO.ANSI.red}ERROR: " <> error_reason) %Maxwell.Conn{} = response_conn -> finish_time = :os.timestamp() duration = :timer.now_diff(finish_time, start_time) duration_ms = :io_lib.format("~.3f", [duration / 10_000]) - log_response_message(response_conn, duration_ms, level) + log_response_message(options, response_conn, duration_ms) end new_result end - defp log_response_message(conn, ms, level) do + defp log_response_message(options, conn, ms) do %Maxwell.Conn{status: status, url: url, method: method} = conn - color = case status do - _ when status < 300 -> IO.ANSI.green - _ when status < 400 -> IO.ANSI.yellow - _ -> IO.ANSI.red - end - message = "#{method} #{url} <<<#{color}#{status}(#{ms}ms)#{IO.ANSI.reset}\n#{inspect conn}" - Logger.log(level, message) - end - - defp check_opts(opts) do - for {key, value} <- opts do - case key do - :log_level -> - unless is_atom(value), do: raise(ArgumentError, "Logger Middleware :log_level only accepts atom"); - _ -> raise(ArgumentError, "Logger Middleware Options doesn't accept #{key} (:log_level)") + level = get_level(options, status) + color = + case level do + nil -> nil + :debug -> IO.ANSI.cyan + :info -> IO.ANSI.normal + :warn -> IO.ANSI.yellow + :error -> IO.ANSI.red end + + unless is_nil(color) do + message = "#{method} #{url} <<<#{color}#{status}(#{ms}ms)#{IO.ANSI.reset}\n#{inspect conn}" + Logger.log(level, message) end end + defp get_level([], _code), do: nil + defp get_level([{code, level} | _], code), do: level + defp get_level([{from..to, level} | _], code) + when code in from..to, do: level + defp get_level([{:default, level} | _], _code), do: level + defp get_level([_ | t], code), do: get_level(t, code) + + + defp parse_opts(options), do: parse_opts(options, [], nil) + defp parse_opts([], result, nil), do: Enum.reverse(result) + defp parse_opts([], result, default), do: Enum.reverse([{:default, default} | result]) + + defp parse_opts([{level, :default} | rest], result, nil) do + check_level(level) + parse_opts(rest, result, level) + end + + defp parse_opts([{level, :default} | rest], result, level) do + Logger.warn "Logger Middleware: default level defined multiple times." + parse_opts(rest, result, level) + end + + defp parse_opts([{_level, :default} | _rest], _result, _default) do + raise ArgumentError, "Logger Middleware: default level conflict." + end + + defp parse_opts([{level, codes} | rest], result, default) when is_list(codes) do + check_level(level) + result = Enum.reduce(codes, result, fn code, acc -> + check_code(code) + [{code, level} | acc] + end) + parse_opts(rest, result, default) + end + + defp parse_opts([{level, code} | rest], result, default) do + check_level(level) + check_code(code) + parse_opts(rest, [{code, level} | result], default) + end + + + defp check_level(level) when level in @levels, do: :ok + defp check_level(_level) do + raise ArgumentError, "Logger Middleware: level only accepts #{inspect @levels}." + end + + + defp check_code(code) when is_integer(code), do: :ok + defp check_code(_from.._to), do: :ok + defp check_code(_any) do + raise ArgumentError, "Logger Middleware: status code only accepts Integer and Range." + end + end diff --git a/test/maxwell/middleware/logger_test.exs b/test/maxwell/middleware/logger_test.exs index fecb613..f15ba71 100644 --- a/test/maxwell/middleware/logger_test.exs +++ b/test/maxwell/middleware/logger_test.exs @@ -17,21 +17,24 @@ defmodule LoggerTest do test "Logger Call" do conn = %Conn{method: :get, url: "http://example.com", status: 200} outputstr = capture_log fn -> - Maxwell.Middleware.Logger.call(conn,fn(x) ->{:error, "bad request", %{x| status: 400}} end, :info) end - output301 = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> %{x| status: 301} end, :info) end - output404 = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> %{x| status: 404} end, :info) end - output500 = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> %{x| status: 500} end, :info) end - outputok = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> x end, :info) end - assert outputstr =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\] GET http://example.com>> \e\[31mERROR: <<\"bad request\">>\n\e\[0m" + Maxwell.Middleware.Logger.call(conn,fn(x) ->{:error, "bad request", %{x| status: 400}} end, [default: :info]) + end + output301 = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> %{x| status: 301} end, [default: :info]) end + output404 = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> %{x| status: 404} end, [{404, :info}]) end + output500 = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> %{x| status: 500} end, [{500..599, :info}, {:default, :error}]) end + outputok = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> x end, [default: :info]) end + nooutput = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> x end, [{400.599, :info}]) end + assert outputstr =~ ~r"\e\[31m\n\d+:\d+:\d+.\d+ \[error\] GET http://example.com>> \e\[31mERROR: <<\"bad request\">>\n\e\[0m" - assert output301 =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\] get http://example.com <<<\e\[33m301\(\d+.\d+ms\)\e\[0m\n%Maxwell.Conn\{method: :get, opts: \[\], path: \"\", query_string: \%\{\}, req_body: nil, req_headers: \%\{\}, resp_body: \"\", resp_headers: \%\{\}, state: :unsent, status: 301, url: \"http://example.com\"\}\n\e\[0m" + assert output301 =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\] get http://example.com <<<\e\[22m301\(\d+.\d+ms\)\e\[0m\n%Maxwell.Conn\{method: :get, opts: \[\], path: \"\", query_string: \%\{\}, req_body: nil, req_headers: \%\{\}, resp_body: \"\", resp_headers: \%\{\}, state: :unsent, status: 301, url: \"http://example.com\"\}\n\e\[0m" - assert output404 =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\] get http://example.com <<<\e\[31m404\(\d+.\d+ms\)\e\[0m\n%Maxwell.Conn\{method: :get, opts: \[\], path: \"\", query_string: \%\{\}, req_body: nil, req_headers: \%\{\}, resp_body: \"\", resp_headers: \%\{\}, state: :unsent, status: 404, url: \"http://example.com\"\}\n\e\[0m" + assert output404 =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\] get http://example.com <<<\e\[22m404\(\d+.\d+ms\)\e\[0m\n%Maxwell.Conn\{method: :get, opts: \[\], path: \"\", query_string: \%\{\}, req_body: nil, req_headers: \%\{\}, resp_body: \"\", resp_headers: \%\{\}, state: :unsent, status: 404, url: \"http://example.com\"\}\n\e\[0m" - assert output500 =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\] get http://example.com <<<\e\[31m500\(\d+.\d+ms\)\e\[0m\n%Maxwell.Conn\{method: :get, opts: \[\], path: \"\", query_string: \%\{\}, req_body: nil, req_headers: \%\{\}, resp_body: \"\", resp_headers: \%\{\}, state: :unsent, status: 500, url: \"http://example.com\"\}\n\e\[0m" + assert output500 =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\] get http://example.com <<<\e\[22m500\(\d+.\d+ms\)\e\[0m\n%Maxwell.Conn\{method: :get, opts: \[\], path: \"\", query_string: \%\{\}, req_body: nil, req_headers: \%\{\}, resp_body: \"\", resp_headers: \%\{\}, state: :unsent, status: 500, url: \"http://example.com\"\}\n\e\[0m" - assert outputok =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\] get http://example.com <<<\e\[32m200\(\d+.\d+ms\)\e\[0m\n%Maxwell.Conn\{method: :get, opts: \[\], path: \"\", query_string: \%\{\}, req_body: nil, req_headers: \%\{\}, resp_body: \"\", resp_headers: \%\{\}, state: :unsent, status: 200, url: \"http://example.com\"}\n\e\[0m" + assert outputok =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\] get http://example.com <<<\e\[22m200\(\d+.\d+ms\)\e\[0m\n%Maxwell.Conn\{method: :get, opts: \[\], path: \"\", query_string: \%\{\}, req_body: nil, req_headers: \%\{\}, resp_body: \"\", resp_headers: \%\{\}, state: :unsent, status: 200, url: \"http://example.com\"}\n\e\[0m" + assert nooutput == "" end test "Change Middleware Logger's log_level" do @@ -45,7 +48,7 @@ defmodule LoggerTest do end test "Middleware Logger with invalid log_level" do - assert_raise ArgumentError, "Logger Middleware :log_level only accepts atom", fn -> + assert_raise ArgumentError, ~r/Logger Middleware: level only accepts/, fn -> defmodule TAtom1 do use Maxwell.Builder, [:get, :post] middleware Maxwell.Middleware.Logger, [log_level: 1234] @@ -64,4 +67,55 @@ defmodule LoggerTest do end end + test "Complex log_level for Middleware Logger 1" do + assert_raise RuntimeError, "ok", fn -> + defmodule TAtom3 do + use Maxwell.Builder, [:get, :post] + middleware Maxwell.Middleware.Logger, log_level: [ + error: 400..599 + ] + end + raise "ok" + end + end + + test "Complex log_level for Middleware Logger 2" do + assert_raise RuntimeError, "ok", fn -> + defmodule TAtom4 do + use Maxwell.Builder, [:get, :post] + middleware Maxwell.Middleware.Logger, log_level: [ + info: [1..99, 100, 200..299], + warn: 300..399, + error: :default + ] + end + raise "ok" + end + end + + test "Complex log_level with wrong status code" do + assert_raise ArgumentError, "Logger Middleware: status code only accepts Integer and Range.", fn -> + defmodule TStatusCode do + use Maxwell.Builder, [:get, :post] + middleware Maxwell.Middleware.Logger, log_level: [ + info: ["100"], + ] + end + raise "ok" + end + end + + test "Complex log_level with duplicated default level" do + assert_raise ArgumentError, "Logger Middleware: default level conflict.", fn -> + defmodule TDefaultLevel do + use Maxwell.Builder, [:get, :post] + middleware Maxwell.Middleware.Logger, log_level: [ + info: :default, + error: :default, + ] + end + raise "ok" + end + end + end