Skip to content

Add metadata to logger#631

Open
teamon wants to merge 1 commit intomasterfrom
tt/logger-meta
Open

Add metadata to logger#631
teamon wants to merge 1 commit intomasterfrom
tt/logger-meta

Conversation

@teamon
Copy link
Copy Markdown
Member

@teamon teamon commented Oct 27, 2023

wip, testing in progress

@teamon
Copy link
Copy Markdown
Member Author

teamon commented Oct 27, 2023

@yordis wdyt of this as an idea?

Use `:conceal` request option to conceal sensitive requests.

```
Tesla.get(client, opts: [conceal: true]])
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Overall, I like the idea, the only feedback is about documentation.

We should document in one place all the "reserved" options that have a given intent.

I like it!

@yordis
Copy link
Copy Markdown
Member

yordis commented Aug 1, 2024

Recently, I had to send the data somehow, I ended up doing the following:

defmodule Umbrella.Tesla.Logger do
  def log_level(%Tesla.Env{status: status}) when status in 400..499, do: :warning
  def log_level(_env), do: :default

  def log_formatter(req, {:error, reason}, time) do
    %{
      time: time,
      method: upper_case_method(req),
      url: req.url,
      path: req.opts[:req_url],
      req_body: log_env_body(req),
      reason: inspect(reason)
    }
  end

  def log_formatter(req, {:ok, resp}, time) do
    %{
      time: time,
      status: resp.status,
      method: upper_case_method(req),
      url: req.url,
      path: req.opts[:req_url],
      req_body: log_env_body(req),
      resp_body: log_env_body(resp)
    }
  end

  defp log_env_body(%Tesla.Env{status: status} = env) when status >= 400 do
    inspect(env.body)
  end

  defp log_env_body(_), do: "[REDACTED]"

  defp upper_case_method(%Tesla.Env{} = env) do
    env.method
    |> to_string()
    |> String.upcase()
  end
end

As long as the metadata is under a given key tesla: [....] I do not see any issue, although, I still believe that structured logging is much better.

Being said, the ultimate way to deal with this is to simple allow the user to do Logger calls themselves and give them enough information to know what to do with it.

I think it was a misdirection to call Logger ourselves. Except for the debug flag!

@yordis yordis force-pushed the master branch 6 times, most recently from 2bca420 to fe7207c Compare October 24, 2024 16:11
@yordis
Copy link
Copy Markdown
Member

yordis commented Jun 12, 2025

@teamon do you mind rebasing? I am still unsure about the feature and the final version

Copilot AI review requested due to automatic review settings March 23, 2026 18:57
Copy link
Copy Markdown

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR adds optional Tesla request/response metadata to Tesla.Middleware.Logger log events, extending the formatter to support request/response bodies and adding tests around metadata inclusion/exclusion behavior.

Changes:

  • Extend Tesla.Middleware.Logger.Formatter to support $request_body / $response_body output keys.
  • Add metadata: option behavior to emit a :tesla metadata map (all keys or a selected subset), and skip metadata when opts: [conceal: true].
  • Replace prior metadata test coverage with new tests that assert Logger metadata contents via a custom backend.

Reviewed changes

Copilot reviewed 2 out of 2 changed files in this pull request and generated 5 comments.

File Description
lib/tesla/middleware/logger.ex Adds formatter keys and implements metadata: handling + docs for Tesla metadata emission.
test/tesla/middleware/logger_test.exs Adds a custom Logger backend and new tests validating metadata behavior and concealment.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment on lines 85 to +88
- `:metadata` - metadata to pass to `Logger`
- `:debug` - use `Logger.debug/2` to log request/response details
- `:format` - custom string template or function for log message (see below)
- `:metadata` - configure logger metadata
Copy link

Copilot AI Mar 23, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

:metadata is documented twice and the first description ("metadata to pass to Logger") no longer matches the implementation (it now treats :metadata as false | true | [atom]). This is also an API-breaking change for existing callers that passed keyword metadata (e.g. [request_id: ...]), so the option docs should be updated to reflect the supported shapes and/or a new option name should be introduced for the Tesla-specific metadata to preserve backward compatibility.

Suggested change
- `:metadata` - metadata to pass to `Logger`
- `:debug` - use `Logger.debug/2` to log request/response details
- `:format` - custom string template or function for log message (see below)
- `:metadata` - configure logger metadata
- `:metadata` - configure logger metadata; accepts `false` (disable metadata), `true` (use the default metadata set), or a list of atoms selecting which Tesla-specific metadata fields to include
- `:debug` - use `Logger.debug/2` to log request/response details
- `:format` - custom string template or function for log message (see below)

Copilot uses AI. Check for mistakes.
Comment on lines +376 to +383
@metadata_keys [:method, :url, :query, :status, :request_body, :response_body, :time]

defp metadata(req, res, time, keys) when is_list(keys) do
if req.opts[:conceal] do
[]
else
[tesla: Enum.into(keys, %{}, fn key -> {key, Formatter.output(key, req, res, time)} end)]
end
Copy link

Copilot AI Mar 23, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

metadata/4 treats any list as a list of keys to extract, but prior behavior allowed passing a keyword list directly to Logger.log/3 (e.g. [request_id: "abc123"]). With the current implementation, a keyword list will be iterated as {key, value} tuples and Formatter.output/4 will crash with a FunctionClauseError. Consider supporting keyword lists explicitly (e.g. when Keyword.keyword?(keys)) and merging them with the new tesla: metadata, or introduce a separate option name for Tesla metadata and keep :metadata as pass-through.

Copilot uses AI. Check for mistakes.
Comment on lines +376 to +388
@metadata_keys [:method, :url, :query, :status, :request_body, :response_body, :time]

defp metadata(req, res, time, keys) when is_list(keys) do
if req.opts[:conceal] do
[]
else
[tesla: Enum.into(keys, %{}, fn key -> {key, Formatter.output(key, req, res, time)} end)]
end
end

defp metadata(req, res, time, true), do: metadata(req, res, time, @metadata_keys)

defp metadata(_req, _res, _time, false), do: []
Copy link

Copilot AI Mar 23, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When metadata: is a list, any atom is accepted, but Formatter.output/4 only has clauses for a fixed set of keys. Passing an unsupported key (e.g. metadata: [:foo]) will raise at runtime. It would be safer to validate/filter keys against @metadata_keys (or handle unknown keys by returning nil/skipping) and raise a clear ArgumentError if an invalid key is provided.

Copilot uses AI. Check for mistakes.
Comment on lines +529 to +537
assert meta[:tesla] == %{
status: "200",
time: "0.000",
url: "/ok",
query: "",
method: "POST",
request_body: "reqdata",
response_body: "ok"
}
Copy link

Copilot AI Mar 23, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This assertion hard-codes time: "0.000", but the middleware measures real elapsed time via :timer.tc/3, which is not guaranteed to be exactly zero and can be non-deterministic across machines/CI. To avoid flaky tests, assert that time is present and matches a numeric format (or that it parses as a float >= 0) rather than asserting an exact string value.

Suggested change
assert meta[:tesla] == %{
status: "200",
time: "0.000",
url: "/ok",
query: "",
method: "POST",
request_body: "reqdata",
response_body: "ok"
}
tesla_meta = meta[:tesla]
# Assert all metadata fields except time match exactly
assert Map.delete(tesla_meta, :time) == %{
status: "200",
url: "/ok",
query: "",
method: "POST",
request_body: "reqdata",
response_body: "ok"
}
# Assert time is present and is a non-negative float in string form
assert is_binary(tesla_meta.time)
assert {time_float, ""} = Float.parse(tesla_meta.time)
assert time_float >= 0.0

Copilot uses AI. Check for mistakes.
}
end

test "do not include metadata for concealed reqeusts", %{adapter: adapter} do
Copy link

Copilot AI Mar 23, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Typo in test name: "reqeusts" should be "requests".

Suggested change
test "do not include metadata for concealed reqeusts", %{adapter: adapter} do
test "do not include metadata for concealed requests", %{adapter: adapter} do

Copilot uses AI. Check for mistakes.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants