A thin Elixir wrapper around the Erlang snabbkaffe trace-based testing library.
snabbkaffe ships its instrumentation as Erlang preprocessor macros
(-include_lib("snabbkaffe/include/trace.hrl")) which are not usable from
Elixir. This module provides the Elixir macro counterparts so that:
- Trace points placed in production code (
tp/2,tp/3,tp_span/3,tp_span/4) only become real snabbkaffe collector calls in:test. Compiled anywhere else they follow snabbkaffe'strace_prod.hrlconvention: by defaultdatais evaluated and its value thrown away,level:degrades to a:loggercall, andignore_side_effects: truedrops to a bare:ok(see "Why discard in prod?" below). - Test helpers (
check_trace/2,block_until/2,of_kind/2, ...) wrap the corresponding:snabbkafferuntime calls. Most are plain functions; only the ones that take an Elixir pattern (block_until,find_pairs,causality,force_ordering, ...) need to be macros: they turn the pattern into a matcher function in place of snabbkaffe's?match_event.
Why discard in prod?
Snabbkaffex is a test-only dependency (only: :test). The trace-point macros
live in regular lib/ code, so they must compile to a cheap no-op when the
collector is not present. Following snabbkaffe's own convention, the gate is
Mix.env() == :test, evaluated at macro-expansion time so it reflects the
environment of the module being compiled.
To match the Erlang semantics precisely, the discarded tp/2 still evaluates
its data expression (so side effects behave identically across builds) and then
throws the value away. Passing level: makes it degrade to a :logger call in
non-test builds instead (just like trace_prod.hrl); passing
ignore_side_effects: true skips the data expression entirely. The two are
mutually exclusive (passing both raises at compile time), since they pull in
opposite directions — keep the event in prod logs vs. drop it to nothing. See
tp/3.
Usage
Instrument production code with use Snabbkaffex, only: :trace, which imports
only the discardable trace-point macros (tp/2, tp/3, tp_span/3,
tp_span/4) and none of the test-only helpers:
defmodule MyServer do
use Snabbkaffex, only: :trace
def handle_event(e) do
tp(:my_server_got_event, %{event: e})
# ...
end
endAnd in a test, use Snabbkaffex (no options) to also get check_trace/2,
of_kind/2, and friends. The trace collector is a global singleton, so a
test module that runs traces must be async: false:
use ExUnit.Case, async: false
use Snabbkaffex
test "server processes the event" do
check_trace(
fn -> MyServer.handle_event(:hello) end,
fn trace ->
assert [%{event: :hello}] = of_kind(trace, :my_server_got_event)
end
)
enduse Snabbkaffex emits a compile-time warning if the module is
use ExUnit.Case, async: true, since concurrent tests would clobber each
other's traces through the shared collector.
Event shape
A trace point tp(:kind, %{a: 1}) is collected as a map
%{:"$kind" => :kind, :a => 1, :"~meta" => %{...}}. When pattern matching on
events, the kind lives under the :"$kind" key. Prefer of_kind/2 to filter
by kind so you rarely need to spell that out.
Argument order
Trace-querying functions (of_kind/2, projection/2, find_pairs/3,
causality/3, ...) take the trace as their first argument, unlike the
Erlang originals, so they read left-to-right in a pipe:
trace
|> of_kind(:worker_started)
|> projection(:input)
Summary
Types
A check_trace/2,3 check function. Passes unless it raises (its return value
is ignored, unlike Erlang snabbkaffe's :snabbkaffe.trace_spec/1, which
requires ok/true). Arity 1 receives the trace; arity 2 the run result
and the trace.
Field (or fields) to project out of each event; see projection/2.
Functions
Requires Snabbkaffex and imports its macros/helpers.
Fault scenario for inject_crash/2's scenario: option: crash on every
matching trace point. This is also inject_crash's default when no strategy
option is given.
Print an analysis of all statistics collected via push_stat/2.
Block until an event matching pattern is collected, or until timeout.
block_until/3 waiting for n_events events matching pattern (mirrors
Erlang's ?block_until({Predicate, NEvents}, ...) form). Events already in
the collected trace count towards n_events, which makes it the right tool
for waiting on the Nth occurrence of a recurring event (e.g. a node becoming
:ready for the same view a second time, after churn). Returns
{:ok, [event]} or {:timeout, [partial]}.
Assert every effect event in trace was preceded by a matching cause event.
Pairs may be nested. Raises on a causality violation; otherwise returns true
if at least one pair was found, false if none.
causality/3 with a guard expression over both events' bindings.
Run run_fun, collect the resulting trace, then validate it with check_fun.
check_trace/2 with a snabbkaffe run config (a map, e.g. %{timeout: 100}) or
an integer statistics bucket.
Reset the collector and nemesis state (drops the buffered trace and any injected crashes/orderings) without stopping the collector.
Flush and return the collected trace, waiting timeout ms for silence first.
Dump trace to a file (as snabbkaffe does on failure) and return the path.
Strip timestamps from every event in trace (useful before comparing traces).
Find cause/effect pairs in trace matching cause_pattern and effect_pattern.
find_pairs/3 with an extra guard expression over both events' bindings.
Remove a crash injected by inject_crash/2 (given its reference).
Enforce an ordering between two classes of events: hold back every event
matching the :delay pattern until events matching the :until pattern have
been emitted.
Start forwarding trace events emitted on the remote node to this collector.
Return the raw statistics map collected so far.
Assert value is within deviation of expected. Returns true or raises.
Assert the numbers in list are non-decreasing. Returns true or raises.
Inject crashes at trace points matching pattern, returning a reference you
can later pass to fix_crash/1.
Build a predicate fn event -> boolean end from an Elixir pattern.
Keep only events in trace whose logger metadata domain equals domain.
Keep only events in trace whose :"$kind" is kind (or one of a list of kinds).
Keep only events in trace emitted on node.
The maximum nesting depth among a list of pairs (from find_pairs/3).
Fault scenario for inject_crash/2's scenario: option: crash periodically,
driven by the count of matching trace
points (not wall-clock time). Within each cycle of period matches the trace
point stays healthy for the first duty_cycle fraction and crashes for the
rest; phase (in radians, 0 to 2 * pi) shifts the cycle.
Project field (atom) or fields (list of atoms) out of each event in trace.
Assert every value in expected appears in the projection of fields over
trace (i.e. expected is a subset of what was traced). Returns true or
raises. The complement of projection_is_subset/3.
Assert the projection of fields over trace contains no values outside
expected (i.e. what was traced is a subset of expected). Returns true
or raises.
Record a value for metric. With an extra leading argument, records a
{x, y} datapoint (push_stat(metric, x, y)). See analyze_statistics/0.
Record many datapoints for metric at once (see :snabbkaffe.push_stats/2,3).
Fault scenario: crash with the given probability (a float in 0.0..1.0).
Usually reached via inject_crash(pattern, random_crash: probability).
Wait for the events of a subscription returned by subscribe/1. Returns
{:ok, [event]} or {:timeout, [partial]}.
Fault scenario: crash the first n times a trace point matches, then recover.
Usually reached via inject_crash(pattern, recover_after: n).
Retry the do block up to n times, sleeping interval ms between attempts,
until it stops raising. Returns the block's value.
Split trace at the first event matching pattern, returning
{before, [match | after]} (Elixir's Enum.split_while/2 at the marker).
Split trace into segments, each ending with an event matching pattern;
a trailing run of non-matching events forms the final segment. Mirrors
?splitl_trace.
Split trace into segments, each starting with an event matching
pattern; a leading run of non-matching events forms the first segment.
Mirrors ?splitr_trace.
Start the snabbkaffe collector (idempotent).
Stop the snabbkaffe collector.
Like causality/3, but additionally forbids unmatched effect events.
strict_causality/3 with a guard expression over both events' bindings.
Assert the numbers in list are strictly increasing. Returns true or raises.
Subscribe to events matching predicate, returning {:ok, subscription}.
Emit a trace point of the given kind carrying data (a map).
tp/2 with a literal keyword-list of opts
Trace a span around a do block: emits a start event before and a
{:complete, return} event after, then returns the block's value.
Stop forwarding node's trace events, reverting it to recording locally.
Assert every event in trace is unique. Returns true or raises.
Subscribe to an event matching pattern, run the do block, then wait (up to
timeout) for the event. Returns {block_return, {:ok, event} | :timeout}.
Types
@type check_fun() :: (:snabbkaffe.trace() -> any()) | (term(), :snabbkaffe.trace() -> any())
A check_trace/2,3 check function. Passes unless it raises (its return value
is ignored, unlike Erlang snabbkaffe's :snabbkaffe.trace_spec/1, which
requires ok/true). Arity 1 receives the trace; arity 2 the run result
and the trace.
Field (or fields) to project out of each event; see projection/2.
Functions
Requires Snabbkaffex and imports its macros/helpers.
Options:
only: :trace— import only the discardable trace-point macros (tp/2,tp/3,tp_span/3,tp_span/4). Use this in productionlib/modules so you don't pull test-only helpers (stop/0,retry/3, ...) into their namespace.
With no options, imports everything (intended for test modules). In that case
Snabbkaffex also installs a @before_compile hook that warns if the module is
use ExUnit.Case, async: true, because the trace collector is a global
singleton and concurrent tests would corrupt each other's traces.
Fault scenario for inject_crash/2's scenario: option: crash on every
matching trace point. This is also inject_crash's default when no strategy
option is given.
Print an analysis of all statistics collected via push_stat/2.
Block until an event matching pattern is collected, or until timeout.
back_in_time (ms) lets the matcher also consider recently-collected events,
avoiding a race when the event fires before the call. Returns
{:ok, event} or :timeout.
block_until/3 waiting for n_events events matching pattern (mirrors
Erlang's ?block_until({Predicate, NEvents}, ...) form). Events already in
the collected trace count towards n_events, which makes it the right tool
for waiting on the Nth occurrence of a recurring event (e.g. a node becoming
:ready for the same view a second time, after churn). Returns
{:ok, [event]} or {:timeout, [partial]}.
Assert every effect event in trace was preceded by a matching cause event.
Pairs may be nested. Raises on a causality violation; otherwise returns true
if at least one pair was found, false if none.
causality/3 with a guard expression over both events' bindings.
Run run_fun, collect the resulting trace, then validate it with check_fun.
run_fun is a zero-arity function whose return value becomes the test result.
check_fun is a function of either arity 1 (trace) or arity 2
(result, trace). The check passes unless it raises: use ordinary ExUnit
assertions; the function's return value is ignored (unlike Erlang snabbkaffe,
which requires true/ok).
check_trace(
fn -> do_work() end,
fn result, trace ->
assert result == :ok
assert [_] = of_kind(trace, :work_done)
end
)
@spec check_trace(:snabbkaffe.run_config() | integer(), (-> term()), check_fun()) :: true
check_trace/2 with a snabbkaffe run config (a map, e.g. %{timeout: 100}) or
an integer statistics bucket.
Reset the collector and nemesis state (drops the buffered trace and any injected crashes/orderings) without stopping the collector.
@spec collect_trace(integer()) :: :snabbkaffe.trace()
Flush and return the collected trace, waiting timeout ms for silence first.
Dump trace to a file (as snabbkaffe does on failure) and return the path.
Strip timestamps from every event in trace (useful before comparing traces).
Find cause/effect pairs in trace matching cause_pattern and effect_pattern.
find_pairs/3 with an extra guard expression over both events' bindings.
Remove a crash injected by inject_crash/2 (given its reference).
Enforce an ordering between two classes of events: hold back every event
matching the :delay pattern until events matching the :until pattern have
been emitted.
Takes a literal keyword list so the direction is obvious at the call site — "delay X until Y":
:delay(required) — pattern for the events to hold back.:until(required) — pattern for the gate events that release them.:count— release only after this many:untilevents have been seen (default1). Events already in the collected trace count towards it.:when— a boolean guard over the variables bound in the:delayand:untilpatterns, used to tie the two together (e.g. by a shared id). Defaults to always matching.
Examples
# Hold worker :a's :store until worker :b's :miss has fired.
force_ordering(
delay: %{:"$kind" => :store, worker: :a},
until: %{:"$kind" => :miss, worker: :b}
)
# Tie the two events together by id, and wait for two gate events.
force_ordering(
delay: %{:"$kind" => :store, id: sid},
until: %{:"$kind" => :miss, id: mid},
count: 2,
when: sid == mid
)Wraps snabbkaffe's force_ordering (whose positional argument order differs).
Start forwarding trace events emitted on the remote node to this collector.
Used in multi-node tests so tp calls on node land in the local trace.
Return the raw statistics map collected so far.
Assert value is within deviation of expected. Returns true or raises.
Assert the numbers in list are non-decreasing. Returns true or raises.
Inject crashes at trace points matching pattern, returning a reference you
can later pass to fix_crash/1.
With no options the process crashes on every matching trace point. Pass at most one strategy option to shape when it crashes:
recover_after: n— crash the firstnmatches, then recoverrandom_crash: p— crash with probabilityp(a float in0.0..1.0)scenario: fun— any snabbkaffe fault scenario, for the less common cases (e.g.scenario: periodic_crash(10, 0.5, 0.0))
The reason: option sets the exit reason for the crashing process (defaults to
:notmyday).
inject_crash(%{:"$kind" => :write}) # crash every time
inject_crash(%{:"$kind" => :write}, reason: :disk_full) # ... with a reason
inject_crash(%{:"$kind" => :before_ack}, recover_after: 1)
inject_crash(%{:"$kind" => :flaky}, random_crash: 0.1)
inject_crash(%{:"$kind" => :wave}, scenario: periodic_crash(10, 0.5, 0.0))
Build a predicate fn event -> boolean end from an Elixir pattern.
This is the Elixir counterpart of snabbkaffe's ?match_event, used internally
by the pattern-taking macros and exposed for building snabbkaffe subscriptions
directly (:snabbkaffe.subscribe/1, etc.).
@spec of_domain(:snabbkaffe.trace(), [atom()]) :: :snabbkaffe.trace()
Keep only events in trace whose logger metadata domain equals domain.
@spec of_kind(:snabbkaffe.trace(), :snabbkaffe.kind() | [:snabbkaffe.kind()]) :: :snabbkaffe.trace()
Keep only events in trace whose :"$kind" is kind (or one of a list of kinds).
@spec of_node(:snabbkaffe.trace(), node()) :: :snabbkaffe.trace()
Keep only events in trace emitted on node.
The maximum nesting depth among a list of pairs (from find_pairs/3).
Fault scenario for inject_crash/2's scenario: option: crash periodically,
driven by the count of matching trace
points (not wall-clock time). Within each cycle of period matches the trace
point stays healthy for the first duty_cycle fraction and crashes for the
rest; phase (in radians, 0 to 2 * pi) shifts the cycle.
@spec projection(:snabbkaffe.trace(), fields()) :: list()
Project field (atom) or fields (list of atoms) out of each event in trace.
With a single atom, returns a list of values; with a list, a list of tuples.
@spec projection_complete(:snabbkaffe.trace(), fields(), [term()]) :: true
Assert every value in expected appears in the projection of fields over
trace (i.e. expected is a subset of what was traced). Returns true or
raises. The complement of projection_is_subset/3.
@spec projection_is_subset(:snabbkaffe.trace(), fields(), [term()]) :: true
Assert the projection of fields over trace contains no values outside
expected (i.e. what was traced is a subset of expected). Returns true
or raises.
Record a value for metric. With an extra leading argument, records a
{x, y} datapoint (push_stat(metric, x, y)). See analyze_statistics/0.
Record many datapoints for metric at once (see :snabbkaffe.push_stats/2,3).
Fault scenario: crash with the given probability (a float in 0.0..1.0).
Usually reached via inject_crash(pattern, random_crash: probability).
Wait for the events of a subscription returned by subscribe/1. Returns
{:ok, [event]} or {:timeout, [partial]}.
Fault scenario: crash the first n times a trace point matches, then recover.
Usually reached via inject_crash(pattern, recover_after: n).
Retry the do block up to n times, sleeping interval ms between attempts,
until it stops raising. Returns the block's value.
retry 10, 5 do
assert something_eventually_true()
end
Split trace at the first event matching pattern, returning
{before, [match | after]} (Elixir's Enum.split_while/2 at the marker).
Split trace into segments, each ending with an event matching pattern;
a trailing run of non-matching events forms the final segment. Mirrors
?splitl_trace.
E.g. splitting [a, b, M, c, M, d] on M gives [[a, b, M], [c, M], [d]].
Split trace into segments, each starting with an event matching
pattern; a leading run of non-matching events forms the first segment.
Mirrors ?splitr_trace.
E.g. splitting [a, b, M, c, M, d] on M gives [[a, b], [M, c], [M, d]].
@spec start_trace() :: :ok
Start the snabbkaffe collector (idempotent).
@spec stop() :: :ok
Stop the snabbkaffe collector.
Like causality/3, but additionally forbids unmatched effect events.
strict_causality/3 with a guard expression over both events' bindings.
Assert the numbers in list are strictly increasing. Returns true or raises.
Subscribe to events matching predicate, returning {:ok, subscription}.
Lower-level than block_until/2: pair with receive_events/1 to collect the
events later. predicate is a fn event -> boolean end — build one from a
pattern with match_event/1. Optional n_events (default 1), timeout, and
back_in_time mirror :snabbkaffe.subscribe/1..4.
Emit a trace point of the given kind carrying data (a map).
In :test this records an event via the snabbkaffe collector. Outside :test
the behaviour is controlled by opts (see tp/3); with no options data is
evaluated for its side effects and the result discarded, returning :ok
(mirroring snabbkaffe's ?tp/2).
tp/2 with a literal keyword-list of opts:
level: <atom>— set the event's severity. In:testit's the collected event's level; outside:testthe call degrades to a:loggercall at that level, so the event stays visible in production logs (mirrors?tp/3).ignore_side_effects: true— outside:testthe whole call becomes a bare:okanddatais not evaluated at all (mirrors?tp_ignore_side_effects_in_prod). Use when buildingdatais expensive or side-effecting and should cost nothing in production; the trade-off is thatdatamust be purely diagnostic. Mutually exclusive with:level(passing both raisesArgumentErrorat compile time)::levelkeeps the event in production logs, whereas this drops it entirely outside:test.
Examples:
tp(:got_event, %{event: e}, level: :warning)
tp(:snapshot, %{state: expensive_dump(s)}, ignore_side_effects: true)
Trace a span around a do block: emits a start event before and a
{:complete, return} event after, then returns the block's value.
The keyword list carrying the do: block also accepts the same options as
tp/3 (:level, :ignore_side_effects). Unlike the Erlang macro (which
expands DATA twice), data is evaluated exactly once. With
ignore_side_effects: true, outside :test the span reduces to just the
block and data is never evaluated.
tp_span :fetch, %{id: id} do
do_fetch(id)
end
tp_span :fetch, %{id: id}, level: :info do
do_fetch(id)
end
@spec unforward_trace(node()) :: :ok
Stop forwarding node's trace events, reverting it to recording locally.
A Snabbkaffex addition — snabbkaffe itself exposes no "unforward" call.
forward_trace/1 works by pointing node's trace-point function (the
:snabbkaffe_tp_fun persistent term) at :snabbkaffe.remote_tp/5, which RPCs
every event back to this collector; this resets it to the default
:snabbkaffe.local_tp/5, so node keeps its own trace instead.
The motivating case is netsplit tests: with forwarding left on, every tp/2
on the disconnected node does a synchronous RPC to the collector, which
auto-reconnects a node you deliberately Node.disconnect/1'd. Call this while
node is still reachable, before disconnecting; re-attach with
forward_trace/1 once reconnected.
Assert every event in trace is unique. Returns true or raises.
Subscribe to an event matching pattern, run the do block, then wait (up to
timeout) for the event. Returns {block_return, {:ok, event} | :timeout}.
The block is the async action; it runs before the wait even though it reads
last. Pass timeout: (ms, default :infinity) in the options alongside the
block.
wait_async_action %{"$kind": :work_done} do
GenServer.cast(pid, :go)
end
wait_async_action %{"$kind": :work_done}, timeout: 100 do
GenServer.cast(pid, :go)
end