|
%%% @author Fred Hebert <mononcqc@ferd.ca>
|
|
%%% [http://ferd.ca/]
|
|
%%% @doc
|
|
%%% `recon_trace' is a module that handles tracing in a safe manner for single
|
|
%%% Erlang nodes, currently for function calls only. Functionality includes:
|
|
%%%
|
|
%%% <ul>
|
|
%%% <li>Nicer to use interface (arguably) than `dbg' or trace BIFs.</li>
|
|
%%% <li>Protection against dumb decisions (matching all calls on a node
|
|
%%% being traced, for example)</li>
|
|
%%% <li>Adding safe guards in terms of absolute trace count or
|
|
%%% rate-limitting</li>
|
|
%%% <li>Nicer formatting than default traces</li>
|
|
%%% </ul>
|
|
%%%
|
|
%%% == Tracing Erlang Code ==
|
|
%%%
|
|
%%% The Erlang Trace BIFs allow to trace any Erlang code at all. They work in
|
|
%%% two parts: pid specifications, and trace patterns.
|
|
%%%
|
|
%%% Pid specifications let you decide which processes to target. They can be
|
|
%%% specific pids, `all' pids, `existing' pids, or `new' pids (those not
|
|
%%% spawned at the time of the function call).
|
|
%%%
|
|
%%% The trace patterns represent functions. Functions can be specified in two
|
|
%%% parts: specifying the modules, functions, and arguments, and then with
|
|
%%% Erlang match specifications to add constraints to arguments (see
|
|
%%% {@link calls/3} for details).
|
|
%%%
|
|
%%% What defines whether you get traced or not is the intersection of both:
|
|
%%%
|
|
%%% ```
|
|
%%% _,--------,_ _,--------,_
|
|
%%% ,-' `-,,-' `-,
|
|
%%% ,-' ,-' '-, `-,
|
|
%%% | Matching -' '- Matching |
|
|
%%% | Pids | Getting | Trace |
|
|
%%% | | Traced | Patterns |
|
|
%%% | -, ,- |
|
|
%%% '-, '-, ,-' ,-'
|
|
%%% '-,_ _,-''-,_ _,-'
|
|
%%% '--------' '--------'
|
|
%%% '''
|
|
%%%
|
|
%%% If either the pid specification excludes a process or a trace pattern
|
|
%%% excludes a given call, no trace will be received.
|
|
%%%
|
|
%%% == Example Session ==
|
|
%%%
|
|
%%% First let's trace the `queue:new' functions in any process:
|
|
%%%
|
|
%%% ```
|
|
%%% 1> recon_trace:calls({queue, new, '_'}, 1).
|
|
%%% 1
|
|
%%% 13:14:34.086078 <0.44.0> queue:new()
|
|
%%% Recon tracer rate limit tripped.
|
|
%%% '''
|
|
%%%
|
|
%%% The limit was set to `1' trace message at most, and `recon' let us
|
|
%%% know when that limit was reached.
|
|
%%%
|
|
%%% Let's instead look for all the `queue:in/2' calls, to see what it is
|
|
%%% we're inserting in queues:
|
|
%%%
|
|
%%% ```
|
|
%%% 2> recon_trace:calls({queue, in, 2}, 1).
|
|
%%% 1
|
|
%%% 13:14:55.365157 <0.44.0> queue:in(a, {[],[]})
|
|
%%% Recon tracer rate limit tripped.
|
|
%%% '''
|
|
%%%
|
|
%%% In order to see the content we want, we should change the trace patterns
|
|
%%% to use a `fun' that matches on all arguments in a list (`_') and returns
|
|
%%% `return_trace()'. This last part will generate a second trace for each
|
|
%%% call that includes the return value:
|
|
%%%
|
|
%%% ```
|
|
%%% 3> recon_trace:calls({queue, in, fun(_) -> return_trace() end}, 3).
|
|
%%% 1
|
|
%%%
|
|
%%% 13:15:27.655132 <0.44.0> queue:in(a, {[],[]})
|
|
%%%
|
|
%%% 13:15:27.655467 <0.44.0> queue:in/2 --> {[a],[]}
|
|
%%%
|
|
%%% 13:15:27.757921 <0.44.0> queue:in(a, {[],[]})
|
|
%%% Recon tracer rate limit tripped.
|
|
%%% '''
|
|
%%%
|
|
%%% Matching on argument lists can be done in a more complex manner:
|
|
%%%
|
|
%%% ```
|
|
%%% 4> recon_trace:calls(
|
|
%%% 4> {queue, '_', fun([A,_]) when is_list(A); is_integer(A) andalso A > 1 -> return_trace() end},
|
|
%%% 4> {10,100}
|
|
%%% 4> ).
|
|
%%% 32
|
|
%%%
|
|
%%% 13:24:21.324309 <0.38.0> queue:in(3, {[],[]})
|
|
%%%
|
|
%%% 13:24:21.371473 <0.38.0> queue:in/2 --> {[3],[]}
|
|
%%%
|
|
%%% 13:25:14.694865 <0.53.0> queue:split(4, {[10,9,8,7],[1,2,3,4,5,6]})
|
|
%%%
|
|
%%% 13:25:14.695194 <0.53.0> queue:split/2 --> {{[4,3,2],[1]},{[10,9,8,7],[5,6]}}
|
|
%%%
|
|
%%% 5> recon_trace:clear().
|
|
%%% ok
|
|
%%% '''
|
|
%%%
|
|
%%% Note that in the pattern above, no specific function (<code>'_'</code>) was
|
|
%%% matched against. Instead, the `fun' used restricted functions to those
|
|
%%% having two arguments, the first of which is either a list or an integer
|
|
%%% greater than `1'.
|
|
%%%
|
|
%%% The limit was also set using `{10,100}' instead of an integer, making the
|
|
%%% rate-limitting at 10 messages per 100 milliseconds, instead of an absolute
|
|
%%% value.
|
|
%%%
|
|
%%% Any tracing can be manually interrupted by calling `recon_trace:clear()',
|
|
%%% or killing the shell process.
|
|
%%%
|
|
%%% Be aware that extremely broad patterns with lax rate-limitting (or very
|
|
%%% high absolute limits) may impact your node's stability in ways
|
|
%%% `recon_trace' cannot easily help you with.
|
|
%%%
|
|
%%% In doubt, start with the most restrictive tracing possible, with low
|
|
%%% limits, and progressively increase your scope.
|
|
%%%
|
|
%%% See {@link calls/3} for more details and tracing possibilities.
|
|
%%%
|
|
%%% == Structure ==
|
|
%%%
|
|
%%% This library is production-safe due to taking the following structure for
|
|
%%% tracing:
|
|
%%%
|
|
%%% ```
|
|
%%% [IO/Group leader] <---------------------,
|
|
%%% | |
|
|
%%% [shell] ---> [tracer process] ----> [formatter]
|
|
%%% '''
|
|
%%%
|
|
%%% The tracer process receives trace messages from the node, and enforces
|
|
%%% limits in absolute terms or trace rates, before forwarding the messages
|
|
%%% to the formatter. This is done so the tracer can do as little work as
|
|
%%% possible and never block while building up a large mailbox.
|
|
%%%
|
|
%%% The tracer process is linked to the shell, and the formatter to the
|
|
%%% tracer process. The formatter also traps exits to be able to handle
|
|
%%% all received trace messages until the tracer termination, but will then
|
|
%%% shut down as soon as possible.
|
|
%%%
|
|
%%% In case the operator is tracing from a remote shell which gets
|
|
%%% disconnected, the links between the shell and the tracer should make it
|
|
%%% so tracing is automatically turned off once you disconnect.
|
|
%%%
|
|
%%% If sending output to the Group Leader is not desired, you may specify
|
|
%%% a different pid() via the option `io_server' in the {@link calls/3} function.
|
|
%%% For instance to write the traces to a file you can do something like
|
|
%%%
|
|
%%% ```
|
|
%%% 1> {ok, Dev} = file:open("/tmp/trace",[write]).
|
|
%%% 2> recon_trace:calls({queue, in, fun(_) -> return_trace() end}, 3, [{io_server, Dev}]).
|
|
%%% 1
|
|
%%% 3>
|
|
%%% Recon tracer rate limit tripped.
|
|
%%% 4> file:close(Dev).
|
|
%%% '''
|
|
%%%
|
|
%%% The only output still sent to the Group Leader is the rate limit being
|
|
%%% tripped, and any errors. The rest will be sent to the other IO
|
|
%%% server (see [http://erlang.org/doc/apps/stdlib/io_protocol.html]).
|
|
%%%
|
|
%%% == Record Printing ==
|
|
%%%
|
|
%%% Thanks to code contributed by Bartek Górny, record printing can be added
|
|
%%% to traces by first importing records in an active session with
|
|
%%% `recon_rec:import([Module, ...])', after which the records declared in
|
|
%%% the module list will be supported.
|
|
%%% @end
|
|
-module(recon_trace).
|
|
|
|
%% API
|
|
-export([clear/0, calls/2, calls/3]).
|
|
|
|
-export([format/1]).
|
|
|
|
%% Internal exports
|
|
-export([count_tracer/1, rate_tracer/2, formatter/5, format_trace_output/1, format_trace_output/2]).
|
|
|
|
-type matchspec() :: [{[term()] | '_', [term()], [term()]}].
|
|
-type shellfun() :: fun((_) -> term()).
|
|
-type formatterfun() :: fun((_) -> iodata()).
|
|
-type millisecs() :: non_neg_integer().
|
|
-type pidspec() :: all | existing | new | recon:pid_term().
|
|
-type max_traces() :: non_neg_integer().
|
|
-type max_rate() :: {max_traces(), millisecs()}.
|
|
|
|
%% trace options
|
|
-type options() :: [ {pid, pidspec() | [pidspec(),...]} % default: all
|
|
| {timestamp, formatter | trace} % default: formatter
|
|
| {args, args | arity} % default: args
|
|
| {io_server, pid()} % default: group_leader()
|
|
| {formatter, formatterfun()} % default: internal formatter
|
|
| return_to | {return_to, boolean()} % default: false
|
|
%% match pattern options
|
|
| {scope, global | local} % default: global
|
|
].
|
|
|
|
-type mod() :: '_' | module().
|
|
-type fn() :: '_' | atom().
|
|
-type args() :: '_' | 0..255 | return_trace | matchspec() | shellfun().
|
|
-type tspec() :: {mod(), fn(), args()}.
|
|
-type max() :: max_traces() | max_rate().
|
|
-type num_matches() :: non_neg_integer().
|
|
|
|
-export_type([mod/0, fn/0, args/0, tspec/0, num_matches/0, options/0,
|
|
max_traces/0, max_rate/0]).
|
|
|
|
%%%%%%%%%%%%%%
|
|
%%% PUBLIC %%%
|
|
%%%%%%%%%%%%%%
|
|
|
|
%% @doc Stops all tracing at once.
|
|
-spec clear() -> ok.
|
|
clear() ->
|
|
erlang:trace(all, false, [all]),
|
|
erlang:trace_pattern({'_','_','_'}, false, [local,meta,call_count,call_time]),
|
|
erlang:trace_pattern({'_','_','_'}, false, []), % unsets global
|
|
maybe_kill(recon_trace_tracer),
|
|
maybe_kill(recon_trace_formatter),
|
|
ok.
|
|
|
|
%% @equiv calls({Mod, Fun, Args}, Max, [])
|
|
-spec calls(tspec() | [tspec(),...], max()) -> num_matches().
|
|
calls({Mod, Fun, Args}, Max) ->
|
|
calls([{Mod,Fun,Args}], Max, []);
|
|
calls(TSpecs = [_|_], Max) ->
|
|
calls(TSpecs, Max, []).
|
|
|
|
%% @doc Allows to set trace patterns and pid specifications to trace
|
|
%% function calls.
|
|
%%
|
|
%% The basic calls take the trace patterns as tuples of the form
|
|
%% `{Module, Function, Args}' where:
|
|
%%
|
|
%% <ul>
|
|
%% <li>`Module' is any atom representing a module</li>
|
|
%% <li>`Function' is any atom representing a function, or the wildcard
|
|
%% <code>'_'</code></li>
|
|
%% <li>`Args' is either the arity of a function (`0..255'), a wildcard
|
|
%% pattern (<code>'_'</code>), a
|
|
%% <a href="http://learnyousomeerlang.com/ets#you-have-been-selected">match specification</a>,
|
|
%% or a function from a shell session that can be transformed into
|
|
%% a match specification</li>
|
|
%% </ul>
|
|
%%
|
|
%% There is also an argument specifying either a maximal count (a number)
|
|
%% of trace messages to be received, or a maximal frequency (`{Num, Millisecs}').
|
|
%%
|
|
%% Here are examples of things to trace:
|
|
%%
|
|
%% <ul>
|
|
%% <li>All calls from the `queue' module, with 10 calls printed at most:
|
|
%% ``recon_trace:calls({queue, '_', '_'}, 10)''</li>
|
|
%% <li>All calls to `lists:seq(A,B)', with 100 calls printed at most:
|
|
%% `recon_trace:calls({lists, seq, 2}, 100)'</li>
|
|
%% <li>All calls to `lists:seq(A,B)', with 100 calls per second at most:
|
|
%% `recon_trace:calls({lists, seq, 2}, {100, 1000})'</li>
|
|
%% <li>All calls to `lists:seq(A,B,2)' (all sequences increasing by two)
|
|
%% with 100 calls at most:
|
|
%% `recon_trace:calls({lists, seq, fun([_,_,2]) -> ok end}, 100)'</li>
|
|
%% <li>All calls to `iolist_to_binary/1' made with a binary as an argument
|
|
%% already (kind of useless conversion!):
|
|
%% `recon_trace:calls({erlang, iolist_to_binary, fun([X]) when is_binary(X) -> ok end}, 10)'</li>
|
|
%% <li>Calls to the queue module only in a given process `Pid', at a rate
|
|
%% of 50 per second at most:
|
|
%% ``recon_trace:calls({queue, '_', '_'}, {50,1000}, [{pid, Pid}])''</li>
|
|
%% <li>Print the traces with the function arity instead of literal arguments:
|
|
%% `recon_trace:calls(TSpec, Max, [{args, arity}])'</li>
|
|
%% <li>Matching the `filter/2' functions of both `dict' and `lists' modules,
|
|
%% across new processes only:
|
|
%% `recon_trace:calls([{dict,filter,2},{lists,filter,2}], 10, [{pid, new}])'</li>
|
|
%% <li>Tracing the `handle_call/3' functions of a given module for all new processes,
|
|
%% and those of an existing one registered with `gproc':
|
|
%% `recon_trace:calls({Mod,handle_call,3}, {10,100}, [{pid, [{via, gproc, Name}, new]}'</li>
|
|
%% <li>Show the result of a given function call:
|
|
%% `recon_trace:calls({Mod,Fun,fun(_) -> return_trace() end}, Max, Opts)'
|
|
%% or
|
|
%% ``recon_trace:calls({Mod,Fun,[{'_', [], [{return_trace}]}]}, Max, Opts)'',
|
|
%% the important bit being the `return_trace()' call or the
|
|
%% `{return_trace}' match spec value.
|
|
%% A short-hand version for this pattern of 'match anything, trace everything'
|
|
%% for a function is `recon_trace:calls({Mod, Fun, return_trace})'. </li>
|
|
%% </ul>
|
|
%%
|
|
%% There's a few more combination possible, with multiple trace patterns per call, and more
|
|
%% options:
|
|
%%
|
|
%% <ul>
|
|
%% <li>`{pid, PidSpec}': which processes to trace. Valid options is any of
|
|
%% `all', `new', `existing', or a process descriptor (`{A,B,C}',
|
|
%% `"<A.B.C>"', an atom representing a name, `{global, Name}',
|
|
%% `{via, Registrar, Name}', or a pid). It's also possible to specify
|
|
%% more than one by putting them in a list.</li>
|
|
%% <li>`{timestamp, formatter | trace}': by default, the formatter process
|
|
%% adds timestamps to messages received. If accurate timestamps are
|
|
%% required, it's possible to force the usage of timestamps within
|
|
%% trace messages by adding the option `{timestamp, trace}'.</li>
|
|
%% <li>`{args, arity | args}': whether to print arity in function calls
|
|
%% or their (by default) literal representation.</li>
|
|
%% <li>`{scope, global | local}': by default, only 'global' (fully qualified
|
|
%% function calls) are traced, not calls made internally. To force tracing
|
|
%% of local calls, pass in `{scope, local}'. This is useful whenever
|
|
%% you want to track the changes of code in a process that isn't called
|
|
%% with `Module:Fun(Args)', but just `Fun(Args)'.</li>
|
|
%% <li>`{formatter, fun(Term) -> io_data() end}': override the default
|
|
%% formatting functionality provided by recon.</li>
|
|
%% <li>`{io_server, pid() | atom()}': by default, recon logs to the current
|
|
%% group leader, usually the shell. This option allows to redirect
|
|
%% trace output to a different IO server (such as a file handle).</li>
|
|
%% <li>`return_to': If this option is set (in conjunction with the match
|
|
%% option `{scope, local}'), the function to which the value is returned
|
|
%% is output in a trace. Note that this is distinct from giving the
|
|
%% *caller* since exception handling or calls in tail position may
|
|
%% hide the original caller.</li>
|
|
%% </ul>
|
|
%%
|
|
%% Also note that putting extremely large `Max' values (i.e. `99999999' or
|
|
%% `{10000,1}') will probably negate most of the safe-guarding this library
|
|
%% does and be dangerous to your node. Similarly, tracing extremely large
|
|
%% amounts of function calls (all of them, or all of `io' for example)
|
|
%% can be risky if more trace messages are generated than any process on
|
|
%% the node could ever handle, despite the precautions taken by this library.
|
|
%% @end
|
|
-spec calls(tspec() | [tspec(),...], max(), options()) -> num_matches().
|
|
|
|
calls({Mod, Fun, Args}, Max, Opts) ->
|
|
calls([{Mod,Fun,Args}], Max, Opts);
|
|
calls(TSpecs = [_|_], {Max, Time}, Opts) ->
|
|
Pid = setup(rate_tracer, [Max, Time],
|
|
validate_formatter(Opts), validate_io_server(Opts)),
|
|
trace_calls(TSpecs, Pid, Opts);
|
|
calls(TSpecs = [_|_], Max, Opts) ->
|
|
Pid = setup(count_tracer, [Max],
|
|
validate_formatter(Opts), validate_io_server(Opts)),
|
|
trace_calls(TSpecs, Pid, Opts).
|
|
|
|
%%%%%%%%%%%%%%%%%%%%%%%
|
|
%%% PRIVATE EXPORTS %%%
|
|
%%%%%%%%%%%%%%%%%%%%%%%
|
|
%% @private Stops when N trace messages have been received
|
|
count_tracer(0) ->
|
|
exit(normal);
|
|
count_tracer(N) ->
|
|
receive
|
|
Msg ->
|
|
recon_trace_formatter ! Msg,
|
|
count_tracer(N-1)
|
|
end.
|
|
|
|
%% @private Stops whenever the trace message rates goes higher than
|
|
%% `Max' messages in `Time' milliseconds. Note that if the rate
|
|
%% proposed is higher than what the IO system of the formatter
|
|
%% can handle, this can still put a node at risk.
|
|
%%
|
|
%% It is recommended to try stricter rates to begin with.
|
|
rate_tracer(Max, Time) -> rate_tracer(Max, Time, 0, os:timestamp()).
|
|
|
|
rate_tracer(Max, Time, Count, Start) ->
|
|
receive
|
|
Msg ->
|
|
recon_trace_formatter ! Msg,
|
|
Now = os:timestamp(),
|
|
Delay = timer:now_diff(Now, Start) div 1000,
|
|
if Delay > Time -> rate_tracer(Max, Time, 0, Now)
|
|
; Max > Count -> rate_tracer(Max, Time, Count+1, Start)
|
|
; Max =:= Count -> exit(normal)
|
|
end
|
|
end.
|
|
|
|
%% @private Formats traces to be output
|
|
formatter(Tracer, Parent, Ref, FormatterFun, IOServer) ->
|
|
process_flag(trap_exit, true),
|
|
link(Tracer),
|
|
Parent ! {Ref, linked},
|
|
formatter(Tracer, IOServer, FormatterFun).
|
|
|
|
formatter(Tracer, IOServer, FormatterFun) ->
|
|
receive
|
|
{'EXIT', Tracer, normal} ->
|
|
io:format("Recon tracer rate limit tripped.~n"),
|
|
exit(normal);
|
|
{'EXIT', Tracer, Reason} ->
|
|
exit(Reason);
|
|
TraceMsg ->
|
|
io:format(IOServer, FormatterFun(TraceMsg), []),
|
|
formatter(Tracer, IOServer, FormatterFun)
|
|
end.
|
|
|
|
|
|
%%%%%%%%%%%%%%%%%%%%%%%
|
|
%%% SETUP FUNCTIONS %%%
|
|
%%%%%%%%%%%%%%%%%%%%%%%
|
|
|
|
%% starts the tracer and formatter processes, and
|
|
%% cleans them up before each call.
|
|
setup(TracerFun, TracerArgs, FormatterFun, IOServer) ->
|
|
clear(),
|
|
Ref = make_ref(),
|
|
Tracer = spawn_link(?MODULE, TracerFun, TracerArgs),
|
|
register(recon_trace_tracer, Tracer),
|
|
Format = spawn(?MODULE, formatter, [Tracer, self(), Ref, FormatterFun, IOServer]),
|
|
register(recon_trace_formatter, Format),
|
|
receive
|
|
{Ref, linked} -> Tracer
|
|
after 5000 ->
|
|
error(setup_failed)
|
|
end.
|
|
|
|
%% Sets the traces in action
|
|
trace_calls(TSpecs, Pid, Opts) ->
|
|
{PidSpecs, TraceOpts, MatchOpts} = validate_opts(Opts),
|
|
Matches = [begin
|
|
{Arity, Spec} = validate_tspec(Mod, Fun, Args),
|
|
erlang:trace_pattern({Mod, Fun, Arity}, Spec, MatchOpts)
|
|
end || {Mod, Fun, Args} <- TSpecs],
|
|
[erlang:trace(PidSpec, true, [call, {tracer, Pid} | TraceOpts])
|
|
|| PidSpec <- PidSpecs],
|
|
lists:sum(Matches).
|
|
|
|
|
|
%%%%%%%%%%%%%%%%%%
|
|
%%% VALIDATION %%%
|
|
%%%%%%%%%%%%%%%%%%
|
|
|
|
validate_opts(Opts) ->
|
|
PidSpecs = validate_pid_specs(proplists:get_value(pid, Opts, all)),
|
|
Scope = proplists:get_value(scope, Opts, global),
|
|
TraceOpts = case proplists:get_value(timestamp, Opts, formatter) of
|
|
formatter -> [];
|
|
trace -> [timestamp]
|
|
end ++
|
|
case proplists:get_value(args, Opts, args) of
|
|
args -> [];
|
|
arity -> [arity]
|
|
end ++
|
|
case proplists:get_value(return_to, Opts, undefined) of
|
|
true when Scope =:= local ->
|
|
[return_to];
|
|
true when Scope =:= global ->
|
|
io:format("Option return_to only works with option {scope, local}~n"),
|
|
%% Set it anyway
|
|
[return_to];
|
|
_ ->
|
|
[]
|
|
end,
|
|
MatchOpts = [Scope],
|
|
{PidSpecs, TraceOpts, MatchOpts}.
|
|
|
|
%% Support the regular specs, but also allow `recon:pid_term()' and lists
|
|
%% of further pid specs.
|
|
-spec validate_pid_specs(pidspec() | [pidspec(),...]) ->
|
|
[all | new | existing | pid(), ...].
|
|
validate_pid_specs(all) -> [all];
|
|
validate_pid_specs(existing) -> [existing];
|
|
validate_pid_specs(new) -> [new];
|
|
validate_pid_specs([Spec]) -> validate_pid_specs(Spec);
|
|
validate_pid_specs(PidTerm = [Spec|Rest]) ->
|
|
%% can be "<a.b.c>" or [pidspec()]
|
|
try
|
|
[recon_lib:term_to_pid(PidTerm)]
|
|
catch
|
|
error:function_clause ->
|
|
validate_pid_specs(Spec) ++ validate_pid_specs(Rest)
|
|
end;
|
|
validate_pid_specs(PidTerm) ->
|
|
%% has to be `recon:pid_term()'.
|
|
[recon_lib:term_to_pid(PidTerm)].
|
|
|
|
validate_tspec(Mod, Fun, Args) when is_function(Args) ->
|
|
validate_tspec(Mod, Fun, fun_to_ms(Args));
|
|
%% helper to save typing for common actions
|
|
validate_tspec(Mod, Fun, return_trace) ->
|
|
validate_tspec(Mod, Fun, [{'_', [], [{return_trace}]}]);
|
|
validate_tspec(Mod, Fun, Args) ->
|
|
BannedMods = ['_', ?MODULE, io, lists],
|
|
%% The banned mod check can be bypassed by using
|
|
%% match specs if you really feel like being dumb.
|
|
case {lists:member(Mod, BannedMods), Args} of
|
|
{true, '_'} -> error({dangerous_combo, {Mod,Fun,Args}});
|
|
{true, []} -> error({dangerous_combo, {Mod,Fun,Args}});
|
|
_ -> ok
|
|
end,
|
|
case Args of
|
|
'_' -> {'_', true};
|
|
_ when is_list(Args) -> {'_', Args};
|
|
_ when Args >= 0, Args =< 255 -> {Args, true}
|
|
end.
|
|
|
|
validate_formatter(Opts) ->
|
|
case proplists:get_value(formatter, Opts) of
|
|
F when is_function(F, 1) -> F;
|
|
_ -> fun format/1
|
|
end.
|
|
|
|
validate_io_server(Opts) ->
|
|
proplists:get_value(io_server, Opts, group_leader()).
|
|
|
|
%%%%%%%%%%%%%%%%%%%%%%%%
|
|
%%% TRACE FORMATTING %%%
|
|
%%%%%%%%%%%%%%%%%%%%%%%%
|
|
%% Thanks Geoff Cant for the foundations for this.
|
|
format(TraceMsg) ->
|
|
{Type, Pid, {Hour,Min,Sec}, TraceInfo} = extract_info(TraceMsg),
|
|
{FormatStr, FormatArgs} = case {Type, TraceInfo} of
|
|
%% {trace, Pid, 'receive', Msg}
|
|
{'receive', [Msg]} ->
|
|
{"< ~p", [Msg]};
|
|
%% {trace, Pid, send, Msg, To}
|
|
{send, [Msg, To]} ->
|
|
{" > ~p: ~p", [To, Msg]};
|
|
%% {trace, Pid, send_to_non_existing_process, Msg, To}
|
|
{send_to_non_existing_process, [Msg, To]} ->
|
|
{" > (non_existent) ~p: ~p", [To, Msg]};
|
|
%% {trace, Pid, call, {M, F, Args}}
|
|
{call, [{M,F,Args}]} ->
|
|
{"~p:~p~s", [M,F,format_args(Args)]};
|
|
%% {trace, Pid, call, {M, F, Args}, Msg}
|
|
{call, [{M,F,Args}, Msg]} ->
|
|
{"~p:~p~s ~s", [M,F,format_args(Args), format_trace_output(Msg)]};
|
|
%% {trace, Pid, return_to, {M, F, Arity}}
|
|
{return_to, [{M,F,Arity}]} ->
|
|
{" '--> ~p:~p/~p", [M,F,Arity]};
|
|
%% {trace, Pid, return_from, {M, F, Arity}, ReturnValue}
|
|
{return_from, [{M,F,Arity}, Return]} ->
|
|
{"~p:~p/~p --> ~s", [M,F,Arity, format_trace_output(Return)]};
|
|
%% {trace, Pid, exception_from, {M, F, Arity}, {Class, Value}}
|
|
{exception_from, [{M,F,Arity}, {Class,Val}]} ->
|
|
{"~p:~p/~p ~p ~p", [M,F,Arity, Class, Val]};
|
|
%% {trace, Pid, spawn, Spawned, {M, F, Args}}
|
|
{spawn, [Spawned, {M,F,Args}]} ->
|
|
{"spawned ~p as ~p:~p~s", [Spawned, M, F, format_args(Args)]};
|
|
%% {trace, Pid, exit, Reason}
|
|
{exit, [Reason]} ->
|
|
{"EXIT ~p", [Reason]};
|
|
%% {trace, Pid, link, Pid2}
|
|
{link, [Linked]} ->
|
|
{"link(~p)", [Linked]};
|
|
%% {trace, Pid, unlink, Pid2}
|
|
{unlink, [Linked]} ->
|
|
{"unlink(~p)", [Linked]};
|
|
%% {trace, Pid, getting_linked, Pid2}
|
|
{getting_linked, [Linker]} ->
|
|
{"getting linked by ~p", [Linker]};
|
|
%% {trace, Pid, getting_unlinked, Pid2}
|
|
{getting_unlinked, [Unlinker]} ->
|
|
{"getting unlinked by ~p", [Unlinker]};
|
|
%% {trace, Pid, register, RegName}
|
|
{register, [Name]} ->
|
|
{"registered as ~p", [Name]};
|
|
%% {trace, Pid, unregister, RegName}
|
|
{unregister, [Name]} ->
|
|
{"no longer registered as ~p", [Name]};
|
|
%% {trace, Pid, in, {M, F, Arity} | 0}
|
|
{in, [{M,F,Arity}]} ->
|
|
{"scheduled in for ~p:~p/~p", [M,F,Arity]};
|
|
{in, [0]} ->
|
|
{"scheduled in", []};
|
|
%% {trace, Pid, out, {M, F, Arity} | 0}
|
|
{out, [{M,F,Arity}]} ->
|
|
{"scheduled out from ~p:~p/~p", [M, F, Arity]};
|
|
{out, [0]} ->
|
|
{"scheduled out", []};
|
|
%% {trace, Pid, gc_start, Info}
|
|
{gc_start, [Info]} ->
|
|
HeapSize = proplists:get_value(heap_size, Info),
|
|
OldHeapSize = proplists:get_value(old_heap_size, Info),
|
|
MbufSize = proplists:get_value(mbuf_size, Info),
|
|
{"gc beginning -- heap ~p bytes",
|
|
[HeapSize + OldHeapSize + MbufSize]};
|
|
%% {trace, Pid, gc_end, Info}
|
|
{gc_end, [Info]} ->
|
|
HeapSize = proplists:get_value(heap_size, Info),
|
|
OldHeapSize = proplists:get_value(old_heap_size, Info),
|
|
MbufSize = proplists:get_value(mbuf_size, Info),
|
|
{"gc finished -- heap ~p bytes",
|
|
[HeapSize + OldHeapSize + MbufSize]};
|
|
_ ->
|
|
{"unknown trace type ~p -- ~p", [Type, TraceInfo]}
|
|
end,
|
|
io_lib:format("~n~p:~p:~9.6.0f ~p " ++ FormatStr ++ "~n",
|
|
[Hour, Min, Sec, Pid] ++ FormatArgs).
|
|
|
|
extract_info(TraceMsg) ->
|
|
case tuple_to_list(TraceMsg) of
|
|
[trace_ts, Pid, Type | Info] ->
|
|
{TraceInfo, [Timestamp]} = lists:split(length(Info)-1, Info),
|
|
{Type, Pid, to_hms(Timestamp), TraceInfo};
|
|
[trace, Pid, Type | TraceInfo] ->
|
|
{Type, Pid, to_hms(os:timestamp()), TraceInfo}
|
|
end.
|
|
|
|
to_hms(Stamp = {_, _, Micro}) ->
|
|
{_,{H, M, Secs}} = calendar:now_to_local_time(Stamp),
|
|
Seconds = Secs rem 60 + (Micro / 1000000),
|
|
{H,M,Seconds};
|
|
to_hms(_) ->
|
|
{0,0,0}.
|
|
|
|
format_args(Arity) when is_integer(Arity) ->
|
|
[$/, integer_to_list(Arity)];
|
|
format_args(Args) when is_list(Args) ->
|
|
[$(, join(", ", [format_trace_output(Arg) || Arg <- Args]), $)].
|
|
|
|
|
|
%% @doc formats call arguments and return values - most types are just printed out, except for
|
|
%% tuples recognised as records, which mimic the source code syntax
|
|
%% @end
|
|
format_trace_output(Args) ->
|
|
format_trace_output(recon_rec:is_active(), recon_map:is_active(), Args).
|
|
|
|
format_trace_output(Recs, Args) ->
|
|
format_trace_output(Recs, recon_map:is_active(), Args).
|
|
|
|
format_trace_output(true, _, Args) when is_tuple(Args) ->
|
|
recon_rec:format_tuple(Args);
|
|
format_trace_output(false, true, Args) when is_tuple(Args) ->
|
|
format_tuple(false, true, Args);
|
|
format_trace_output(Recs, Maps, Args) when is_list(Args), Recs orelse Maps ->
|
|
case io_lib:printable_list(Args) of
|
|
true ->
|
|
io_lib:format("~p", [Args]);
|
|
false ->
|
|
format_maybe_improper_list(Recs, Maps, Args)
|
|
end;
|
|
format_trace_output(Recs, true, Args) when is_map(Args) ->
|
|
{Label, Map} = case recon_map:process_map(Args) of
|
|
{L, M} -> {atom_to_list(L), M};
|
|
M -> {"", M}
|
|
end,
|
|
ItemList = maps:to_list(Map),
|
|
[Label,
|
|
"#{",
|
|
join(", ", [format_kv(Recs, true, Key, Val) || {Key, Val} <- ItemList]),
|
|
"}"];
|
|
format_trace_output(Recs, false, Args) when is_map(Args) ->
|
|
ItemList = maps:to_list(Args),
|
|
["#{",
|
|
join(", ", [format_kv(Recs, false, Key, Val) || {Key, Val} <- ItemList]),
|
|
"}"];
|
|
format_trace_output(_, _, Args) ->
|
|
io_lib:format("~p", [Args]).
|
|
|
|
format_kv(Recs, Maps, Key, Val) ->
|
|
[format_trace_output(Recs, Maps, Key), "=>", format_trace_output(Recs, Maps, Val)].
|
|
|
|
|
|
format_tuple(Recs, Maps, Tup) ->
|
|
[${ | format_tuple_(Recs, Maps, tuple_to_list(Tup))].
|
|
|
|
format_tuple_(_Recs, _Maps, []) ->
|
|
"}";
|
|
format_tuple_(Recs, Maps, [H|T]) ->
|
|
[format_trace_output(Recs, Maps, H), $,,
|
|
format_tuple_(Recs, Maps, T)].
|
|
|
|
|
|
format_maybe_improper_list(Recs, Maps, List) ->
|
|
[$[ | format_maybe_improper_list_(Recs, Maps, List)].
|
|
|
|
format_maybe_improper_list_(_, _, []) ->
|
|
"]";
|
|
format_maybe_improper_list_(Recs, Maps, [H|[]]) ->
|
|
[format_trace_output(Recs, Maps, H), $]];
|
|
format_maybe_improper_list_(Recs, Maps, [H|T]) when is_list(T) ->
|
|
[format_trace_output(Recs, Maps, H), $,,
|
|
format_maybe_improper_list_(Recs, Maps, T)];
|
|
format_maybe_improper_list_(Recs, Maps, [H|T]) when not is_list(T) ->
|
|
%% Handling improper lists
|
|
[format_trace_output(Recs, Maps, H), $|,
|
|
format_trace_output(Recs, Maps, T), $]].
|
|
|
|
|
|
%%%%%%%%%%%%%%%
|
|
%%% HELPERS %%%
|
|
%%%%%%%%%%%%%%%
|
|
|
|
maybe_kill(Name) ->
|
|
case whereis(Name) of
|
|
undefined ->
|
|
ok;
|
|
Pid ->
|
|
unlink(Pid),
|
|
exit(Pid, kill),
|
|
wait_for_death(Pid, Name)
|
|
end.
|
|
|
|
wait_for_death(Pid, Name) ->
|
|
case is_process_alive(Pid) orelse whereis(Name) =:= Pid of
|
|
true ->
|
|
timer:sleep(10),
|
|
wait_for_death(Pid, Name);
|
|
false ->
|
|
ok
|
|
end.
|
|
|
|
%% Borrowed from dbg
|
|
fun_to_ms(ShellFun) when is_function(ShellFun) ->
|
|
case erl_eval:fun_data(ShellFun) of
|
|
{fun_data,ImportList,Clauses} ->
|
|
case ms_transform:transform_from_shell(
|
|
dbg,Clauses,ImportList) of
|
|
{error,[{_,[{_,_,Code}|_]}|_],_} ->
|
|
io:format("Error: ~s~n",
|
|
[ms_transform:format_error(Code)]),
|
|
{error,transform_error};
|
|
Else ->
|
|
Else
|
|
end;
|
|
false ->
|
|
exit(shell_funs_only)
|
|
end.
|
|
|
|
|
|
-ifdef(OTP_RELEASE).
|
|
-spec join(term(), [term()]) -> [term()].
|
|
join(Sep, List) ->
|
|
lists:join(Sep, List).
|
|
-else.
|
|
-spec join(string(), [string()]) -> string().
|
|
join(Sep, List) ->
|
|
string:join(List, Sep).
|
|
-endif.
|