Skip to content

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(Filters, 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}`: Filter 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'