minato_telemetry (minato v0.18.6)

View Source

Every event minato emits, in one module.

Instrumentation belongs in one place for the same reason the protocol codec does: the event names, the measurements and the metadata keys are a contract with whoever is collecting them, and a contract spread across eight call sites drifts. Everything here is telemetry, which is what an OpenTelemetry bridge, a Prometheus exporter and a logger handler all already know how to read.

The events

Spans follow the telemetry:span/3 shape, so each is three events - start, stop, and exception when the work raised - and stop carries a duration in native units.

eventwhen
[minato, connect, start\|stop\|exception]opening a connection, including TLS and authentication
[minato, query, start\|stop\|exception]one statement, whichever query path ran it
[minato, checkout, start\|stop\|exception]borrowing a connection, so duration is the time spent waiting for one
[minato, connection, opened]a pool connection became available
[minato, connection, closed]a pool connection was closed, with why
[minato, notification, received]LISTEN delivered something
[minato, listener, reconnected]a listener lost its connection and resubscribed, so notifications were missed

What is in the metadata, and what is never

sql is present when minato was configured with log_statements => true, and absent otherwise. A statement is not a secret but it is close to one: SELECT * FROM users WHERE email = $1 in a log is fine, and the same statement written by a caller that pasted the value in is a leak. Parameters are never in an event, in any configuration, for the same reason - they are the values themselves.

Passwords never reach this module at all. See minato_conn for where they stop.

Attaching

telemetry:attach(<<"minato-slow">>, [minato, query, stop], fun
    (_Event, #{duration := Duration}, #{command := Command}, _Config) ->
        case erlang:convert_time_unit(Duration, native, millisecond) of
            Slow when Slow > 100 -> logger:warning(#{slow_query => Command, ms => Slow});
            _Fast -> ok
        end
end, undefined).

Summary

Types

The measurements an event carries. Durations are in native time units.

The metadata a caller attaches to an event: atoms to whatever they carry.

Functions

event/3 with no measurements beyond the time it happened.

Run a function as a span: start, then stop or exception.

Whether statements may be put in events and logs.

Add the statement to metadata, if statements may be logged at all.

Types

measurements()

-type measurements() :: #{atom() => number()}.

The measurements an event carries. Durations are in native time units.

metadata()

-type metadata() :: #{atom() => term()}.

The metadata a caller attaches to an event: atoms to whatever they carry.

Functions

event(Name, Metadata)

-spec event([atom()], metadata()) -> ok.

event/3 with no measurements beyond the time it happened.

event(Name, Measurements, Metadata)

-spec event([atom()], measurements(), metadata()) -> ok.

Emit one event.

span(Name, Metadata, Fun)

-spec span([atom()], metadata(), fun(() -> {dynamic(), metadata()})) -> dynamic().

Run a function as a span: start, then stop or exception.

The function answers {Result, ExtraMetadata}, and the extra metadata is merged into the stop event, which is how a query reports the command it turned out to be and how many rows it returned. The result is whatever the function returned, which is why it is untyped here: this module carries answers without knowing what they are.

statements()

-spec statements() -> boolean().

Whether statements may be put in events and logs.

Off unless the minato application environment says log_statements is true. Read once per call rather than cached, because an operator turning it on to diagnose something at three in the morning should not have to restart anything.

statements(Sql)

-spec statements(iodata()) -> metadata().

Add the statement to metadata, if statements may be logged at all.