Page MenuHomePhorge
Files F113474

No OneTemporary
Actions

Size
18 KB
Referenced Files
None
Subscribers
None

View Options

diff --git a/config/config.exs b/config/config.exs
index cb22775..5bd9fed 100644
--- a/config/config.exs
+++ b/config/config.exs
@@ -1,23 +1,21 @@
-# This file is responsible for configuring your application
-# and its dependencies with the aid of the Mix.Config module.
use Mix.Config
config :tesla, adapter: Tesla.Adapter.Httpc
-config :logger, :console,
- level: :debug,
- format: "$date $time [$level] $metadata$message\n"
-
if Mix.env == :test do
+ config :logger, :console,
+ level: :debug,
+ format: "$date $time [$level] $metadata$message\n"
+
config :httparrot,
http_port: 5080,
https_port: 5443,
ssl: true,
unix_socket: false
config :sasl,
errlog_type: :error,
sasl_error_logger: false
config :tesla, MockClient, adapter: Tesla.Mock
end
diff --git a/lib/tesla/middleware/logger.ex b/lib/tesla/middleware/logger.ex
index d98ea44..bcf8c16 100644
--- a/lib/tesla/middleware/logger.ex
+++ b/lib/tesla/middleware/logger.ex
@@ -1,220 +1,188 @@
+defmodule Tesla.Middleware.Logger.Formatter do
+ @moduledoc false
+
+ # Heavily based on Elixir's Logger.Formatter
+ # https://github.com/elixir-lang/elixir/blob/v1.6.4/lib/logger/lib/logger/formatter.ex
+
+ @default_format "$method $url -> $status ($time ms)"
+ @keys ~w(method url status time)
+
+ @type format :: [atom | binary]
+
+ @spec compile(binary | nil) :: format
+ def compile(nil), do: compile(@default_format)
+
+ def compile(binary) do
+ ~r/(?<h>)\$[a-z]+(?<t>)/
+ |> Regex.split(binary, on: [:h, :t], trim: true)
+ |> Enum.map(&compile_key/1)
+ end
+
+ defp compile_key("$" <> key) when key in @keys, do: String.to_atom(key)
+ defp compile_key("$" <> key), do: raise(ArgumentError, "$#{key} is an invalid format pattern.")
+ defp compile_key(part), do: part
+
+ @spec format(Tesla.Env.t(), Tesla.Env.result(), integer, format) :: IO.chardata()
+ def format(request, response, time, format) do
+ Enum.map(format, &output(&1, request, response, time))
+ end
+
+ defp output(:method, env, _, _), do: env.method |> to_string() |> String.upcase()
+ defp output(:url, env, _, _), do: env.url
+ defp output(:status, _, {:ok, env}, _), do: to_string(env.status)
+ defp output(:status, _, {:error, reason}, _), do: "error: " <> inspect(reason)
+ defp output(:time, _, _, time), do: :io_lib.format("~.3f", [time / 1000])
+ defp output(binary, _, _, _), do: binary
+end
+
defmodule Tesla.Middleware.Logger do
@behaviour Tesla.Middleware
@moduledoc """
- Log requests as single line.
+ Log requests using Elixir's Logger.
- Logs request method, url, response status and time taken in milliseconds.
+ With the default settings it logs request method, url, response status and time taken in milliseconds.
### Example usage
```
defmodule MyClient do
use Tesla
plug Tesla.Middleware.Logger
end
```
- ### Custom log levels
- ```
- defmodule MyClient do
- use Tesla
+ ### Options
+ - `:log_level` - custom function for calculating log level (see below)
- plug Tesla.Middleware.Logger, log_level: &my_log_level/1
- end
- def my_log_level(env) do
- case env.status do
- 404 -> :info
- _ -> Tesla.Middleware.Logger.default_log_level(env)
- end
- end
- ```
+ ## Custom log format
+
+ The default log format is `"$method $url -> $status ($time ms)"`
+ which shows in logs like:
- ### Logger output
```
- 2017-09-30 13:39:06.663 [info] GET http://example.com -> 200 (736.988 ms)
+ 2018-03-25 18:32:40.397 [info] GET https://bitebot.io -> 200 (88.074 ms)
```
- See `Tesla.Middleware.DebugLogger` to log request/response body
- """
+ Because log format is processed during compile time it needs to be set in config:
- @type log_level :: :info | :warn | :error
+ ```
+ config :tesla, Tesla.Middleware.Logger, format: "$method $url ====> $status / time=$time"
+ ```
- require Logger
+ ## Custom log levels
- def call(env, next, opts) do
- log_level = Keyword.get(opts, :log_level, &default_log_level/1)
- {time, result} = :timer.tc(Tesla, :run, [env, next])
- _ = log(env, result, time, log_level)
- result
- end
+ By default, the following log levels will be used:
+ - `:error` - for errors, 5xx and 4xx responses
+ - `:warn` - for 3xx responses
+ - `:info` - for 2xx responses
- defp log(env, {:error, reason}, _time, _log_level) do
- Logger.error("#{normalize_method(env)} #{env.url} -> #{inspect(reason)}")
- end
+ You can custimize this setting by providing your own `log_level/1` function:
- defp log(_env, {:ok, env}, time, log_level) do
- ms = :io_lib.format("~.3f", [time / 1000])
- message = "#{normalize_method(env)} #{env.url} -> #{env.status} (#{ms} ms)"
+ ```
+ defmodule MyClient do
+ use Tesla
- case log_level.(env) do
- :info -> Logger.info(message)
- :warn -> Logger.warn(message)
- :error -> Logger.error(message)
- end
- end
+ plug Tesla.Middleware.Logger, log_level: &my_log_level/1
- @spec default_log_level(Tesla.Env.t()) :: log_level
- def default_log_level(env) do
- cond do
- env.status >= 400 -> :error
- env.status >= 300 -> :warn
- true -> :info
+ def my_log_level(env) do
+ case env.status do
+ 404 -> :info
+ _ -> :default
+ end
end
end
+ ```
- defp normalize_method(env) do
- env.method |> to_string() |> String.upcase()
- end
-end
+ ### Logger Debug output
-defmodule Tesla.Middleware.DebugLogger do
- @behaviour Tesla.Middleware
+ When the Elixir Logger log level is set to `:debug`
+ Tesla Logger will show full request & response.
+ """
- @moduledoc """
- Log full reqeust/response content
+ alias Tesla.Middleware.Logger.Formatter
- ### Example usage
- ```
- defmodule MyClient do
- use Tesla
-
- plug Tesla.Middleware.DebugLogger
- end
- ```
+ @config Application.get_env(:tesla, __MODULE__, [])
+ @format Formatter.compile(@config[:format])
- ### Logger output
- ```
- 2017-09-30 13:41:56.281 [debug] > POST https://httpbin.org/post
- 2017-09-30 13:41:56.281 [debug]
- 2017-09-30 13:41:56.281 [debug] > a=3
- 2017-09-30 13:41:56.432 [debug]
- 2017-09-30 13:41:56.432 [debug] < HTTP/1.1 200
- 2017-09-30 13:41:56.432 [debug] < access-control-allow-credentials: true
- 2017-09-30 13:41:56.432 [debug] < access-control-allow-origin: *
- 2017-09-30 13:41:56.432 [debug] < connection: keep-alive
- 2017-09-30 13:41:56.432 [debug] < content-length: 280
- 2017-09-30 13:41:56.432 [debug] < content-type: application/json
- 2017-09-30 13:41:56.432 [debug] < date: Sat, 30 Sep 2017 11:41:55 GMT
- 2017-09-30 13:41:56.432 [debug] < server: meinheld/0.6.1
- 2017-09-30 13:41:56.432 [debug] < via: 1.1 vegur
- 2017-09-30 13:41:56.432 [debug] < x-powered-by: Flask
- 2017-09-30 13:41:56.432 [debug] < x-processed-time: 0.0011260509491
- 2017-09-30 13:41:56.432 [debug]
- 2017-09-30 13:41:56.432 [debug] > {
- "args": {},
- "data": "a=3",
- "files": {},
- "form": {},
- "headers": {
- "Connection": "close",
- "Content-Length": "3",
- "Content-Type": "",
- "Host": "httpbin.org"
- },
- "json": null,
- "origin": "0.0.0.0",
- "url": "https://httpbin.org/post"
- }
- ```
- """
+ @type log_level :: :info | :warn | :error
require Logger
- def call(env, next, _opts) do
- env
- |> log_request
- |> log_headers("> ")
- |> log_params("> ")
- |> log_body("> ")
- |> Tesla.run(next)
- |> case do
- {:ok, env} ->
- env
- |> log_response
- |> log_headers("< ")
- |> log_body("< ")
-
- {:ok, env}
-
- {:error, reason} ->
- log_exception(reason, "< ")
- {:error, reason}
+ def call(env, next, opts) do
+ {time, response} = :timer.tc(Tesla, :run, [env, next])
+ level = log_level(response, opts)
+ Logger.log(level, fn -> Formatter.format(env, response, time, @format) end)
+ Logger.debug(fn -> debug(env, response) end)
+ response
+ end
+
+ defp log_level({:error, _}, _), do: :error
+
+ defp log_level({:ok, env}, opts) do
+ case Keyword.get(opts, :log_level) do
+ nil -> default_log_level(env)
+ fun when is_function(fun) ->
+ case fun.(env) do
+ :default -> default_log_level(env)
+ level -> level
+ end
+ atom when is_atom(atom) -> atom
end
end
- defp log_request(env) do
- _ = Logger.debug("> #{env.method |> to_string |> String.upcase()} #{env.url}")
- env
- end
-
- defp log_response(env) do
- _ = Logger.debug("")
- _ = Logger.debug("< HTTP/1.1 #{env.status}")
- env
- end
-
- defp log_headers(env, prefix) do
- for {k, v} <- env.headers do
- _ = Logger.debug("#{prefix}#{k}: #{v}")
+ @spec default_log_level(Tesla.Env.t()) :: log_level
+ def default_log_level(env) do
+ cond do
+ env.status >= 400 -> :error
+ env.status >= 300 -> :warn
+ true -> :info
end
-
- env
end
- defp log_params(env, prefix) do
- encoded_query = Enum.flat_map(env.query, &Tesla.encode_pair/1)
+ @debug_no_query "(no query)"
+ @debug_no_headers "(no headers)"
+ @debug_no_body "(no body)"
+ @debug_stream "[Elixir.Stream]"
- for {k, v} <- encoded_query do
- _ = Logger.debug("#{prefix} Query Param '#{k}': '#{v}'")
- end
-
- env
+ defp debug(request, {:ok, response}) do
+ [
+ "\n>>> REQUEST >>>\n",
+ debug_query(request.query), ?\n,
+ debug_headers(request.headers), ?\n,
+ debug_body(request.body), ?\n,
+ "\n<<< RESPONSE <<<\n",
+ debug_headers(response.headers), ?\n,
+ debug_body(response.body),
+ ]
end
+ defp debug(_request, _error), do: []
- defp log_body(%Tesla.Env{} = env, _prefix) do
- Map.update!(env, :body, &log_body(&1, "> "))
+ defp debug_query([]), do: @debug_no_query
+ defp debug_query(query) do
+ query
+ |> Enum.flat_map(&Tesla.encode_pair/1)
+ |> Enum.map(fn {k,v} -> ["Query: ", to_string(k), ": ", to_string(v), ?\n] end)
end
- defp log_body(nil, _), do: nil
- defp log_body([], _), do: nil
- defp log_body(%Stream{} = stream, prefix), do: log_body_stream(stream, prefix)
- defp log_body(stream, prefix) when is_function(stream), do: log_body_stream(stream, prefix)
- defp log_body(%Tesla.Multipart{} = mp, prefix), do: log_multipart_body(mp, prefix)
+ defp debug_headers([]), do: @debug_no_headers
+ defp debug_headers(headers), do: Enum.map(headers, fn {k,v} -> [k, ": ", v, ?\n] end)
- defp log_body(data, prefix) when is_binary(data) or is_list(data) do
- _ = Logger.debug("")
- _ = Logger.debug(prefix <> to_string(data))
- data
- end
+ defp debug_body(nil), do: @debug_no_body
+ defp debug_body([]), do: @debug_no_body
+ defp debug_body(%Stream{}), do: @debug_stream
+ defp debug_body(stream) when is_function(stream), do: @debug_stream
- defp log_body_stream(stream, prefix) do
- _ = Logger.debug("")
- Stream.each(stream, fn line -> Logger.debug(prefix <> line) end)
+ defp debug_body(%Tesla.Multipart{} = mp) do
+ [
+ "[Tesla.Multipart]\n",
+ "boundary: ", mp.boundary, ?\n,
+ "content_type_params: ", inspect(mp.content_type_params), ?\n
+ | Enum.map(mp.parts, &([inspect(&1), ?\n]))
+ ]
end
- defp log_multipart_body(%Tesla.Multipart{} = mp, prefix) do
- _ = Logger.debug("")
- _ = Logger.debug(prefix <> "boundary: " <> mp.boundary)
- _ = Logger.debug(prefix <> "content_type_params: " <> inspect(mp.content_type_params))
- Enum.each(mp.parts, &Logger.debug(prefix <> inspect(&1)))
-
- mp
- end
-
- defp log_exception(reason, prefix) do
- _ = Logger.debug(prefix <> " (#{inspect(reason)})")
- end
+ defp debug_body(data) when is_binary(data) or is_list(data), do: data
end
diff --git a/test/tesla/middleware/logger_test.exs b/test/tesla/middleware/logger_test.exs
index a808cc1..d2b54f1 100644
--- a/test/tesla/middleware/logger_test.exs
+++ b/test/tesla/middleware/logger_test.exs
@@ -1,133 +1,181 @@
defmodule Tesla.Middleware.LoggerTest do
use ExUnit.Case, async: false
defmodule Client do
use Tesla
plug Tesla.Middleware.Logger
- plug Tesla.Middleware.DebugLogger
adapter fn env ->
env = Tesla.put_header(env, "content-type", "text/plain")
case env.url do
"/connection-error" ->
{:error, :econnrefused}
"/server-error" ->
{:ok, %{env | status: 500, body: "error"}}
"/client-error" ->
{:ok, %{env | status: 404, body: "error"}}
"/redirect" ->
{:ok, %{env | status: 301, body: "moved"}}
"/ok" ->
{:ok, %{env | status: 200, body: "ok"}}
end
end
end
import ExUnit.CaptureLog
- test "connection error" do
- log =
- capture_log(fn ->
- assert {:error, _} = Client.get("/connection-error")
- end)
+ describe "Logger" do
+ setup do
+ Logger.configure(level: :info)
- assert log =~ "/connection-error -> :econnrefused"
- end
+ :ok
+ end
- test "server error" do
- log = capture_log(fn -> Client.get("/server-error") end)
- assert log =~ "/server-error -> 500"
- end
+ test "connection error" do
+ log = capture_log(fn -> Client.get("/connection-error") end)
+ assert log =~ "/connection-error -> error: :econnrefused"
+ end
- test "client error" do
- log = capture_log(fn -> Client.get("/client-error") end)
- assert log =~ "/client-error -> 404"
- end
+ test "server error" do
+ log = capture_log(fn -> Client.get("/server-error") end)
+ assert log =~ "/server-error -> 500"
+ end
- test "redirect" do
- log = capture_log(fn -> Client.get("/redirect") end)
- assert log =~ "/redirect -> 301"
- end
+ test "client error" do
+ log = capture_log(fn -> Client.get("/client-error") end)
+ assert log =~ "/client-error -> 404"
+ end
- test "ok" do
- log = capture_log(fn -> Client.get("/ok") end)
- assert log =~ "/ok -> 200"
- end
+ test "redirect" do
+ log = capture_log(fn -> Client.get("/redirect") end)
+ assert log =~ "/redirect -> 301"
+ end
- test "ok with params" do
- log = capture_log(fn -> Client.get("/ok", query: %{"test" => "true"}) end)
- assert log =~ "Query Param 'test': 'true'"
+ test "ok" do
+ log = capture_log(fn -> Client.get("/ok") end)
+ assert log =~ "/ok -> 200"
+ end
end
- test "ok with list params" do
- log = capture_log(fn -> Client.get("/ok", query: %{"test" => ["first", "second"]}) end)
- assert log =~ "Query Param 'test[]': 'first'"
- assert log =~ "Query Param 'test[]': 'second'"
- end
+ describe "Debug mode" do
+ setup do
+ Logger.configure(level: :debug)
+ :ok
+ end
- test "multipart" do
- mp = Tesla.Multipart.new() |> Tesla.Multipart.add_field("field1", "foo")
- log = capture_log(fn -> Client.post("/ok", mp) end)
- assert log =~ "boundary: #{mp.boundary}"
- assert log =~ inspect(List.first(mp.parts))
- end
+ test "ok with params" do
+ log = capture_log(fn -> Client.get("/ok", query: %{"test" => "true"}) end)
+ assert log =~ "Query: test: true"
+ end
- test "stream" do
- stream = Stream.map(1..10, fn i -> "chunk: #{i}" end)
- log = capture_log(fn -> Client.post("/ok", stream) end)
- assert log =~ "/ok -> 200"
+ test "ok with list params" do
+ log = capture_log(fn -> Client.get("/ok", query: %{"test" => ["first", "second"]}) end)
+ assert log =~ "Query: test[]: first"
+ assert log =~ "Query: test[]: second"
+ end
+
+ test "multipart" do
+ mp = Tesla.Multipart.new() |> Tesla.Multipart.add_field("field1", "foo")
+ log = capture_log(fn -> Client.post("/ok", mp) end)
+ assert log =~ "boundary: #{mp.boundary}"
+ assert log =~ inspect(List.first(mp.parts))
+ end
+
+ test "stream" do
+ stream = Stream.map(1..10, fn i -> "chunk: #{i}" end)
+ log = capture_log(fn -> Client.post("/ok", stream) end)
+ assert log =~ "/ok -> 200"
+ assert log =~ "Stream"
+ end
end
describe "with log_level" do
defmodule ClientWithLogLevel do
use Tesla
- require Logger
-
plug Tesla.Middleware.Logger, log_level: &log_level/1
defp log_level(env) do
cond do
env.status == 404 -> :info
true -> Tesla.Middleware.Logger.default_log_level(env)
end
end
adapter fn env ->
- env = Tesla.put_header(env, "content-type", "text/plain")
-
case env.url do
"/bad-request" ->
{:ok, %{env | status: 400, body: "bad request"}}
"/not-found" ->
{:ok, %{env | status: 404, body: "not found"}}
"/ok" ->
{:ok, %{env | status: 200, body: "ok"}}
end
end
end
test "not found" do
log = capture_log(fn -> ClientWithLogLevel.get("/not-found") end)
assert log =~ "[info] GET /not-found -> 404"
end
test "bad request" do
log = capture_log(fn -> ClientWithLogLevel.get("/bad-request") end)
assert log =~ "[error] GET /bad-request -> 400"
end
test "ok" do
log = capture_log(fn -> ClientWithLogLevel.get("/ok") end)
assert log =~ "[info] GET /ok -> 200"
end
end
+
+ alias Tesla.Middleware.Logger.Formatter
+
+ describe "Formatter: compile/1" do
+ test "compile default format" do
+ assert is_list(Formatter.compile(nil))
+ end
+
+ test "comppile pattern" do
+ assert Formatter.compile("$method $url => $status") == [:method, " ", :url, " => ", :status]
+ end
+
+ test "raise compile-time error when pattern not found" do
+ assert_raise ArgumentError, fn ->
+ Formatter.compile("$method $nope")
+ end
+ end
+ end
+
+ describe "Formatter: format/2" do
+ setup do
+ format = Formatter.compile("$method $url -> $status | $time")
+ {:ok, format: format}
+ end
+
+ test "format error", %{format: format} do
+ req = %Tesla.Env{method: :get, url: "/error"}
+ res = {:error, :econnrefused}
+
+ assert IO.chardata_to_string(Formatter.format(req, res, 200_000, format)) ==
+ "GET /error -> error: :econnrefused | 200.000"
+ end
+
+ test "format ok response", %{format: format} do
+ req = %Tesla.Env{method: :get, url: "/ok"}
+ res = {:ok, %Tesla.Env{method: :get, url: "/ok", status: 201}}
+
+ assert IO.chardata_to_string(Formatter.format(req, res, 200_000, format)) ==
+ "GET /ok -> 201 | 200.000"
+ end
+ end
end

File Metadata

Mime Type
text/x-diff
Expires
Mon, Nov 25, 6:23 AM (1 d, 9 h)
Storage Engine
blob
Storage Format
Raw Data
Storage Handle
39678
Default Alt Text
(18 KB)

Event Timeline