[erlang-questions] Erlang tracing
Tony Rogvall
tony@REDACTED
Mon Sep 21 21:48:01 CEST 2015
Hi!
Here is my input:
While thinking about how to trace erlang program execution I came to think about how the
’line’ beam op code works. The idea is to add a new opcode called ’pint’ ( short for print. )
The idea has been around for a long time and is also called printf debugging :-)
( heavily inspired by Mats Cronqvist )
The ’pint’ opcode has the feature that it can be removed while loading a module, or
it can stay lurking for later debugging opportunities. The ’pint’ opcode has an argument,
and it is the bound variables at the line in the source code. If the compiler could preserve
the the variables names ( transform them a bit more gently through the core and kernel passes )
it could be enough just print the module, line and bound variabels to get a sense of what
is going on sometimes.
Example
Given the program:
%%
%% Simple test program
%%
-module(fib).
-compile(export_all).
nth(0) -> 1;
nth(1) -> 1;
nth(N) ->
N1 = N-1,
N2 = N-2,
nth(N1) + nth(N2).
%% ————
My patched compiler generates the following beam code:
{module, fib}. %% version = 0
{exports, [{module_info,0},{module_info,1},{nth,1}]}.
{attributes, []}.
{labels, 9}.
{function, nth, 1, 2}.
{label,1}.
{line,[{location,"fib.erl",8}]}.
{func_info,{atom,fib},{atom,nth},1}.
{label,2}.
{pint,{literal,[{cor0,{x,0}}]}}.
{test,is_integer,{f,4},[{x,0}]}.
{select_val,{x,0},{f,4},{list,[{integer,1},{f,3},{integer,0},{f,3}]}}.
{label,3}.
{move,{integer,1},{x,0}}.
return.
{label,4}.
{allocate_zero,1,1}.
{line,[{location,"fib.erl",11}]}.
{pint,{literal,[{cor0,{x,0}}]}}.
{gc_bif,'-',{f,0},1,[{x,0},{integer,1}],{x,1}}.
{line,[{location,"fib.erl",12}]}.
{pint,{literal,[{cor0,{x,0}},{'N1',{x,1}}]}}.
{gc_bif,'-',{f,0},2,[{x,0},{integer,2}],{y,0}}.
{move,{x,1},{x,0}}.
{line,[{location,"fib.erl",13}]}.
{pint,{literal,[{cor4,{x,0}}]}}.
{call,1,{f,2}}.
{move,{x,0},{x,1}}.
{move,{y,0},{x,0}}.
{move,{x,1},{y,0}}.
{line,[{location,"fib.erl",13}]}.
{pint,{literal,[{cor3,{x,0}}]}}.
{call,1,{f,2}}.
{line,[{location,"fib.erl",13}]}.
{pint,{literal,[{cor3,{x,0}}]}}.
{gc_bif,'+',{f,0},1,[{y,0},{x,0}],{x,0}}.
{deallocate,1}.
return.
And the output when running a modified runtime system currently look like this:
Erlang/OTP 17 [erts-6.3.1] [source-f8b6ef6] [64-bit] [smp:4:4] [async-threads:10] [hipe] [kernel-poll:false]
Eshell V6.3.1 (abort with ^G)
1> fib:nth(4).
fib.erl:8: [fib:nth/1] {x,0}=cor0=4
fib.erl:11: [fib:nth/1] {x,0}=cor0=4
fib.erl:12: [fib:nth/1] {x,0}=cor0=4 {x,1}=N1=3
fib.erl:13: [fib:nth/1] {x,0}=cor4=3
fib.erl:8: [fib:nth/1] {x,0}=cor0=3
fib.erl:11: [fib:nth/1] {x,0}=cor0=3
fib.erl:12: [fib:nth/1] {x,0}=cor0=3 {x,1}=N1=2
fib.erl:13: [fib:nth/1] {x,0}=cor4=2
fib.erl:8: [fib:nth/1] {x,0}=cor0=2
fib.erl:11: [fib:nth/1] {x,0}=cor0=2
fib.erl:12: [fib:nth/1] {x,0}=cor0=2 {x,1}=N1=1
fib.erl:13: [fib:nth/1] {x,0}=cor4=1
fib.erl:8: [fib:nth/1] {x,0}=cor0=1
fib.erl:13: [fib:nth/1] {x,0}=cor3=0
fib.erl:8: [fib:nth/1] {x,0}=cor0=0
fib.erl:13: [fib:nth/1] {x,0}=cor3=1
fib.erl:13: [fib:nth/1] {x,0}=cor3=1
fib.erl:8: [fib:nth/1] {x,0}=cor0=1
fib.erl:13: [fib:nth/1] {x,0}=cor3=1
fib.erl:13: [fib:nth/1] {x,0}=cor3=2
fib.erl:8: [fib:nth/1] {x,0}=cor0=2
fib.erl:11: [fib:nth/1] {x,0}=cor0=2
fib.erl:12: [fib:nth/1] {x,0}=cor0=2 {x,1}=N1=1
fib.erl:13: [fib:nth/1] {x,0}=cor4=1
fib.erl:8: [fib:nth/1] {x,0}=cor0=1
fib.erl:13: [fib:nth/1] {x,0}=cor3=0
fib.erl:8: [fib:nth/1] {x,0}=cor0=0
fib.erl:13: [fib:nth/1] {x,0}=cor3=1
fib.erl:13: [fib:nth/1] {x,0}=cor3=2
5
Yes it uses fib 1,1 definition and the output is not good enough yet, but with some effort in
the compiler to tracking variables names and possibly be able to output return values etc.
But even more important is a system that can turn the pints on or off, either by line, function,
module and pid etc. Also a system that can collect the output from the traces and deliver them
to remote systems, filter them etc.
Well, for what its worth...
/Tony
> On 21 sep 2015, at 10:52, Lukas Larsson <lukas@REDACTED> wrote:
>
> Hello everyone.
>
> As you may know, one of the OTP teams focus areas for the coming year is make tracing better. At the moment we are gathering ideas and attempting to put together a vision of what we would like to have, before deciding what we can make.
>
> I'm pretty sure that many of you have much more experience with using Erlang tracing while developing and in production than I do, which is we would love to have your input as to what you would like to change about tracing.
>
> To set the scope of the discussion, when I say tracing I include; erlang tracing, dtrace/systemtap, trace outputs (stdout/file/IP), filtering through match specs, sequence tracing, tool integration (dbg, fprof, redbug, recon to mention some) and probably more.
>
> To start the discussion, here are a few of my ideas in no particular order:
> * Allow multiple tracers. Today only one port/process can be the receiver of trace data.
> * Create a couple of scalable high throughput tracing output backends with different overflow mechanics. Today all tracing is funneled through one bottleneck and has no overflow handling at all.
> * Expose vm probes (today dtrace probes) to the erlang tracer.
> * Better integration of dtrace/lttngt/systemtap into the erlang trace.
> * Allow the erlang tracer to be an Erlang callback module. Today only ports/processes are allowed.
> * Optimize trace output to file/ip. Maybe use something like the Common Trace Format (http://git.efficios.com/?p=ctf.git;a=blob_plain;f=common-trace-format-specification.md;hb=master), instead of the term_to_binary that we have today.
> * Write much much better documentation for dbg :)
>
> We are looking for feedback from both beginners as well as seasoned veterans to make erlang tracing the best it can be. So if you have any thoughts or ideas, join the discussion to make Erlang tracing better for you and everyone else.
>
> Thanks in advance,
> Lukas
> Erlang/OTP team
> _______________________________________________
> erlang-questions mailing list
> erlang-questions@REDACTED
> http://erlang.org/mailman/listinfo/erlang-questions
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 801 bytes
Desc: Message signed with OpenPGP using GPGMail
URL: <http://erlang.org/pipermail/erlang-questions/attachments/20150921/e8433e97/attachment.bin>
More information about the erlang-questions
mailing list