Kazoo System Tracing

It is possible to create Erlang traces and write them to file(s) so you can get an idea about what is happening in the VM. Lager provides this tracing functionality and kz_data_tracing exposes the wrapper.

Start a trace

Creating a system trace needs to be surgical; too many events could overwhelm the VM and impact performance. Especially if tracing a production system, use filters to limit the scope of events traced.

Starting a trace is straight-forward:

1> {'ok', Trace1} = kz_data_tracing:trace_file().
{'ok', Ref1}
2> {'ok', Trace2} = kz_data_tracing:trace_file(Filters).
{'ok', Ref2}
3> {'ok', Trace3} = kz_data_tracing:trace_file(Filters, Filename).
{'ok', Ref3}
4> {'ok', Trace4} = kz_data_tracing:trace_file(Fitlers, Filename, Format).
{'ok', Ref4}

SUP-provided examples:

sup kazoo_data_maintenance trace_module Module
sup kazoo_data_maintenance trace_function Function
sup kazoo_data_maintenance trace_function Module Function
sup kazoo_data_maintenance trace_pid 'X.Y.Z'

Filters

Filters are 2-tuples that contain the patterns used on events to see if they meet the necessary criteria.

  • `{'module', Module}`: Filter for calls to `Module`
  • `{'function', Function}`: Filter for calls to `Function` When combined with `{'module', Module}`, just trace that Module:Function combo
  • `{'pid', Pid}`: Fitler for calls by `Pid`
  • Custom metadata
    • `lager:warning([{request, RequestID}], "the passwords didn't match for ~s", [UserId])` would allow a filter of `{'request', RequestID}`
    • You can also associate metadata with a `pid()`: `lager:md([{'zone', 'west'}])`

You can also use `'*'` in the second element to match all of that class of filter.

For example, `[{'module', 'kz_json'}, {'function', '*'}]` would filter all calls to the `kz_json` module.

Filename

Specify the filename for where to write the trace results.

Format

You can also supply a custom formatter to be used when writing the log line (uses the Kazoo standard format otherwise).

Defaults

  • Filters: `[{'function', '*'}]`
  • Filename: `/tmp/{32_char_hex}.log`
  • Format: -define(DEFAULT_TRACE_OUTPUT_FORMAT, ['time'," [",'severity',"] |", 'from_app', "|", {'callid', }, "|", 'mod', ":" , 'func', ":", 'line', " (",'pid', ") ", 'message', "\n"]).

Stopping a trace

Assuming you bound the second element in the resulting tuple:

1> {'ok', Ref} = kz_data_tracing:trace_file().
{'ok', Ref}
2> ...Do some things...or not
'maybe'
3> kz_data_tracing:stop_trace(Ref).
'ok'

Edit this page here