## Introduction

The Linux Trace Toolkit: next generation is an open source system software package for correlated tracing of the Linux kernel, user applications and libraries.

For more information, please visit http://lttng.org

## Building Erlang/OTP with LTTng support

Configure and build Erlang with LTTng support:

For LTTng to work properly with Erlang/OTP you need the following packages installed:

LTTng-tools: a command line interface to control tracing sessions.

LTTng-UST: user space tracing library.

On Ubuntu this can be installed via aptitude:

`$ sudo aptitude install lttng-tools liblttng-ust-dev`

See Installing LTTng for more information on how to install LTTng on your system.

After LTTng is properly installed on the system Erlang/OTP can be built with LTTng support.

`$ ./configure --with-dynamic-trace=lttng $ make`

## Dyntrace Tracepoints

All tracepoints are in the domain of org_erlang_dyntrace

All Erlang types are the string equivalent in LTTng.

process_spawn

pid : string :: Process ID. Ex. "<0.131.0>" parent : string :: Process ID. Ex. "<0.131.0>" entry : string :: Code Location. Ex. "lists:sort/1"

Available through erlang:trace/3 with trace flag procs and {tracer,dyntrace,[]} as tracer module.

Example:

`process_spawn: { cpu_id = 3 }, { pid = "<0.131.0>", parent = "<0.130.0>", entry = "erlang:apply/2" }`

process_link

to : string :: Process ID or Port ID. Ex. "<0.131.0>" from : string :: Process ID or Port ID. Ex. "<0.131.0>" type : string :: "link" | "unlink"

Available through erlang:trace/3 with trace flag procs and {tracer,dyntrace,[]} as tracer module.

Example:

`process_link: { cpu_id = 3 }, { from = "<0.130.0>", to = "<0.131.0>", type = "link" }`

process_exit

pid : string :: Process ID. Ex. "<0.131.0>" reason : string :: Exit reason. Ex. "normal"

Available through erlang:trace/3 with trace flag procs and {tracer,dyntrace,[]} as tracer module.

Example:

`process_exit: { cpu_id = 3 }, { pid = "<0.130.0>", reason = "normal" }`

process_register

pid : string :: Process ID. Ex. "<0.131.0>" name : string :: Registered name. Ex. "logger" type : string :: "register" | "unregister"

Example:

`process_register: { cpu_id = 0 }, { pid = "<0.128.0>", name = "dyntrace_lttng_SUITE" type = "register" }`

process_scheduled

pid : string :: Process ID. Ex. "<0.131.0>" entry : string :: Code Location. Ex. "lists:sort/1" type : string :: "in" | "out" | "in_exiting" | "out_exiting" | "out_exited"

Available through erlang:trace/3 with trace flag running and {tracer,dyntrace,[]} as tracer module.

Example:

`process_scheduled: { cpu_id = 0 }, { pid = "<0.136.0>", entry = "erlang:apply/2", type = "in" }`

port_open

pid : string :: Process ID. Ex. "<0.131.0>" driver : string :: Driver name. Ex. "tcp_inet" port : string :: Port ID. Ex. "#Port<0.1031>"

Available through erlang:trace/3 with trace flag ports and {tracer,dyntrace,[]} as tracer module.

Example:

`port_open: { cpu_id = 5 }, { pid = "<0.131.0>", driver = "'/bin/sh -s unix:cmd'", port = "#Port<0.1887>" }`

port_exit

port : string :: Port ID. Ex. "#Port<0.1031>" reason : string :: Exit reason. Ex. "normal"

Available through erlang:trace/3 with trace flag ports and {tracer,dyntrace,[]} as tracer module.

Example:

`port_exit: { cpu_id = 5 }, { port = "#Port<0.1887>", reason = "normal" }`

port_link

to : string :: Process ID. Ex. "<0.131.0>" from : string :: Process ID. Ex. "<0.131.0>" type : string :: "link" | "unlink"

Available through erlang:trace/3 with trace flag ports and {tracer,dyntrace,[]} as tracer module.

Example:

`port_link: { cpu_id = 5 }, { from = "#Port<0.1887>", to = "<0.131.0>", type = "unlink" }`

port_scheduled

Available through erlang:trace/3 with trace flag running and {tracer,dyntrace,[]} as tracer module.

port : string :: Port ID. Ex. "#Port<0.1031>" entry : string :: Callback. Ex. "open" type : string :: "in" | "out" | "in_exiting" | "out_exiting" | "out_exited"

Example:

`port_scheduled: { cpu_id = 5 }, { pid = "#Port<0.1905>", entry = "close", type = "out" }`

Available through erlang:trace/3 with trace flag running and {tracer,dyntrace,[]} as tracer module.

function_call

pid : string :: Process ID. Ex. "<0.131.0>" entry : string :: Code Location. Ex. "lists:sort/1" depth : integer :: Stack depth. Ex. 0

Available through erlang:trace/3 with trace flag call and {tracer,dyntrace,[]} as tracer module.

Example:

`function_call: { cpu_id = 5 }, { pid = "<0.145.0>", entry = "dyntrace_lttng_SUITE:'-t_call/1-fun-1-'/0", depth = 0 }`

function_return

pid : string :: Process ID. Ex. "<0.131.0>" entry : string :: Code Location. Ex. "lists:sort/1" depth : integer :: Stack depth. Ex. 0

Available through erlang:trace/3 with trace flag call or return_to and {tracer,dyntrace,[]} as tracer module.

Example:

`function_return: { cpu_id = 5 }, { pid = "<0.145.0>", entry = "dyntrace_lttng_SUITE:waiter/0", depth = 0 }`

function_exception

pid : string :: Process ID. Ex. "<0.131.0>" entry : string :: Code Location. Ex. "lists:sort/1" class : string :: Error reason. Ex. "error"

Available through erlang:trace/3 with trace flag call and {tracer,dyntrace,[]} as tracer module.

Example:

`function_exception: { cpu_id = 5 }, { pid = "<0.144.0>", entry = "t:call_exc/1", class = "error" }`

message_send

from : string :: Process ID or Port ID. Ex. "<0.131.0>" to : string :: Process ID or Port ID. Ex. "<0.131.0>" message : string :: Message sent. Ex. "{<0.162.0>,ok}"

Available through erlang:trace/3 with trace flag send and {tracer,dyntrace,[]} as tracer module.

Example:

`message_send: { cpu_id = 3 }, { from = "#Port<0.1938>", to = "<0.160.0>", message = "{#Port<0.1938>,eof}" }`

message_receive

to : string :: Process ID or Port ID. Ex. "<0.131.0>" message : string :: Message received. Ex. "{<0.162.0>,ok}"

Available through erlang:trace/3 with trace flag 'receive' and {tracer,dyntrace,[]} as tracer module.

Example:

`message_receive: { cpu_id = 7 }, { to = "<0.167.0>", message = "{<0.165.0>,ok}" }`

gc_minor_start

pid : string :: Process ID. Ex. "<0.131.0>" need : integer :: Heap need. Ex. 2 heap : integer :: Young heap word size. Ex. 233 old_heap : integer :: Old heap word size. Ex. 233

Available through erlang:trace/3 with trace flag garbage_collection and {tracer,dyntrace,[]} as tracer module.

Example:

`gc_minor_start: { cpu_id = 0 }, { pid = "<0.172.0>", need = 0, heap = 610, old_heap = 0 }`

gc_minor_end

pid : string :: Process ID. Ex. "<0.131.0>" reclaimed : integer :: Heap reclaimed. Ex. 2 heap : integer :: Young heap word size. Ex. 233 old_heap : integer :: Old heap word size. Ex. 233

Available through erlang:trace/3 with trace flag garbage_collection and {tracer,dyntrace,[]} as tracer module.

Example:

`gc_minor_end: { cpu_id = 0 }, { pid = "<0.172.0>", reclaimed = 120, heap = 1598, old_heap = 1598 }`

gc_major_start

pid : string :: Process ID. Ex. "<0.131.0>" need : integer :: Heap need. Ex. 2 heap : integer :: Young heap word size. Ex. 233 old_heap : integer :: Old heap word size. Ex. 233

Available through erlang:trace/3 with trace flag garbage_collection and {tracer,dyntrace,[]} as tracer module.

Example:

`gc_major_start: { cpu_id = 0 }, { pid = "<0.172.0>", need = 8, heap = 2586, old_heap = 1598 }`

gc_major_end

pid : string :: Process ID. Ex. "<0.131.0>" reclaimed : integer :: Heap reclaimed. Ex. 2 heap : integer :: Young heap word size. Ex. 233 old_heap : integer :: Old heap word size. Ex. 233

Available through erlang:trace/3 with trace flag garbage_collection and {tracer,dyntrace,[]} as tracer module.

Example:

`gc_major_end: { cpu_id = 0 }, { pid = "<0.172.0>", reclaimed = 240, heap = 4185, old_heap = 0 }`

## BEAM Tracepoints

All tracepoints are in the domain of org_erlang_otp

All Erlang types are the string equivalent in LTTng.

driver_init

driver : string :: Driver name. Ex. "tcp_inet" major : integer :: Major version. Ex. 3 minor : integer :: Minor version. Ex. 1 flags : integer :: Flags. Ex. 1

Example:

`driver_init: { cpu_id = 2 }, { driver = "caller_drv", major = 3, minor = 3, flags = 1 }`

driver_start

pid : string :: Process ID. Ex. "<0.131.0>" driver : string :: Driver name. Ex. "tcp_inet" port : string :: Port ID. Ex. "#Port<0.1031>"

Example:

`driver_start: { cpu_id = 2 }, { pid = "<0.198.0>", driver = "caller_drv", port = "#Port<0.3676>" }`

driver_output

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet" bytes : integer :: Size of data returned. Ex. 82

Example:

`driver_output: { cpu_id = 2 }, { pid = "<0.198.0>", port = "#Port<0.3677>", driver = "/bin/sh -s unix:cmd", bytes = 36 }`

driver_outputv

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet" bytes : integer :: Size of data returned. Ex. 82

Example:

`driver_outputv: { cpu_id = 5 }, { pid = "<0.194.0>", port = "#Port<0.3663>", driver = "tcp_inet", bytes = 3 }`

driver_ready_input

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet"

Example:

`driver_ready_input: { cpu_id = 5 }, { pid = "<0.189.0>", port = "#Port<0.3637>", driver = "inet_gethost 4 " }`

driver_ready_output

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet"

Example:

`driver_ready_output: { cpu_id = 5 }, { pid = "<0.194.0>", port = "#Port<0.3663>", driver = "tcp_inet" }`

driver_timeout

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet"

Example:

`driver_timeout: { cpu_id = 5 }, { pid = "<0.196.0>", port = "#Port<0.3664>", driver = "tcp_inet" }`

driver_stop_select

driver : string :: Driver name. Ex. "tcp_inet"

Example:

`driver_stop_select: { cpu_id = 5 }, { driver = "unknown" }`

driver_flush

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet"

Example:

`driver_flush: { cpu_id = 7 }, { pid = "<0.204.0>", port = "#Port<0.3686>", driver = "tcp_inet" }`

driver_stop

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet"

Example:

`driver_stop: { cpu_id = 5 }, { pid = "[]", port = "#Port<0.3673>", driver = "tcp_inet" }`

driver_process_exit

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet"

driver_ready_async

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet"

Example:

`driver_ready_async: { cpu_id = 3 }, { pid = "<0.181.0>", port = "#Port<0.3622>", driver = "tcp_inet" }`

driver_call

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet" command : integer :: Command integer. Ex. 1 bytes : integer :: Size of data returned. Ex. 82

Example:

`driver_call: { cpu_id = 2 }, { pid = "<0.202.0>", port = "#Port<0.3676>", driver = "caller_drv", command = 0, bytes = 2 }`

driver_control

pid : string :: Process ID. Ex. "<0.131.0>" port : string :: Port ID. Ex. "#Port<0.1031>" driver : string :: Driver name. Ex. "tcp_inet" command : integer :: Command integer. Ex. 1 bytes : integer :: Size of data returned. Ex. 82

Example:

`driver_control: { cpu_id = 3 }, { pid = "<0.32767.8191>", port = "#Port<0.0>", driver = "forker", command = 83, bytes = 32 }`

carrier_create

type : string :: Carrier type. Ex. "ets_alloc" instance : integer :: Allocator instance. Ex. 1 size : integer :: Carrier size. Ex. 262144 mbc_carriers : integer :: Number of multiblock carriers in instance. Ex. 3 mbc_carriers_size : integer :: Total size of multiblock blocks carriers in instance. Ex. 1343488 mbc_blocks : integer :: Number of multiblock blocks in instance. Ex. 122 mbc_blocks_size : integer :: Total size of all multiblock blocks in instance. Ex. 285296 sbc_carriers : integer :: Number of singleblock carriers in instance. Ex. 1 sbc_carriers_size : integer :: Total size of singleblock blocks carriers in instance. Ex. 1343488 sbc_blocks : integer :: Number of singleblocks in instance. Ex. 1 sbc_blocks_size : integer :: Total size of all singleblock blocks in instance. Ex. 285296

Example:

`carrier_create: { cpu_id = 2 }, { type = "ets_alloc", instance = 7, size = 2097152, mbc_carriers = 4, mbc_carriers_size = 3440640, mbc_blocks = 526, mbc_blocks_size = 1278576, sbc_carriers = 0, sbc_carriers_size = 0, sbc_blocks = 0, sbc_blocks_size = 0 }`

carrier_destroy

type : string :: Carrier type. Ex. "ets_alloc" instance : integer :: Allocator instance. Ex. 1 size : integer :: Carrier size. Ex. 262144 mbc_carriers : integer :: Number of multiblock carriers in instance. Ex. 3 mbc_carriers_size : integer :: Total size of multiblock blocks carriers in instance. Ex. 1343488 mbc_blocks : integer :: Number of multiblock blocks in instance. Ex. 122 mbc_blocks_size : integer :: Total size of all multiblock blocks in instance. Ex. 285296 sbc_carriers : integer :: Number of singleblock carriers in instance. Ex. 1 sbc_carriers_size : integer :: Total size of singleblock blocks carriers in instance. Ex. 1343488 sbc_blocks : integer :: Number of singleblocks in instance. Ex. 1 sbc_blocks_size : integer :: Total size of all singleblock blocks in instance. Ex. 285296

Example:

`carrier_destroy: { cpu_id = 6 }, { type = "ets_alloc", instance = 7, size = 262144, mbc_carriers = 3, mbc_carriers_size = 3178496, mbc_blocks = 925, mbc_blocks_size = 2305336, sbc_carriers = 0, sbc_carriers_size = 0, sbc_blocks = 0, sbc_blocks_size = 0 }`

carrier_pool_put

type : string :: Carrier type. Ex. "ets_alloc" instance : integer :: Allocator instance. Ex. 1 size : integer :: Carrier size. Ex. 262144

Example:

`carrier_pool_put: { cpu_id = 3 }, { type = "ets_alloc", instance = 5, size = 1048576 }`

carrier_pool_get

type : string :: Carrier type. Ex. "ets_alloc" instance : integer :: Allocator instance. Ex. 1 size : integer :: Carrier size. Ex. 262144

Example:

`carrier_pool_get: { cpu_id = 7 }, { type = "ets_alloc", instance = 4, size = 3208 }`

## Example of process tracing

An example of process tracing of os_mon and friends.

Clean start of lttng in a bash shell.

    $ lttng create erlang-demo
    Spawning a session daemon
    Session erlang-demo created.
    Traces will be written in /home/egil/lttng-traces/erlang-demo-20160526-165920

Start an Erlang node with lttng enabled.

    $ erl
    Erlang/OTP 19 [erts-8.0] [source-4d7b24d] [64-bit] [smp:8:8] [async-threads:10] [hipe] [kernel-poll:false] [lttng]

    Eshell V8.0  (abort with ^G)
    1>

Load the dyntrace module.

    1> l(dyntrace).
    {module,dyntrace}

All tracepoints via dyntrace are now visibile and can be listed through lttng list -u.

Enable the process_register LTTng tracepoint for Erlang.

    $ lttng enable-event -u org_erlang_dyntrace:process_register
    UST event org_erlang_dyntrace:process_register created in channel channel0

Enable process tracing for new processes and use dyntrace as tracer backend.

    2> erlang:trace(new,true,[procs,{tracer,dyntrace,[]}]).
    0

Start LTTng tracing.

    $ lttng start
    Tracing started for session erlang-demo

Start the os_mon application in Erlang.

    3> application:ensure_all_started(os_mon).
    {ok,[sasl,os_mon]}

Stop LTTng tracing and view the result.

    $ lttng stop
    Tracing stopped for session erlang-demo
    $ lttng view
    [17:20:42.561168759] (+?.?????????) elxd1168lx9 org_erlang_dyntrace:process_register: \
        { cpu_id = 5 }, { pid = "<0.66.0>", name = "sasl_sup", type = "register" }
    [17:20:42.561215519] (+0.000046760) elxd1168lx9 org_erlang_dyntrace:process_register: \
        { cpu_id = 5 }, { pid = "<0.67.0>", name = "sasl_safe_sup", type = "register" }
    [17:20:42.562149024] (+0.000933505) elxd1168lx9 org_erlang_dyntrace:process_register: \
        { cpu_id = 5 }, { pid = "<0.68.0>", name = "alarm_handler", type = "register" }
    [17:20:42.571035803] (+0.008886779) elxd1168lx9 org_erlang_dyntrace:process_register: \
        { cpu_id = 5 }, { pid = "<0.69.0>", name = "release_handler", type = "register" }
    [17:20:42.574939868] (+0.003904065) elxd1168lx9 org_erlang_dyntrace:process_register: \
        { cpu_id = 5 }, { pid = "<0.74.0>", name = "os_mon_sup", type = "register" }
    [17:20:42.576818712] (+0.001878844) elxd1168lx9 org_erlang_dyntrace:process_register: \
        { cpu_id = 5 }, { pid = "<0.75.0>", name = "disksup", type = "register" }
    [17:20:42.580032013] (+0.003213301) elxd1168lx9 org_erlang_dyntrace:process_register: \
        { cpu_id = 5 }, { pid = "<0.76.0>", name = "memsup", type = "register" }
    [17:20:42.583046339] (+0.003014326) elxd1168lx9 org_erlang_dyntrace:process_register: \
        { cpu_id = 5 }, { pid = "<0.78.0>", name = "cpu_sup", type = "register" }
    [17:20:42.586206242] (+0.003159903) elxd1168lx9 org_erlang_dyntrace:process_register: \
        { cpu_id = 5 }, { pid = "<0.82.0>", name = "timer_server", type = "register" }