Introduction to Snabbkaffe

• Snabbkaffe is a library that allows to test concurrent and distributed systems
• It does so by moving focus from states to effects
• Developers find bugs by looking at the logs, snabbkaffe does the same and automates the process
• Advanced modes of testing: fault and scheduling injection
• Efficiency: run test scenario once, verify multiple properties

• Snabbkaffe means ``instant coffee'' in Swedish
• There is no hidden meaning, the name was chosen randomly

Erlang partitions the state of the system between processes

• It eliminates some concurrency bugs and isolates failures
• But it makes the system harder to analyze
• More often than not it's impossible to inspect state of the process (sys:get_state)
• Often it's useless
• Tests that rely on the state usually need to wait for the system to stabilize, it can be slow, and they can't analyze the system in motion
• Asynchronous data processing patterns (e.g. job queues) are incredibly annoying to test using traditional methods

Move away from states and embrace events and their temporal relationships

1. Replace your regular logs with structured logs (the industry is moving towards structured logs anyway)
2. Include "snabbkaffe/include/trace.hrl" header to your module
3. Use ?tp or ?tp_span macros for logging (tp stands for Trace Point)
   • In the release build these macros will become regular logger messages
   • In the test build these macros will emit trace events

Forward traces from the remote node:

%% on the ct_master:
snabbkaffe:forward_trace(Node)

All features (incl. fault and scheduling injections) will work

An often asked question: why not using dbg:tracer or the like?

It was a conscious design choice:

• Traces obtained this way are tightly bound to the structure of the code. Refactoring the code or adding a new function argument would break the tests
• Debug traces are excessive, it would be hard to see the forest through the trees
• Log messages are typically placed in ``interesting'' places
  • Interesting for humans = interesting for tests

Every testcase is split in two stages:

It is possible to block run stage until a certain event occurs:

?block_until(#{ ?snk_kind  := message_acked
              , message_id := Id
              } when Id > 42,
             Timeout, BackInTime)

This macro will return immediately as soon as the event happens, so it's more efficient and less prone to flakiness than a sleep.

?block_until is fine, but it requires timeout tuning. What if the same event happened in the past?

?wait_async_action( send_async_request(Req)
                  , #{ ?snk_kind := request_handled
                     , request := Req
                     }
                 [, Timeout]
                  )

This macro doesn't have to look into the past.

It's not a problem to combine stateless PropER tests with snabbkaffe. ?check_trace macro can be used inside proper's ?FORALL macro.

Snabbkaffe provides some convenience macros that simplify trace-property-based testing:

trace_prop_test(Config) ->
  Prop = ?forall_trace(
            X, list(),
            begin
              %% Run stage:
              do_stuff(X)
            end,
            fun(Result, Trace) ->
                %% Check stage
                true
            end),
  ?run_prop(Config, Prop).

There are a few macros that are not directly related to trace-based testing, but often needed:

?strict_causality( #{?snk_kind := msg_received, id := _Id}
                 , #{?snk_kind := msg_processed, id := _Id}
                 , Trace
                 )

Return value:

• true if some matching events were found
• false if no events were found
• exception if causality is violated

Suppose we're testing a "base64 server":

?strict_causality( #{req := _Req}
                 , #{resp := _Resp}
                 , _Resp =:= base64:encode(_Req)
                 , Trace
                 )

Overall, it's the same as ?strict_causality, except it doesn't require each ``cause'' to have an ``effect''

?causality( #{?snk_kind := msg_received, id := _Id}
          , #{?snk_kind := msg_processed, id := _Id}
         [, Guard]
          , Trace
          )

There is a potential problem with ``causality'' macros:

1. Format of the event is changed in the code
2. Match expressions in causality stop matching the events
3. Tests still pass, even though they didn't find any events

Solution:

Always wrap ?causality and ?strict_causality in ?assert, unless there are legit situations when no events can be produced in the test

?find_pairs(Strict, MatchCause, MatchEffect [, Guard] , Trace)

1. It returns a list of {pair, Cause, Effect} or {singleton, Cause}
2. When Strict is true this macro also checks that effects don't occur before causes (much like ?causality)

Often it is useful to split traces to parts before and after some event (for example, restart)

There are a variety of macros for this:

• Taking fault-tolerance seriously is one of the selling points of Erlang. Organizing processes in supervisor trees is used widely, but not often tested
• Tuning supervisor trees is an art
• Snabbkaffe wants to turn it into a chore
• It does so by injecting deliberate faults into the system

Any tracepoint can be used to inject errors into the system

?inject_crash( #{?snk_meta := #{domain := [ekka, rlog|_]}}
             , snabbkaffe_nemesis:random_crash(0.1)
             )

• First argument: event matching expression
• Second argument: fault scenario

• Sometimes it is necessary to test a certain process scheduling
• Imagine working on a bugfix using TDD-style
• For example, normally effect foo occurs after effect bar, and everything works. But in rare cases the opposite happens, and the bug occurs
• Snabbkaffe can manipulate process schedulings to some extend:

%% run stage...
?force_ordering(#{?snk_kind := bar}, #{?snk_kind := foo})

(It also supports guards)

• This usecase is a secondary, and quite rudimentary. Don't expect much
• It lacks many features of proper benchmarking libraries, such as
  • Warmup
  • Advanced statistical analysis, e.g. outlier detection

push_stats function also works together with ?find_pairs macro:

Pairs = ?find_pairs( #{ ?snk_span := start
                      , ?snk_kind := foo
                      , pid       := _Pid
                      }
                   , #{ ?snk_span := {complete, _}
                      , ?snk_kind := foo
                      , pid       := _Pid
                      }
                   ),
snabbkaffe:push_stats(metric_name, [X,] Pairs)

Use the following function in the end of check stage:

snabbkaffe:analyze_statistics()

It will print the results in the console:

Mean scalar_metric_name: 10.0

Statisitics of metric_name
100.479087 ^                                       *
           |                         *
           |                   *
           |
           |            *
           |      *
         0 +---------------------------------------->
           0                                     1100

https://github.com/kafka4beam/snabbkaffe

The library is being actively developed.

Suggestions, bug reports and patches are welcome!