Wymcp.
View Source
Renders wymcp's telemetry events as structured Logger lines under one
policy — attached at boot by default, off with
config :wymcp, logger: false.
The library emits, this handler renders, the consuming application
chooses. Wymcp.Telemetry owns the events and their metadata; this module
owns nothing but the lines, so a consumer wanting different levels, keys or
destinations attaches a handler of its own against the same events and
turns this one off — that is what telemetry is for, and it is why there is
no level knob here.
Nothing connects this to MCP's own logging capability. logging/setLevel
sets a per-session threshold on the notifications/message push, which
Wymcp.Session owns; this module renders wymcp's telemetry to the BEAM
Logger. Neither reads the other, and the two level vocabularies are
unrelated.
Configuration
config :wymcp, logger: false stops Wymcp.Application attaching the
handler at boot; the default is true. The key is read exactly once, at
boot, through enabled?/0. attach/0 and detach/0 ignore it — a test
that detaches can re-attach without consulting configuration, and the boot
read stays the one place the key is consulted.
Turning it off means turning off every line below, including the fault
lines: a tool that raises is rescued and answered as an isError result,
so with no handler attached nothing about that raise reaches the adapter
and no line exists. That is the consumer's choice to make, and it is why
the default is on.
Line policy
One sentence: a client-triggerable fact renders at :info, a
consumer-code or wymcp fault at :error, and nothing renders at
:warning.
A public MCP endpoint's rejections are attacker-triggerable volume, so a
:warning per bad request is a flood the attacker chooses the size of.
Nothing a client can provoke is therefore louder than :info. A start
event renders no line; one call renders one line, plus a fault line where
consumer code broke — an auth module that raises renders both
wymcp.auth.error and the rejection's own line, because the two say
different things and the fault is the consumer's to fix; and no line ever
carries a session id — it is bearer-equivalent, and the facts that matter
are on the line already.
Client- and consumer-controlled values are bounded on render by
bounded/1, which replaces control characters as well as cutting length —
a client able to put a newline on a line is a client able to forge one.
The events themselves carry the raw values, because a consumer's own
handler shapes its own line.
The message string is the dotted event name — wymcp.wire.reject — so one
grep handle works in every formatter, and the facts are metadata. There is
no event metadata key: that name is common in application line
vocabularies and a collision is the consumer's to resolve, not wymcp's to
cause.
Line table
A ★ marks a value bounded by bounded/1 on render — cut to length, with
control characters replaced.
| event | level | line keys |
|---|---|---|
wire.reject | :info | rejecter, reason, status, http_method, method★, message_id★, message★, era when present |
session.start | :info | client_name★, client_version★, era |
session.expired | :info | era |
tool.start | not rendered | — |
tool.stop | :info | tool_name★, action★, is_error, error_kind, duration_ms, era |
tool.error | :error | tool_name★, action★, message_id★, exception, error★, duration_ms, era, crash_reason |
help.called | not rendered | — |
auth.error | :error | auth_module, exception, error★, http_method, method★, message_id★, crash_reason |
server.reject | :info | server, reason★, message_id★, era |
server.error | :error | server, exception, error★, message_id★, era, crash_reason |
This table is the metadata allowlist a consuming application copies into
its own Logger :metadata config. wymcp ships no allowlist of its own:
that config belongs to the application.
tool.start renders nothing because it carries nothing tool.stop lacks —
the same tool, action and era, without the outcome — so a start line would
be a second line per call saying less. Start events serve the metrics and
tracing consumers, who read the event. The one case a start line alone
would trace, a tool that never returns, is accepted.
help.called renders nothing because a help call is a tool call and
already renders as tool.stop with tool_name: "help" and the target
action, error answers included. What help.called adds — the target tool,
the answer level — is product signal rather than an operator's line, and
rendering it beside tool.stop would break one line per call.
Totality
:telemetry detaches a handler that raises, from every event it was
attached to, and logs one warning; after that every line is silently gone.
So every clause here reads its metadata with Map.get/3 and matches no key
in a head, and a value of an unexpected shape is rendered rather than
matched. crash_reason is forwarded verbatim and never inspected.
Summary
Functions
Attaches the handler to every event it renders, unconditionally.
A value made safe to put on a log line: cut to a length that fits, with control characters replaced.
Detaches the handler. Idempotent: detaching when nothing is attached
answers :ok.
Whether the handler is attached at boot — the config :wymcp, logger: …
key, default true.
Functions
Attaches the handler to every event it renders, unconditionally.
Idempotent: a second call is a no-op, so a test that detached in setup
can re-attach on exit without coordinating with boot.
A value made safe to put on a log line: cut to a length that fits, with control characters replaced.
A string is cut at 256 graphemes (String.slice/3, so no codepoint is
split), has every C0 control byte and DEL replaced with a space, and is
cut again. Cutting first keeps the scrub's work close to the bound for
an ordinary long value — method and message_id reach a rejection off
an unauthenticated request, and a megabyte of plain text would otherwise
be walked whole to produce 256 characters. The bound is in graphemes, not
bytes: a value that is one long grapheme cluster (a megabyte of combining
marks) is walked whole by the cut itself, a cost of the same order as the
JSON decode that already accepted it. Cutting again is what holds the
bound afterwards: "\r\n" is one grapheme and scrubs to two spaces, so
the substitution can push a cut string back over 256. An atom, float,
boolean or nil passes through — none can be long or carry a control
character — and so does an integer of up to 256 digits; a longer one is a
JSON id the client chose the size of, and is inspected and cut like any
other term. Anything else is inspected with its own printable and
collection limits and cut to the same length, which keeps a request body
off a line; inspect/2 escapes a control character inside a string
itself, so that clause needs no replacement of its own.
The replacement is what stops a client forging log lines. A JSON-RPC
string may decode to an embedded newline, and several of the values
bounded here come straight out of the client's body or headers, so
rendering one raw would let a client write a whole line of its own into
the operator's stream — including a line that looks like one of wymcp's.
The scrub is byte-wise rather than a regex because a header value need not
be valid UTF-8 and a ~r/.../u match raises on the bytes that are not,
and a raising handler is detached from every event.
256 is a sanity bound rather than a byte budget: the point is that one client-supplied value cannot make a line unreadable, not that lines fit some size.
Examples
iex> Wymcp.Telemetry.Logger.bounded("tools/call")
"tools/call"
iex> Wymcp.Telemetry.Logger.bounded("id\n[error] forged line")
"id [error] forged line"
iex> Wymcp.Telemetry.Logger.bounded(:invalid_token)
:invalid_token
iex> Wymcp.Telemetry.Logger.bounded(42)
42
iex> Wymcp.Telemetry.Logger.bounded(nil)
nil
iex> Wymcp.Telemetry.Logger.bounded(%{"a" => 1})
"%{\"a\" => 1}"Detaches the handler. Idempotent: detaching when nothing is attached
answers :ok.
Whether the handler is attached at boot — the config :wymcp, logger: …
key, default true.
Wymcp.Application is the only caller: attach/0 and detach/0
deliberately do not consult it.