Flame graphs

It can be nice to visualize where time is spent when executing code.

We have added Scott Fritchie's fork of eflame to help trace and generate flame graphs.

Important: as far as I can tell, you can only have one trace going on at any given time. Be aware!

kz_tracers

The kz_tracers module (in core/whistle_apps) starts the trace. Currently it just traces the supplied pid() with an optional time to trace (default 100s but this is way too long for most requests).

Tracing Crossbar requests

You can enable a trace for a crossbar request by adding a header x-trace-request: true.

You will also need to enable tracing as a system config: sup whapps_config set_default crossbar allow_tracing true This has performance implications so I wouldn't leave this enabled on a production environment.

Now try your cURL request:

curl -v -X PUT \
    -H "content-type:application/json" \
    -H "x-trace-request:true" \
    -d '{"data":{"credentials":"{HASH}","account_name":"master"}}' \
    http://localhost:8000/v2/user_auth

In your Erlang VM (if you're running in interactive mode), you should see some logs:

started trace for <0.10699.2> in <0.10700.2>
Tracer <0.10667.2>
self() <0.10700.2>
Starting tracer results: {v_global_and_local_calls,
                             {ok,[{matched,
                                      'whistle_apps@localhost.localdomain',
                                      24456},
                                  {saved,1}]}}
trace for <0.10699.2> done
trace formatted to /tmp/eflame.trace.out
<0.10699.2> Hello, world, I'm <0.10713.2> and I'm running....
<0.10706.2>

Writing to /tmp/eflame.trace.out for 3 processes... finished!

Once its finished, you need to run a script to create the svg file:

kazoo/deps/eflame$ cat /tmp/eflame.trace.out | ./flamegraph.riak-color.pl > /tmp/eflame.svg

Now load that into your browser and click around!

You can also remove the SLEEP time:

kazoo/deps/eflame$ cat /tmp/eflame.trace.out | grep -v 'SLEEP ' | ./flamegraph.riak-color.pl > /tmp/eflame.svg

Issues

Sometimes nothing gets traced and no svg can be generated. You might see this in your VM:

started trace for <0.10645.2> in <0.10646.2>
Tracer <0.4131.0>
self() <0.10646.2>
Starting tracer results: {v_global_and_local_calls,
                             {ok,[{matched,
                                      'whistle_apps@localhost.localdomain',
                                      24456},
                                  {saved,1}]}}
trace for <0.10645.2> done
trace formatted to /tmp/eflame.trace.out


Writing to /tmp/eflame.trace.out for 0 processes... finished!

I haven't bothered looking into this yet, as rerunning the request to do another trace usually gets some output. I think it depends on how fast the request is processed?

Edit this page here