Current section
Files
Jump to
Current section
Files
lib/clarion.ex
defmodule Clarion do
@moduledoc ~S"""
Clarion helps library authors emit logs that stay structured all the way
through Erlang's `:logger` pipeline — readable for a human at the
console, and still a real map for any handler downstream that wants to
query it (JSON, Datadog, a test assertion) rather than re-parse a
sentence.
See `docs/how_logging_actually_works.md` in the repository for the
verified explanation of *why* this is a real problem in the current
`:logger`/`Logger` pipeline, and `docs/comparison.md` for how this
differs from JSON formatters (`logger_json`), text formatters
(`flatlog`), and log-shipping backends — all of which operate on an
event *after* it already exists, not at the call site that creates it.
## The problem, concretely
Imagine an HTTP client library that retries a failed request. The naive
way to log that:
Logger.info("retrying request to \#{url}, attempt \#{attempt}/\#{max}")
reads fine in a dev console. But the moment that log event reaches a
JSON handler (Datadog, Loki, anything), all a consumer gets is one
opaque string — `url`, `attempt`, and `max` are gone, baked into text
that has to be regexed back apart if anyone wants to alert on
"attempt >= 3", or is 3 = max.
With Clarion:
Clarion.info(%{event: :http_retry, url: url, attempt: attempt, max: max})
Every field arrives at every handler as real data — a JSON handler
writes real `url`/`attempt`/`max` fields, a console handler prints a
readable one-liner (`http_retry url=... attempt=2 max=3`) via
`default_report_cb/1`, and nothing has to guess or re-parse.
## Why `Clarion.info/2` requires a map or keyword list, not a string
`Clarion.info/2`, `Clarion.warning/2`, and `Clarion.error/2` deliberately
do **not** accept a bare string, unlike `Logger.info/2`. This is the
central, debatable design decision in this library — see
`docs/design_decisions.md` for the full reasoning. In short: if the API
accepts a string, someone will pass one, and once a report has been
interpolated into a string at the call site, `:logger` never sees it as
structured data again — no formatter or handler downstream can recover
it. Requiring a report is a guardrail, not new plumbing.
"""
@typedoc "A log level, same as `Logger.level/0`."
@type level :: Logger.level()
@typedoc """
A structured log report: a map or a keyword list of arbitrary
application data. This is the only shape Clarion accepts as the thing
being logged — never a string.
"""
@type report :: map() | keyword()
@typedoc """
A renderer for a `t:report/0`, following the 1-arity form of Erlang's
`:logger` `report_cb()` contract: given the report, return an
`:io_lib.format/2`-style `{format, args}` pair used to produce the
human-readable rendering for consumers (typically a console handler)
that call it.
Clarion never calls this function itself — see the moduledoc and
`docs/how_logging_actually_works.md` for why that matters. It is stored
in the log event's metadata for a *consumer* to call, if and when that
consumer wants text instead of structured data.
"""
@type report_cb :: (report -> {:io.format(), [term()]})
@doc """
Logs `report` at `level`, as a real structured `:logger` report.
`report` must be a map or a keyword list — see the moduledoc for why a
bare string is rejected. Available `opts`:
* `:report_cb` - a `t:report_cb/0` used to render `report` for
handlers that want text. Defaults to `default_report_cb/1`.
Whatever you pass here, Clarion stores it in metadata and never
invokes it — it cannot cause `report` to be lost, because Clarion
never rewrites the event's message with the rendered result.
* any other option is forwarded as `:logger` metadata, exactly as with
`Logger.log/3`.
## Examples
iex> Clarion.report(:info, %{event: :cache_miss, key: "user:42"})
:ok
iex> Clarion.report(:warning, [event: :retry, attempt: 1], request_id: "abc")
:ok
iex> Clarion.report(:info, "not a report")
** (ArgumentError) Clarion.report/3 requires a map or a keyword list, got: "not a report"
"""
defmacro report(level, report, opts \\ []) do
quote bind_quoted: [level: level, report: report, opts: opts] do
Clarion.__validate_report__!(report)
{report_cb, metadata} = Keyword.pop(opts, :report_cb, &Clarion.default_report_cb/1)
metadata = Keyword.put(metadata, :report_cb, report_cb)
require Logger
Logger.log(level, report, metadata)
end
end
@doc """
Logs `report` at the `:info` level. See `report/3`.
## Examples
iex> Clarion.info(%{event: :cache_hit, key: "user:42"})
:ok
"""
defmacro info(report, opts \\ []) do
quote do: Clarion.report(:info, unquote(report), unquote(opts))
end
@doc """
Logs `report` at the `:warning` level. See `report/3`.
## Examples
iex> Clarion.warning(%{event: :retry, attempt: 1})
:ok
"""
defmacro warning(report, opts \\ []) do
quote do: Clarion.report(:warning, unquote(report), unquote(opts))
end
@doc """
Logs `report` at the `:error` level. See `report/3`.
## Examples
iex> Clarion.error(%{event: :request_failed, reason: :timeout})
:ok
"""
defmacro error(report, opts \\ []) do
quote do: Clarion.report(:error, unquote(report), unquote(opts))
end
@doc """
The default `t:report_cb/0` used by `report/3` when the caller doesn't
supply one. Renders `report` as `"key1=val1 key2=val2"`, with an
`:event` field (if present) rendered first, bare, as a leading event
name rather than `event=...`.
Keys are sorted for deterministic output. Values containing whitespace
are wrapped in `inspect/1` so the rendering stays parseable by eye and
by simple tools (logfmt-style).
## Examples
iex> Clarion.default_report_cb(%{event: :http_retry, attempt: 2})
{~c"~ts", ["http_retry attempt=2"]}
iex> Clarion.default_report_cb(%{key: "user:42"})
{~c"~ts", ["key=user:42"]}
iex> Clarion.default_report_cb(%{message: "hello world"})
{~c"~ts", ["message=\\"hello world\\""]}
"""
@spec default_report_cb(report) :: {:io.format(), [term()]}
def default_report_cb(report) do
map = Map.new(report)
{event, rest} = Map.pop(map, :event)
pairs =
rest
|> Enum.sort()
|> Enum.map_join(" ", fn {key, value} -> "#{key}=#{render_value(value)}" end)
rendered =
case {event, pairs} do
{nil, pairs} -> pairs
{event, ""} -> to_string(event)
{event, pairs} -> "#{event} #{pairs}"
end
# The rendered text is passed as an *argument* to a fixed "~ts" format,
# never used as the format string itself: a report value containing a
# literal "~" (e.g. "50~60% CPU") would otherwise be misinterpreted by
# :io_lib.format/2 as a format directive and crash the renderer.
{~c"~ts", [rendered]}
end
defp render_value(value) when is_binary(value) do
if String.contains?(value, " "), do: inspect(value), else: value
end
defp render_value(value), do: inspect(value)
@doc false
@spec __validate_report__!(map() | list()) :: :ok
def __validate_report__!(report) when is_map(report), do: :ok
def __validate_report__!(report) when is_list(report) do
if Keyword.keyword?(report) do
:ok
else
raise ArgumentError,
"Clarion.report/3 requires a map or a keyword list, got: #{inspect(report)}"
end
end
def __validate_report__!(other) do
raise ArgumentError,
"Clarion.report/3 requires a map or a keyword list, got: #{inspect(other)}"
end
end