Merge c3988cf into 25ad3aa

lib/maxwell/middleware/logger.ex

@@ -1,22 +1,33 @@
 defmodule Maxwell.Middleware.Logger do
   @moduledoc  """
   Log the request and response by Logger, default log_level is :info.
+  Setting log_level in 3 ways:
+
+  ### Log everything by log_level
+
+      middleware Maxwell.Middleware.Logger, log_level: :debug
+
+  ### Log request by specific status code.
+
+      middleware Maxwell.Middleware.Logger, log_level: [debug: 200, error: 404, info: default]
+
+  ### Log request by status code's Ranges
+
+      middleware Maxwell.Middleware.Logger, log_level: [error: [500..599, 300..399, 400], warn: 404, debug: default]
 
   ### Examples
 
         # Client.ex
         use Maxwell.Builder ~(get)a
 
-        middleware Maxwell.Middleware.Logger, log_level: :debug
-
         middleware Maxwell.Middleware.Logger, log_level: [
           info: [1..100, 200..299, 404],
           warn: 300..399,
           error: :default
         ]
 
-        def request do
-          "/test" |> url |> get!
+        def your_own_request(url) do
+          url |> new() |> get!()
         end
 
   """
@@ -36,22 +47,21 @@ defmodule Maxwell.Middleware.Logger do
   end
 
   def call(request_env, next_fn, options) do
-    start_time = :os.timestamp()
+    start = System.system_time(:milliseconds)
     new_result = next_fn.(request_env)
     case new_result do
       {:error, reason, _conn} ->
         method = request_env.method |> to_string |> String.upcase
         Logger.error("#{method} #{request_env.url}>> #{IO.ANSI.red}ERROR: #{inspect 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(options, response_conn, duration_ms)
+        stop = System.system_time(:milliseconds)
+        diff = stop - start
+        log_response_message(options, response_conn, diff)
     end
     new_result
   end
 
-  defp log_response_message(options, conn, ms) do
+  defp log_response_message(options, conn, diff) do
     %Maxwell.Conn{status: status, url: url, method: method} = conn
     level = get_level(options, status)
     color =
@@ -64,7 +74,7 @@ defmodule Maxwell.Middleware.Logger do
       end
 
     unless is_nil(level) do
-      message = "#{method} #{url} <<<#{color}#{status}(#{ms}ms)#{IO.ANSI.reset}\n#{inspect conn}"
+      message = "#{method} #{url} <<<#{color}#{status}(#{diff}ms)#{IO.ANSI.reset}\n#{inspect conn}"
       Logger.log(level, message)
     end
   end

test/maxwell/middleware/logger_test.exs

@@ -23,16 +23,16 @@ defmodule LoggerTest do
     output404 = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> %{x| status: 404} end, [{404, :debug}]) end
     output500 = capture_log fn -> Maxwell.Middleware.Logger.call(conn, fn(x) -> %{x| status: 500} end, [{500..599, :warn}, {: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
+    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\[31m\n\d+:\d+:\d+.\d+ \[error\] get http://example.com <<<\e\[31m301\(\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\[31m\n\d+:\d+:\d+.\d+ \[error\] get http://example.com <<<\e\[31m301\(\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\[36m\n\d+:\d+:\d+.\d+ \[debug\] get http://example.com <<<\e\[36m404\(\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\[36m\n\d+:\d+:\d+.\d+ \[debug\] get http://example.com <<<\e\[36m404\(\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\[33m\n\d+:\d+:\d+.\d+ \[warn\]  get http://example.com <<<\e\[33m500\(\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\[33m\n\d+:\d+:\d+.\d+ \[warn\]  get http://example.com <<<\e\[33m500\(\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\[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 outputok  =~ ~r"\e\[22m\n\d+:\d+:\d+.\d+ \[info\]  get http://example.com <<<\e\[22m200\(\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