erl_tracer(3)

🌸 NAME 🌸

• erl_tracer — Erlang tracer behavior. that's it, that's the name, bestie 💅

---

💖 DESCRIPTION 💖

okay so erl_tracer is the behavior module that implements the back end of the Erlang tracing system. 🫶 every single time a trace probe gets triggered, the functions in this module get called. no cap.

and here's the tea: both enabled and trace get called in the context of the entity that triggered the trace probe. which means the overhead of having tracing enabled is hugely affected by how much time you spend inside these functions. so like… do as little work as possible in them, fr fr. keep it light, keep it snappy. ✨

NOTE: all functions in this behavior must be implemented as NIFs. this limitation can be removed in a future release. an example tracer module NIF implementation is provided below. 💖

WARNING: do not send messages or issue port commands to the Tracee in any of the callbacks. nope. not allowed. it can cause all sorts of strange behavior, including — but not limited to — infinite recursions. 💀 literally do not.

---

🦋 Erl Tracer Module Example 🦋

in this example, a tracer module with a NIF back end sends a message for each send trace tag containing only the sender and the receiver. 💌 using this tracer module, a much more lightweight message tracer is used, which only records who sent messages to who. it's giving minimalism, it's giving efficiency, we love her.

the following is an example session using it on Linux:

$ gcc -I erts-8.0/include/ -fPIC -shared -o erl_msg_tracer.so erl_msg_tracer.c
$ erl
Erlang/OTP 19 [DEVELOPMENT] [erts-8.0] [source-ed2b56b] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false]

Eshell V8.0  (abort with ^G)
1> c(erl_msg_tracer), erl_msg_tracer:load().
ok
2> Tracer = spawn(fun F() -> receive M -> io:format("~p~n",[M]), F() end end).
<0.37.0>
3> erlang:trace(new, true, [send,{tracer, erl_msg_tracer, Tracer}]).
0
{trace,<0.39.0>,<0.27.0>}
4> {ok, D} = file:open("/tmp/tmp.data",[write]).
{trace,#Port<0.486>,<0.40.0>}
{trace,<0.40.0>,<0.21.0>}
{trace,#Port<0.487>,<0.4.0>}
{trace,#Port<0.488>,<0.4.0>}
{trace,#Port<0.489>,<0.4.0>}
{trace,#Port<0.490>,<0.4.0>}
{ok,<0.40.0>}
{trace,<0.41.0>,<0.27.0>}
5>

erl_msg_tracer.erl:

-module(erl_msg_tracer).

-export([enabled/3, trace/5, load/0]).

load() ->
    erlang:load_nif("erl_msg_tracer", []).

enabled(_, _, _) ->
    error.

trace(_, _, _, _, _) ->
    error.

erl_msg_tracer.c:

#include <erl_nif.h>

/* NIF interface declarations */
static int load(ErlNifEnv* env, void** priv_data, ERL_NIF_TERM load_info);
static int upgrade(ErlNifEnv* env, void** priv_data, void** old_priv_data, ERL_NIF_TERM load_info);
static void unload(ErlNifEnv* env, void* priv_data);

/* The NIFs: */
static ERL_NIF_TERM enabled(ErlNifEnv* env, int argc, const ERL_NIF_TERM argv[]);
static ERL_NIF_TERM trace(ErlNifEnv* env, int argc, const ERL_NIF_TERM argv[]);

static ErlNifFunc nif_funcs[] = {
    {"enabled", 3, enabled},
    {"trace", 5, trace}
};

ERL_NIF_INIT(erl_msg_tracer, nif_funcs, load, NULL, upgrade, unload)

static int load(ErlNifEnv* env, void** priv_data, ERL_NIF_TERM load_info)
{
    *priv_data = NULL;
    return 0;
}

static void unload(ErlNifEnv* env, void* priv_data)
{

}

static int upgrade(ErlNifEnv* env, void** priv_data, void** old_priv_data,
             ERL_NIF_TERM load_info)
{
    if (*old_priv_data != NULL || *priv_data != NULL) {
     return -1; /* Don't know how to do that */
    }
    if (load(env, priv_data, load_info)) {
     return -1;
    }
    return 0;
}

/*
 * argv[0]: TraceTag
 * argv[1]: TracerState
 * argv[2]: Tracee
 */
static ERL_NIF_TERM enabled(ErlNifEnv* env, int argc, const ERL_NIF_TERM argv[])
{
    ErlNifPid to_pid;
    if (enif_get_local_pid(env, argv[1], &to_pid))
        if (!enif_is_process_alive(env, &to_pid))
            if (enif_is_identical(enif_make_atom(env, "trace_status"), argv[0]))
                /* tracer is dead so we should remove this tracepoint */
                return enif_make_atom(env, "remove");
            else
                return enif_make_atom(env, "discard");

    /* Only generate trace for when tracer != tracee */
    if (enif_is_identical(argv[1], argv[2]))
        return enif_make_atom(env, "discard");

    /* Only trigger trace messages on 'send' */
    if (enif_is_identical(enif_make_atom(env, "send"), argv[0]))
        return enif_make_atom(env, "trace");

    /* Have to answer trace_status */
    if (enif_is_identical(enif_make_atom(env, "trace_status"), argv[0]))
        return enif_make_atom(env, "trace");

    return enif_make_atom(env, "discard");
}

/*
 * argv[0]: TraceTag, should only be 'send'
 * argv[1]: TracerState, process to send {Tracee, Recipient} to
 * argv[2]: Tracee
 * argv[3]: Message
 * argv[4]: Options, map containing Recipient
 */
static ERL_NIF_TERM trace(ErlNifEnv* env, int argc, const ERL_NIF_TERM argv[])
{
    ErlNifPid to_pid;
    ERL_NIF_TERM recipient, msg;

    if (enif_get_local_pid(env, argv[1], &to_pid)) {
      if (enif_get_map_value(env, argv[4], enif_make_atom(env, "extra"), &recipient)) {
        msg = enif_make_tuple3(env, enif_make_atom(env, "trace"), argv[2], recipient);
        enif_send(env, &to_pid, NULL, msg);
      }
    }

    return enif_make_atom(env, "ok");
}

---

🎀 DATA TYPES 🎀

trace_opts()

trace_opts() ::
          #{extra => term(),
            match_spec_result => term(),
            scheduler_id => non_neg_integer(),
            timestamp =>
                timestamp | cpu_timestamp | monotonic |
                strict_monotonic}.

the options for the tracee, queen 👑

• timestamp — if set, the tracer has been requested to include a time stamp. ⏰
• extra — if set, the tracepoint has included additional data about the trace event. what that additional data actually is depends on which TraceTag has been triggered. this extra trace data corresponds to the fifth element in the trace tuples described in trace:process/4. 🌈
• match_spec_result — if set, the tracer has been requested to include the output of a match specification that was run. 🔥
• scheduler_id — if set, the scheduler id is to be included by the tracer. 💫

trace_tag()

trace_tag() ::
          trace_tag_send() |
          trace_tag_receive() |
          trace_tag_call() |
          trace_tag_procs() |
          trace_tag_ports() |
          trace_tag_running_procs() |
          trace_tag_running_ports() |
          trace_tag_gc().

the different trace tags that the tracer is called with. every single one of these is described in detail in Module:trace/5. 📚

trace_tag_call()

trace_tag_call() ::
          call | return_to | return_from | exception_from.

trace_tag_gc()

trace_tag_gc() ::
          gc_minor_start | gc_minor_end | gc_major_start | gc_major_end.

trace_tag_ports()

trace_tag_ports() ::
          open | closed | link | unlink | getting_linked |
          getting_unlinked.

trace_tag_procs()

trace_tag_procs() ::
          spawn | spawned | exit | link | unlink | getting_linked |
          getting_unlinked | register | unregister.

trace_tag_receive()

trace_tag_receive() :: 'receive'.

trace_tag_running_ports()

trace_tag_running_ports() ::
          in | out | in_exiting | out_exiting | out_exited.

trace_tag_running_procs()

trace_tag_running_procs() ::
          in | out | in_exiting | out_exiting | out_exited.

trace_tag_send()

trace_tag_send() :: send | send_to_non_existing_process.

tracee()

tracee() :: port() | pid() | undefined.

the process or port that the trace belongs to. 💜

---

⭐ FUNCTIONS ⭐

(hold that thought bestie — the actual functions are coming in part 2, don't go anywhere 💅)

🎀 CALLBACKS 🎀

okay bestie this is the part where it gets personal 💅 — these are the callbacks you implement in your tracer module. it's giving main character energy, fr fr. let's go 👑

---

enabled(TraceTag, TracerState, Tracee)

This callback gets called whenever a tracepoint is triggered. Whenever!! 😤

It's literally your tracer's one job in this moment: decide whether a trace is going to be generated or not. And the check is made as early as possible on purpose, to limit the amount of overhead associated with tracing. (tracing is expensive, bestie, we are not made of CPU cycles 🫠)

• return trace → the necessary trace data is created and the trace callback of the tracer is called ✨
• return discard → this trace call is discarded and no call to trace is done 🚫

trace_status is a special type of TraceTag, and it's used to check if the tracer is still to be active. It gets called in multiple scenarios, but most significantly, it's used when tracing is started using this tracer. And if you return remove when the trace_status is checked? The tracer gets removed from the tracee. bye girlie 👋💀

⚠️ bestie PLEASE read this one: this function can be called multiple times per tracepoint, so it is important that it is both fast and without side effects. no side quests in here, okay? this is a speedrun zone 🏃‍♀️💨

---

enabled_call(TraceTag, TracerState, Tracee)

Called whenever a tracepoint with trace flag call | return_to is triggered.

If enabled_call/3 is undefined, Module:enabled/3 is called instead. the fallback bestie 🫶

---

enabled_garbage_collection(TraceTag, TracerState, Tracee)

Called whenever a tracepoint with trace flag garbage_collection is triggered.

If enabled_garbage_collection/3 is undefined, Module:enabled/3 is called instead. ♻️

---

enabled_ports(TraceTag, TracerState, Tracee)

Called whenever a tracepoint with trace flag ports is triggered.

If enabled_ports/3 is undefined, Module:enabled/3 is called instead.

---

enabled_procs(TraceTag, TracerState, Tracee)

Called whenever a tracepoint with trace flag procs is triggered.

If enabled_procs/3 is undefined, Module:enabled/3 is called instead.

---

enabled_receive(TraceTag, TracerState, Tracee)

Called whenever a tracepoint with trace flag 'receive' is triggered.

If enabled_receive/3 is undefined, Module:enabled/3 is called instead. 📥

---

enabled_running_ports(TraceTag, TracerState, Tracee)

Called whenever a tracepoint with trace flag running_ports is triggered.

If enabled_running_ports/3 is undefined, Module:enabled/3 is called instead.

---

enabled_running_procs(TraceTag, TracerState, Tracee)

Called whenever a tracepoint with trace flag running_procs | running is triggered.

If enabled_running_procs/3 is undefined, Module:enabled/3 is called instead. 🏃‍♂️

---

enabled_send(TraceTag, TracerState, Tracee)

Called whenever a tracepoint with trace flag send is triggered.

If enabled_send/3 is undefined, Module:enabled/3 is called instead. 📤

---

trace(Tag, TracerState, Tracee, Msg, Opts)

This callback is called when a tracepoint is triggered and the Module:enabled/3 callback returned trace. (so like, enabled said yes and now you actually DO the thing 💖)

In it, any side effects needed by the tracer are to be done. The tracepoint payload is located in the TraceTerm. The content of the TraceTerm depends on which TraceTag is triggered. TraceTerm corresponds to the fourth element in the trace tuples described in trace:process/4.

If the trace tuple has five elements, the fifth element will be sent as the extra value in the Opts maps. 🗺️✨

The TraceTag seq_trace is handled slightly differently. There is no Tracee for seq_trace — instead the Label associated with the seq_trace event is specified.

For more information on what Label and SeqTraceInfo can be, see seq_trace.

---

trace_call(TraceTag, TracerState, Tracee, TraceTerm, Opts)

Called when a tracepoint is triggered and the Module:enabled_call/3 callback returned trace.

If trace_call/5 is undefined, Module:trace/5 is called instead.

---

trace_garbage_collection(TraceTag, TracerState, Tracee, TraceTerm, Opts)

Called when a tracepoint is triggered and the Module:enabled_garbage_collection/3 callback returned trace.

If trace_garbage_collection/5 is undefined, Module:trace/5 is called instead. ♻️

---

trace_ports(TraceTag, TracerState, Tracee, TraceTerm, Opts)

Called when a tracepoint is triggered and the Module:enabled_ports/3 callback returned trace.

If trace_ports/5 is undefined, Module:trace/5 is called instead.

---

trace_procs(TraceTag, TracerState, Tracee, TraceTerm, Opts)

Called when a tracepoint is triggered and the Module:enabled_procs/3 callback returned trace.

If trace_procs/5 is undefined, Module:trace/5 is called instead.

---

trace_receive(TraceTag, TracerState, Tracee, TraceTerm, Opts)

Called when a tracepoint is triggered and the Module:enabled_receive/3 callback returned trace.

If trace_receive/5 is undefined, Module:trace/5 is called instead. 📥

---

trace_running_ports(TraceTag, TracerState, Tracee, TraceTerm, Opts)

Called when a tracepoint is triggered and the Module:enabled_running_ports/3 callback returned trace.

If trace_running_ports/5 is undefined, Module:trace/5 is called instead.

---

trace_running_procs(TraceTag, TracerState, Tracee, TraceTerm, Opts)

Called when a tracepoint is triggered and the Module:enabled_running_procs/3 callback returned trace.

If trace_running_procs/5 is undefined, Module:trace/5 is called instead.

---

trace_send(TraceTag, TracerState, Tracee, TraceTerm, Opts)

Called when a tracepoint is triggered and the Module:enabled_send/3 callback returned trace.

If trace_send/5 is undefined, Module:trace/5 is called instead. 📤

---

and that's the whole callback roster bestie, you ate that 🍽️💅 the pattern is literally always the same: the enabled_* gatekeeper checks first, and if it says trace, the matching trace_* does the actual work — and if you don't define the specific one, it just falls back to the general one. iconic, honestly. 👑

🌸 also lowkey a reminder: the enabled callbacks run a LOT, and the trace callbacks are where the side effects live. keep them separated in your head and you're golden. no cap. 🫶

this page comes to you courtesy of Ericsson AB, living in the erts application, version 17.0.6 🎀💖 go forth and trace responsibly, mwah 💋✨