From 9af78c19d88b4c84e2433c005376c2c4ed6b3aae Mon Sep 17 00:00:00 2001 From: SisMaker <1713699517@qq.com> Date: Wed, 19 May 2021 19:25:47 +0800 Subject: [PATCH] =?UTF-8?q?st:=20=E4=BB=A3=E7=A0=81=E6=A0=BC=E5=BC=8F?= =?UTF-8?q?=E5=8C=96?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- src/eTpf.erl | 168 +++---- src/eTpf_app.erl | 4 +- src/eTpf_sup.erl | 12 +- src/profile/lg_callgrind.erl | 670 +++++++++++++------------- src/profile/lg_file_reader.erl | 124 ++--- src/profile/lg_file_tracer.erl | 118 ++--- src/profile/lg_flame.erl | 410 ++++++++-------- src/profile/lg_messages.erl | 338 ++++++------- src/profile/lg_messages_seqdiag.erl | 194 ++++---- src/profile/lg_rabbit_hole.erl | 14 +- src/profile/lg_raw_console_tracer.erl | 34 +- src/profile/lg_socket_client.erl | 132 ++--- src/profile/lg_socket_tracer.erl | 208 ++++---- src/profile/lg_term.erl | 100 ++-- src/profile/lg_tracer.erl | 24 +- src/profile/lg_tracer_pool.erl | 16 +- src/profile/looking_glass_app.erl | 4 +- src/profile/looking_glass_sup.erl | 12 +- test/lg_SUITE.erl | 420 ++++++++-------- 19 files changed, 1501 insertions(+), 1501 deletions(-) diff --git a/src/eTpf.erl b/src/eTpf.erl index b051a9f..2f46998 100644 --- a/src/eTpf.erl +++ b/src/eTpf.erl @@ -23,9 +23,9 @@ -type pattern() :: module() | {app, atom()} | {callback, module(), atom()}. -type scope() :: {scope, [ - pid() | port() | all | processes | ports | - existing | existing_processes | existing_ports | - new | new_processes | new_ports]}. +pid() | port() | all | processes | ports | +existing | existing_processes | existing_ports | +new | new_processes | new_ports]}. -type input() :: [pattern() | scope()]. -export_type([input/0]). @@ -34,116 +34,116 @@ -type user_input() :: pattern() | input(). -type opts() :: #{ - mode => trace | profile, - pool_id => any(), - pool_size => pos_integer(), - send => boolean(), - running => boolean() +mode => trace | profile, +pool_id => any(), +pool_size => pos_integer(), +send => boolean(), +running => boolean() }. -spec trace(user_input()) -> ok. trace(Input) -> - trace(Input, lg_raw_console_tracer). + trace(Input, lg_raw_console_tracer). -spec trace(user_input(), module()) -> ok. trace(Input, TracerMod) -> - trace(Input, TracerMod, undefined, #{}). + trace(Input, TracerMod, undefined, #{}). -spec trace(user_input(), module(), any()) -> ok. trace(Input, TracerMod, TracerOpts) -> - trace(Input, TracerMod, TracerOpts, #{}). + trace(Input, TracerMod, TracerOpts, #{}). -spec trace(user_input(), module(), any(), opts()) -> ok. trace(Input, TracerMod, TracerOpts, Opts) when is_list(Input) -> - do_trace(Input, TracerMod, TracerOpts, Opts); + do_trace(Input, TracerMod, TracerOpts, Opts); trace(Input, TracerMod, TracerOpts, Opts) -> - trace([Input], TracerMod, TracerOpts, Opts). + trace([Input], TracerMod, TracerOpts, Opts). do_trace(Input0, TracerMod, TracerOpts, Opts) -> - %% @todo Remove eventually? - _ = application:ensure_all_started(looking_glass), - %% Start the pool of tracer processes. - PoolID = maps:get(pool_id, Opts, default), - PoolSize = maps:get(pool_size, Opts, erlang:system_info(schedulers)), - true = PoolSize > 0, - {ok, PoolPid} = supervisor:start_child(looking_glass_sup, #{ - id => PoolID, - start => {lg_tracer_pool, start_link, [PoolSize, TracerMod, TracerOpts]}, - restart => temporary, - type => supervisor - }), - Tracers = lg_tracer_pool:tracers(PoolPid), - TracersMap = maps:from_list(lists:zip(lists:seq(0, length(Tracers) - 1), Tracers)), - Mode = maps:get(mode, Opts, trace), - Input1 = flatten(Input0, []), - Input2 = ensure_pattern(Input1), - Input = ensure_scope(Input2), - trace_input(Input, #{mode => Mode, tracers => TracersMap}, Opts), - ok. + %% @todo Remove eventually? + _ = application:ensure_all_started(looking_glass), + %% Start the pool of tracer processes. + PoolID = maps:get(pool_id, Opts, default), + PoolSize = maps:get(pool_size, Opts, erlang:system_info(schedulers)), + true = PoolSize > 0, + {ok, PoolPid} = supervisor:start_child(looking_glass_sup, #{ + id => PoolID, + start => {lg_tracer_pool, start_link, [PoolSize, TracerMod, TracerOpts]}, + restart => temporary, + type => supervisor + }), + Tracers = lg_tracer_pool:tracers(PoolPid), + TracersMap = maps:from_list(lists:zip(lists:seq(0, length(Tracers) - 1), Tracers)), + Mode = maps:get(mode, Opts, trace), + Input1 = flatten(Input0, []), + Input2 = ensure_pattern(Input1), + Input = ensure_scope(Input2), + trace_input(Input, #{mode => Mode, tracers => TracersMap}, Opts), + ok. flatten([], Acc) -> - lists:flatten(Acc); -flatten([{callback, Mod, Fun}|Tail], Acc) when is_atom(Mod), is_atom(Fun) -> - Input = flatten(Mod:Fun(), []), - flatten(Tail, [Input|Acc]); -flatten([{app, App}|Tail], Acc) when is_atom(App) -> - _ = application:load(App), - {ok, Mods} = application:get_key(App, modules), - flatten(Tail, [Mods|Acc]); -flatten([Input|Tail], Acc) -> - flatten(Tail, [Input|Acc]). + lists:flatten(Acc); +flatten([{callback, Mod, Fun} | Tail], Acc) when is_atom(Mod), is_atom(Fun) -> + Input = flatten(Mod:Fun(), []), + flatten(Tail, [Input | Acc]); +flatten([{app, App} | Tail], Acc) when is_atom(App) -> + _ = application:load(App), + {ok, Mods} = application:get_key(App, modules), + flatten(Tail, [Mods | Acc]); +flatten([Input | Tail], Acc) -> + flatten(Tail, [Input | Acc]). ensure_pattern(Input) -> - case [S || S={scope, _} <- Input] of - Input -> ['_'|Input]; - _ -> Input - end. + case [S || S = {scope, _} <- Input] of + Input -> ['_' | Input]; + _ -> Input + end. ensure_scope(Input) -> - case [S || S={scope, _} <- Input] of - [] -> [{scope, [processes]}|Input]; - _ -> Input - end. + case [S || S = {scope, _} <- Input] of + [] -> [{scope, [processes]} | Input]; + _ -> Input + end. trace_input([], _, _) -> - ok; -trace_input([{scope, Scope}|Tail], TracerState, Opts) -> - %% We currently enable the following trace flags: - %% - call: function calls - %% - procs: process exit events; plus others we ignore - %% - running: process being scheduled in/out - %% - timestamp: events include the current timestamp - %% - arity: function calls only include the arity, not arguments - %% - return_to: return from functions - %% - set_on_spawn: propagate trace flags to any children processes - %% - %% @todo It might be useful to count the number of sends - %% or receives a function does. - ExtraFlags = [running || maps:get(running, Opts, false)] - ++ [send || maps:get(send, Opts, false)], - _ = [erlang:trace(PidPortSpec, true, [ - call, procs, timestamp, arity, return_to, set_on_spawn, - {tracer, lg_tracer, TracerState} - |ExtraFlags - ]) - || PidPortSpec <- Scope], - trace_input(Tail, TracerState, Opts); -trace_input([Mod|Tail], TracerState, Opts) when is_atom(Mod) -> - MatchSpec = case Opts of - #{process_dump := true} -> [{'_', [], [{message, {process_dump}}]}]; - _ -> true - end, - %% The module must be loaded before we attempt to trace it. - _ = code:ensure_loaded(Mod), - _ = erlang:trace_pattern({Mod, '_', '_'}, MatchSpec, [local]), - trace_input(Tail, TracerState, Opts). + ok; +trace_input([{scope, Scope} | Tail], TracerState, Opts) -> + %% We currently enable the following trace flags: + %% - call: function calls + %% - procs: process exit events; plus others we ignore + %% - running: process being scheduled in/out + %% - timestamp: events include the current timestamp + %% - arity: function calls only include the arity, not arguments + %% - return_to: return from functions + %% - set_on_spawn: propagate trace flags to any children processes + %% + %% @todo It might be useful to count the number of sends + %% or receives a function does. + ExtraFlags = [running || maps:get(running, Opts, false)] + ++ [send || maps:get(send, Opts, false)], + _ = [erlang:trace(PidPortSpec, true, [ + call, procs, timestamp, arity, return_to, set_on_spawn, + {tracer, lg_tracer, TracerState} + | ExtraFlags + ]) + || PidPortSpec <- Scope], + trace_input(Tail, TracerState, Opts); +trace_input([Mod | Tail], TracerState, Opts) when is_atom(Mod) -> + MatchSpec = case Opts of + #{process_dump := true} -> [{'_', [], [{message, {process_dump}}]}]; + _ -> true + end, + %% The module must be loaded before we attempt to trace it. + _ = code:ensure_loaded(Mod), + _ = erlang:trace_pattern({Mod, '_', '_'}, MatchSpec, [local]), + trace_input(Tail, TracerState, Opts). stop() -> - stop(default). + stop(default). %% @todo Confirm that we don't need to stop tracing, %% that just terminating the tracers is enough. The %% NIF does cancel traces when tracers go away, but %% better make sure. stop(PoolID) -> - supervisor:terminate_child(looking_glass_sup, PoolID). + supervisor:terminate_child(looking_glass_sup, PoolID). diff --git a/src/eTpf_app.erl b/src/eTpf_app.erl index 84fa3c9..f9fb5fa 100644 --- a/src/eTpf_app.erl +++ b/src/eTpf_app.erl @@ -10,9 +10,9 @@ -export([start/2, stop/1]). start(_StartType, _StartArgs) -> - eTpf_sup:start_link(). + eTpf_sup:start_link(). stop(_State) -> - ok. + ok. %% internal functions diff --git a/src/eTpf_sup.erl b/src/eTpf_sup.erl index 81e2b4e..0999e57 100644 --- a/src/eTpf_sup.erl +++ b/src/eTpf_sup.erl @@ -14,7 +14,7 @@ -define(SERVER, ?MODULE). start_link() -> - supervisor:start_link({local, ?SERVER}, ?MODULE, []). + supervisor:start_link({local, ?SERVER}, ?MODULE, []). %% sup_flags() = #{strategy => strategy(), % optional %% intensity => non_neg_integer(), % optional @@ -26,10 +26,10 @@ start_link() -> %% type => worker(), % optional %% modules => modules()} % optional init([]) -> - SupFlags = #{strategy => one_for_all, - intensity => 0, - period => 1}, - ChildSpecs = [], - {ok, {SupFlags, ChildSpecs}}. + SupFlags = #{strategy => one_for_all, + intensity => 0, + period => 1}, + ChildSpecs = [], + {ok, {SupFlags, ChildSpecs}}. %% internal functions diff --git a/src/profile/lg_callgrind.erl b/src/profile/lg_callgrind.erl index 73245ec..f65e56c 100644 --- a/src/profile/lg_callgrind.erl +++ b/src/profile/lg_callgrind.erl @@ -23,166 +23,166 @@ %% @todo Add an option with a list of modules to exclude. -type opts() :: #{ - %% Whether we filter the output per process. - scope => global | per_process, - %% Whether we compute and save wait times. - running => boolean() +%% Whether we filter the output per process. +scope => global | per_process, +%% Whether we compute and save wait times. +running => boolean() }. -record(call, { - %% The MFA for the call. - mfa :: atom(), - %% The source file name. - source :: {string(), pos_integer()}, - %% The timestamp for the call. - ts :: pos_integer(), - %% The timestamp for when we last started executing this function. - self_ts :: pos_integer(), - %% Execution time including subcalls. - incl :: undefined | non_neg_integer(), - %% Execution time excluding subcalls. - self = 0 :: integer(), - %% Number of times the function was called. - count = 1 :: pos_integer(), - %% Time when the process was not running in this function. - wait = 0 :: non_neg_integer(), - %% Time when the process was not running in this function or any subcalls. - wait_incl = 0 :: non_neg_integer(), - %% Number of times the process was scheduled out. - wait_count = 0 :: non_neg_integer(), - %% Number of times the function or any subcall was scheduled out. - wait_count_incl = 0 :: non_neg_integer(), - %% Calls done by this MFA. - calls = #{} :: #{atom() => #call{}} + %% The MFA for the call. + mfa :: atom(), + %% The source file name. + source :: {string(), pos_integer()}, + %% The timestamp for the call. + ts :: pos_integer(), + %% The timestamp for when we last started executing this function. + self_ts :: pos_integer(), + %% Execution time including subcalls. + incl :: undefined | non_neg_integer(), + %% Execution time excluding subcalls. + self = 0 :: integer(), + %% Number of times the function was called. + count = 1 :: pos_integer(), + %% Time when the process was not running in this function. + wait = 0 :: non_neg_integer(), + %% Time when the process was not running in this function or any subcalls. + wait_incl = 0 :: non_neg_integer(), + %% Number of times the process was scheduled out. + wait_count = 0 :: non_neg_integer(), + %% Number of times the function or any subcall was scheduled out. + wait_count_incl = 0 :: non_neg_integer(), + %% Calls done by this MFA. + calls = #{} :: #{atom() => #call{}} }). -record(proc, { - %% Call stack. - stack = [] :: [#call{}], - %% Profile information waiting to be written to file. - mfas = #{} :: #{atom() => #call{}}, - %% Timestamp the process got scheduled out. - out = undefined :: undefined | non_neg_integer() + %% Call stack. + stack = [] :: [#call{}], + %% Profile information waiting to be written to file. + mfas = #{} :: #{atom() => #call{}}, + %% Timestamp the process got scheduled out. + out = undefined :: undefined | non_neg_integer() }). -record(state, { - %% Input file name. - input :: file:filename_all(), - %% Output file name. - output :: file:filename_all(), - %% Output fd. - output_device :: file:io_device(), - %% Options. - opts :: opts(), - %% List of processes. - processes = #{} :: #{pid() => #proc{}}, - %% Cache of source file information. - sources = #{} :: #{mfa() => {string(), pos_integer()}} + %% Input file name. + input :: file:filename_all(), + %% Output file name. + output :: file:filename_all(), + %% Output fd. + output_device :: file:io_device(), + %% Options. + opts :: opts(), + %% List of processes. + processes = #{} :: #{pid() => #proc{}}, + %% Cache of source file information. + sources = #{} :: #{mfa() => {string(), pos_integer()}} }). -spec patterns() -> eTpf:input(). patterns() -> - [{app, kernel}, {app, stdlib}, {app, looking_glass}]. + [{app, kernel}, {app, stdlib}, {app, looking_glass}]. -spec profile(file:filename_all(), file:filename_all()) -> ok. profile(Input, Output) -> - profile(Input, Output, #{}). + profile(Input, Output, #{}). -spec profile(file:filename_all(), file:filename_all(), opts()) -> ok. profile(Input, Output, Opts) -> - {ok, OutDevice} = file:open(Output, [write]), - State = #state{input=Input, output=Output, output_device=OutDevice, opts=Opts}, - write_header(State), - {ok, FinalState} = lg_file_reader:fold(fun handle_event/2, State, Input), - flush(FinalState), - _ = file:close(OutDevice), - ok. - -flush(State=#state{processes=Procs}) -> - maps:fold(fun(Pid, #proc{mfas=MFAs}, _) -> - write_mfas(Pid, MFAs, State) - end, undefined, Procs), - ok. + {ok, OutDevice} = file:open(Output, [write]), + State = #state{input = Input, output = Output, output_device = OutDevice, opts = Opts}, + write_header(State), + {ok, FinalState} = lg_file_reader:fold(fun handle_event/2, State, Input), + flush(FinalState), + _ = file:close(OutDevice), + ok. + +flush(State = #state{processes = Procs}) -> + maps:fold(fun(Pid, #proc{mfas = MFAs}, _) -> + write_mfas(Pid, MFAs, State) + end, undefined, Procs), + ok. -spec profile_many(file:filename(), file:filename()) -> ok. profile_many(Wildcard, Prefix) -> - profile_many(Wildcard, Prefix, #{}). + profile_many(Wildcard, Prefix, #{}). -spec profile_many(file:filename(), file:filename(), opts()) -> ok. profile_many(Wildcard, Prefix, Opts) -> - Files = filelib:wildcard(Wildcard), - Seq = lists:seq(1, length(Files)), - OutFiles = [Prefix ++ "." ++ integer_to_list(N) || N <- Seq], - Many = lists:zip(Files, OutFiles), - Refs = [monitor(process, spawn_link(?MODULE, profile, [Input, Output, Opts])) - || {Input, Output} <- Many], - wait_for_procs(Refs). + Files = filelib:wildcard(Wildcard), + Seq = lists:seq(1, length(Files)), + OutFiles = [Prefix ++ "." ++ integer_to_list(N) || N <- Seq], + Many = lists:zip(Files, OutFiles), + Refs = [monitor(process, spawn_link(?MODULE, profile, [Input, Output, Opts])) + || {Input, Output} <- Many], + wait_for_procs(Refs). %% We do not need to worry about failure because we are linked. wait_for_procs([]) -> - ok; + ok; wait_for_procs(Refs) -> - receive - %% We purposefully ignore any stray messages. - {'DOWN', R, process, _, _} -> - wait_for_procs(Refs -- [R]) - end. + receive + %% We purposefully ignore any stray messages. + {'DOWN', R, process, _, _} -> + wait_for_procs(Refs -- [R]) + end. %% We handle trace events one by one, keeping track of the %% execution stack for each process. %% We don't care about match spec results for callgrind. handle_event({call, Pid, Ts, MFA, _MSpec}, State) -> - handle_event({call, Pid, Ts, MFA}, State); + handle_event({call, Pid, Ts, MFA}, State); handle_event({call, Pid, Ts, MFA}, State0) -> - Proc = case is_process_profiled(Pid, State0) of - {true, P} -> P; - {empty, P} -> P; - false -> #proc{} - end, - {Source, State} = find_source(MFA, State0), - handle_call(Pid, convert_mfa(MFA), Source, Ts, Proc, State); + Proc = case is_process_profiled(Pid, State0) of + {true, P} -> P; + {empty, P} -> P; + false -> #proc{} + end, + {Source, State} = find_source(MFA, State0), + handle_call(Pid, convert_mfa(MFA), Source, Ts, Proc, State); handle_event({return_to, Pid, Ts, MFA}, State) -> - case is_process_profiled(Pid, State) of - {true, Proc} -> handle_return_to(Pid, convert_mfa(MFA), Ts, Proc, State); - _ -> State - end; + case is_process_profiled(Pid, State) of + {true, Proc} -> handle_return_to(Pid, convert_mfa(MFA), Ts, Proc, State); + _ -> State + end; %% Process exited. Unfold the stacktrace entirely. %% %% We use the atom exit because we know it will not match %% a function call and will therefore unfold everything. handle_event({exit, Pid, Ts, _Reason}, State0) -> - case is_process_profiled(Pid, State0) of - {true, Proc} -> - State=#state{processes=Procs} = handle_return_to(Pid, exit, Ts, Proc, State0), - %% Remove the pid from the state to save memory. - State#state{processes=maps:remove(Pid, Procs)}; - _ -> - State0 - end; -handle_event({in, Pid, Ts, _MFA}, State=#state{opts=#{running := true}}) -> - case is_process_profiled(Pid, State) of - {true, Proc} -> handle_in(Pid, Ts, Proc, State); - _ -> State - end; -handle_event({out, Pid, Ts, _MFA}, State=#state{opts=#{running := true}}) -> - case is_process_profiled(Pid, State) of - {true, Proc} -> handle_out(Pid, Ts, Proc, State); - _ -> State - end; + case is_process_profiled(Pid, State0) of + {true, Proc} -> + State = #state{processes = Procs} = handle_return_to(Pid, exit, Ts, Proc, State0), + %% Remove the pid from the state to save memory. + State#state{processes = maps:remove(Pid, Procs)}; + _ -> + State0 + end; +handle_event({in, Pid, Ts, _MFA}, State = #state{opts = #{running := true}}) -> + case is_process_profiled(Pid, State) of + {true, Proc} -> handle_in(Pid, Ts, Proc, State); + _ -> State + end; +handle_event({out, Pid, Ts, _MFA}, State = #state{opts = #{running := true}}) -> + case is_process_profiled(Pid, State) of + {true, Proc} -> handle_out(Pid, Ts, Proc, State); + _ -> State + end; %% Ignore all other events. We do not need them for building the callgrind file. handle_event(_, State) -> - State. - -is_process_profiled(Pid, #state{processes=Procs}) -> - case maps:get(Pid, Procs, undefined) of - %% We never received events for this process. Ignore. - undefined -> false; - %% We received events but are not in a known function currently. Ignore. - Proc=#proc{stack=[]} -> {empty, Proc}; - %% All good! - Proc -> {true, Proc} - end. + State. + +is_process_profiled(Pid, #state{processes = Procs}) -> + case maps:get(Pid, Procs, undefined) of + %% We never received events for this process. Ignore. + undefined -> false; + %% We received events but are not in a known function currently. Ignore. + Proc = #proc{stack = []} -> {empty, Proc}; + %% All good! + Proc -> {true, Proc} + end. %% We track a number of different things: %% - how much time was spent in the different function calls @@ -204,17 +204,17 @@ is_process_profiled(Pid, #state{processes=Procs}) -> %% Recursive call. Just increase the call count. handle_call(Pid, MFA, _Source, _Ts, - Proc0=#proc{stack=[Call=#call{mfa=MFA, count=Count}|Stack0]}, - State=#state{processes=Procs}) -> - Stack = [Call#call{count=Count + 1}|Stack0], - Proc = Proc0#proc{stack=Stack}, - State#state{processes=Procs#{Pid => Proc}}; + Proc0 = #proc{stack = [Call = #call{mfa = MFA, count = Count} | Stack0]}, + State = #state{processes = Procs}) -> + Stack = [Call#call{count = Count + 1} | Stack0], + Proc = Proc0#proc{stack = Stack}, + State#state{processes = Procs#{Pid => Proc}}; %% Non-recursive call. -handle_call(Pid, MFA, Source, Ts, Proc0=#proc{stack=Stack0}, - State=#state{processes=Procs}) -> - Stack = [#call{mfa=MFA, source=Source, ts=Ts, self_ts=Ts}|Stack0], - Proc = Proc0#proc{stack=Stack}, - State#state{processes=Procs#{Pid => Proc}}. +handle_call(Pid, MFA, Source, Ts, Proc0 = #proc{stack = Stack0}, + State = #state{processes = Procs}) -> + Stack = [#call{mfa = MFA, source = Source, ts = Ts, self_ts = Ts} | Stack0], + Proc = Proc0#proc{stack = Stack}, + State#state{processes = Procs#{Pid => Proc}}. %% We return from the current call, so the current call %% ends regardless of what it was doing. We stop as soon @@ -247,119 +247,119 @@ handle_call(Pid, MFA, Source, Ts, Proc0=#proc{stack=Stack0}, %% and the return time for the end. Here again we also %% update the sub call times. -handle_return_to(Pid, MFA, Ts, Proc0=#proc{stack=[Current0|Stack0], mfas=MFAs0}, - State=#state{processes=Procs}) -> - {Returned0, Stack1} = lists:splitwith( - fun(#call{mfa=E}) -> E =/= MFA end, - Stack0), - #call{ts=CurrentTs, self_ts=CurrentSelfTs, self=CurrentSelf} = Current0, - Current = Current0#call{incl=Ts - CurrentTs, self=CurrentSelf + Ts - CurrentSelfTs}, - Returned = update_tail_calls([Current|Returned0], Ts), - Stack = update_stack(Returned, Stack1, Ts), - %% Save the profile information in the state, potentially flushing it - %% to disk if the stack is empty. - MFAs1 = update_mfas(Returned, MFAs0), - MFAs = case Stack of - [] -> - write_mfas(Pid, MFAs1, State), - #{}; - _ -> - MFAs1 - end, - Proc = Proc0#proc{stack=Stack, mfas=MFAs}, - State#state{processes=Procs#{Pid => Proc}}. +handle_return_to(Pid, MFA, Ts, Proc0 = #proc{stack = [Current0 | Stack0], mfas = MFAs0}, + State = #state{processes = Procs}) -> + {Returned0, Stack1} = lists:splitwith( + fun(#call{mfa = E}) -> E =/= MFA end, + Stack0), + #call{ts = CurrentTs, self_ts = CurrentSelfTs, self = CurrentSelf} = Current0, + Current = Current0#call{incl = Ts - CurrentTs, self = CurrentSelf + Ts - CurrentSelfTs}, + Returned = update_tail_calls([Current | Returned0], Ts), + Stack = update_stack(Returned, Stack1, Ts), + %% Save the profile information in the state, potentially flushing it + %% to disk if the stack is empty. + MFAs1 = update_mfas(Returned, MFAs0), + MFAs = case Stack of + [] -> + write_mfas(Pid, MFAs1, State), + #{}; + _ -> + MFAs1 + end, + Proc = Proc0#proc{stack = Stack, mfas = MFAs}, + State#state{processes = Procs#{Pid => Proc}}. update_tail_calls([Call], _) -> - [Call]; + [Call]; update_tail_calls([ - Callee=#call{ts=CalleeTs}, - Caller0=#call{ts=CallerTs, self_ts=CallerSelfTs, self=CallerSelf} - |Tail], ReturnToTs) -> - Caller1 = Caller0#call{ - incl=ReturnToTs - CallerTs, - self=CallerSelf + CalleeTs - CallerSelfTs - }, - Caller = update_sub_calls(Callee, Caller1), - [Callee|update_tail_calls([Caller|Tail], ReturnToTs)]. + Callee = #call{ts = CalleeTs}, + Caller0 = #call{ts = CallerTs, self_ts = CallerSelfTs, self = CallerSelf} + | Tail], ReturnToTs) -> + Caller1 = Caller0#call{ + incl = ReturnToTs - CallerTs, + self = CallerSelf + CalleeTs - CallerSelfTs + }, + Caller = update_sub_calls(Callee, Caller1), + [Callee | update_tail_calls([Caller | Tail], ReturnToTs)]. %% Update nothing; there's nothing in the stack. update_stack(_, [], _) -> - []; + []; %% Update the incl/self value based on the top-level function we return from, %% but only update the sub calls based on the function we directly called. update_stack(Returned, - [Caller0=#call{self_ts=CallerSelfTs, self=CallerSelf}|Stack], - ReturnToTs) -> - Callee = #call{ts=CalleeTs} = hd(lists:reverse(Returned)), - Caller = Caller0#call{ - self_ts=ReturnToTs, - self=CallerSelf + CalleeTs - CallerSelfTs - }, - [update_sub_calls(Callee, Caller)|Stack]. - -update_sub_calls(Callee=#call{mfa=MFA, incl=CallerIncl, count=CallerCount, - wait_incl=CallerWaitIncl}, Caller=#call{calls=SubCalls}) -> - case maps:get(MFA, SubCalls, undefined) of - %% Add the callee to the subcalls but remove the callee's subcalls - %% since we don't need those here. - undefined -> - Caller#call{calls=SubCalls#{MFA => Callee#call{calls=#{}}}}; - %% Same as above, except we add to the existing values. - Sub = #call{incl=SubIncl, count=SubCount, wait_incl=SubWaitIncl} -> - Caller#call{calls=SubCalls#{MFA => Sub#call{ - %% We do not care about self/wait here as we will be using incl/wait_incl in the output. - incl=SubIncl + CallerIncl, - count=SubCount + CallerCount, - wait_incl=SubWaitIncl + CallerWaitIncl - }}} - end. + [Caller0 = #call{self_ts = CallerSelfTs, self = CallerSelf} | Stack], + ReturnToTs) -> + Callee = #call{ts = CalleeTs} = hd(lists:reverse(Returned)), + Caller = Caller0#call{ + self_ts = ReturnToTs, + self = CallerSelf + CalleeTs - CallerSelfTs + }, + [update_sub_calls(Callee, Caller) | Stack]. + +update_sub_calls(Callee = #call{mfa = MFA, incl = CallerIncl, count = CallerCount, + wait_incl = CallerWaitIncl}, Caller = #call{calls = SubCalls}) -> + case maps:get(MFA, SubCalls, undefined) of + %% Add the callee to the subcalls but remove the callee's subcalls + %% since we don't need those here. + undefined -> + Caller#call{calls = SubCalls#{MFA => Callee#call{calls = #{}}}}; + %% Same as above, except we add to the existing values. + Sub = #call{incl = SubIncl, count = SubCount, wait_incl = SubWaitIncl} -> + Caller#call{calls = SubCalls#{MFA => Sub#call{ + %% We do not care about self/wait here as we will be using incl/wait_incl in the output. + incl = SubIncl + CallerIncl, + count = SubCount + CallerCount, + wait_incl = SubWaitIncl + CallerWaitIncl + }}} + end. %% Processes get scheduled in and out. We get the corresponding %% in and out events when the 'running' option is set to true. %% We keep track of how many times the process was scheduled out %% per function, and how long. -handle_in(Pid, InTs, Proc0=#proc{stack=[Current0|Stack0], out=OutTs}, - State=#state{processes=Procs}) -> - #call{wait=Wait, wait_incl=WaitIncl, - wait_count=WaitCount, wait_count_incl=WaitCountIncl - } = Current0, - ThisWait = InTs - OutTs, - %% We increase the wait time for self first. - Current = Current0#call{wait=Wait + ThisWait, wait_incl=WaitIncl + ThisWait, - wait_count=WaitCount + 1, wait_count_incl=WaitCountIncl + 1}, - %% And then for the parent calls to include wait time of subcalls. - Stack = [ - Call#call{wait_incl=ParentWaitIncl + ThisWait, wait_count_incl=ParentWaitCount + 1} - || Call=#call{wait_incl=ParentWaitIncl, wait_count_incl=ParentWaitCount} <- Stack0], - Proc = Proc0#proc{stack=[Current|Stack], out=undefined}, - State#state{processes=Procs#{Pid => Proc}}. - -handle_out(Pid, Ts, Proc0=#proc{out=undefined}, - State=#state{processes=Procs}) -> - Proc = Proc0#proc{out=Ts}, - State#state{processes=Procs#{Pid => Proc}}. +handle_in(Pid, InTs, Proc0 = #proc{stack = [Current0 | Stack0], out = OutTs}, + State = #state{processes = Procs}) -> + #call{wait = Wait, wait_incl = WaitIncl, + wait_count = WaitCount, wait_count_incl = WaitCountIncl + } = Current0, + ThisWait = InTs - OutTs, + %% We increase the wait time for self first. + Current = Current0#call{wait = Wait + ThisWait, wait_incl = WaitIncl + ThisWait, + wait_count = WaitCount + 1, wait_count_incl = WaitCountIncl + 1}, + %% And then for the parent calls to include wait time of subcalls. + Stack = [ + Call#call{wait_incl = ParentWaitIncl + ThisWait, wait_count_incl = ParentWaitCount + 1} + || Call = #call{wait_incl = ParentWaitIncl, wait_count_incl = ParentWaitCount} <- Stack0], + Proc = Proc0#proc{stack = [Current | Stack], out = undefined}, + State#state{processes = Procs#{Pid => Proc}}. + +handle_out(Pid, Ts, Proc0 = #proc{out = undefined}, + State = #state{processes = Procs}) -> + Proc = Proc0#proc{out = Ts}, + State#state{processes = Procs#{Pid => Proc}}. %% Update the profiling information we currently hold. update_mfas([], MFAs) -> - MFAs; -update_mfas([Call=#call{mfa=MFA, incl=Incl, self=Self, wait=Wait, wait_incl=WaitIncl, - wait_count=WaitCount, wait_count_incl=WaitCountIncl, - count=Count, calls=SubCalls}|Tail], MFAs) -> - case MFAs of - #{MFA := AggCall0=#call{incl=AggIncl, self=AggSelf, wait=AggWait, wait_incl=AggWaitIncl, - wait_count=AggWaitCount, wait_count_incl=AggWaitCountIncl, - count=AggCount, calls=AggSubCalls0}} -> - AggSubCalls = update_mfas(maps:values(SubCalls), AggSubCalls0), - AggCall=AggCall0#call{incl=Incl + AggIncl, self=Self + AggSelf, - wait=Wait + AggWait, wait_incl=WaitIncl + AggWaitIncl, - wait_count=WaitCount + AggWaitCount, - wait_count_incl=WaitCountIncl + AggWaitCountIncl, - count=Count + AggCount, calls=AggSubCalls}, - update_mfas(Tail, MFAs#{MFA => AggCall}); - _ -> - update_mfas(Tail, MFAs#{MFA => Call}) - end. + MFAs; +update_mfas([Call = #call{mfa = MFA, incl = Incl, self = Self, wait = Wait, wait_incl = WaitIncl, + wait_count = WaitCount, wait_count_incl = WaitCountIncl, + count = Count, calls = SubCalls} | Tail], MFAs) -> + case MFAs of + #{MFA := AggCall0 = #call{incl = AggIncl, self = AggSelf, wait = AggWait, wait_incl = AggWaitIncl, + wait_count = AggWaitCount, wait_count_incl = AggWaitCountIncl, + count = AggCount, calls = AggSubCalls0}} -> + AggSubCalls = update_mfas(maps:values(SubCalls), AggSubCalls0), + AggCall = AggCall0#call{incl = Incl + AggIncl, self = Self + AggSelf, + wait = Wait + AggWait, wait_incl = WaitIncl + AggWaitIncl, + wait_count = WaitCount + AggWaitCount, + wait_count_incl = WaitCountIncl + AggWaitCountIncl, + count = Count + AggCount, calls = AggSubCalls}, + update_mfas(Tail, MFAs#{MFA => AggCall}); + _ -> + update_mfas(Tail, MFAs#{MFA => Call}) + end. %% The callgrind format is documented at http://valgrind.org/docs/manual/cl-format.html %% @@ -368,96 +368,96 @@ update_mfas([Call=#call{mfa=MFA, incl=Incl, self=Self, wait=Wait, wait_incl=Wait %% %% The option 'scope' can be used to enable per process tracking. -write_header(#state{output_device=OutDevice, opts=#{running := true}}) -> - ok = file:write(OutDevice, - "# callgrind format\n" - "events: Total Active Wait WaitCount\n" - "event: Total : Total time in microseconds\n" - "event: Active : Active time in microseconds\n" - "event: Wait : Wait time in microseconds (scheduled out)\n" - "event: WaitCount : Number of times the process was scheduled out\n" - "\n"); -write_header(#state{output_device=OutDevice}) -> - ok = file:write(OutDevice, - "# callgrind format\n" - "events: Total\n" - "event: Total : Total time in microseconds\n" - "\n"). +write_header(#state{output_device = OutDevice, opts = #{running := true}}) -> + ok = file:write(OutDevice, + "# callgrind format\n" + "events: Total Active Wait WaitCount\n" + "event: Total : Total time in microseconds\n" + "event: Active : Active time in microseconds\n" + "event: Wait : Wait time in microseconds (scheduled out)\n" + "event: WaitCount : Number of times the process was scheduled out\n" + "\n"); +write_header(#state{output_device = OutDevice}) -> + ok = file:write(OutDevice, + "# callgrind format\n" + "events: Total\n" + "event: Total : Total time in microseconds\n" + "\n"). write_mfas(Pid, MFAs, State) -> - _ = [write_call(Pid, Call, State) || Call <- maps:values(MFAs)], - ok. - -write_call(Pid, #call{mfa=MFA, source={Source, LN}, self=Self, wait=Wait, - wait_count=WaitCount, calls=Calls0}, - #state{output_device=OutDevice, opts=Opts}) -> - Calls = maps:values(Calls0), - Ob = case Opts of - #{scope := per_process} -> - ["ob=", io_lib:write(Pid), "\n"]; - _ -> - [] - end, - RunningCosts = case Opts of - #{running := true} -> - [ - " ", integer_to_list(Self - Wait), - " ", integer_to_list(Wait), - " ", integer_to_list(WaitCount) - ]; - _ -> - [] - end, - file:write(OutDevice, [Ob, - "fl=", Source, "\n" - "fn=", atom_to_list(MFA), "\n", - integer_to_list(LN), " ", integer_to_list(Self), RunningCosts, "\n", - format_subcalls(LN, Calls, Opts), - "\n"]). + _ = [write_call(Pid, Call, State) || Call <- maps:values(MFAs)], + ok. + +write_call(Pid, #call{mfa = MFA, source = {Source, LN}, self = Self, wait = Wait, + wait_count = WaitCount, calls = Calls0}, + #state{output_device = OutDevice, opts = Opts}) -> + Calls = maps:values(Calls0), + Ob = case Opts of + #{scope := per_process} -> + ["ob=", io_lib:write(Pid), "\n"]; + _ -> + [] + end, + RunningCosts = case Opts of + #{running := true} -> + [ + " ", integer_to_list(Self - Wait), + " ", integer_to_list(Wait), + " ", integer_to_list(WaitCount) + ]; + _ -> + [] + end, + file:write(OutDevice, [Ob, + "fl=", Source, "\n" + "fn=", atom_to_list(MFA), "\n", + integer_to_list(LN), " ", integer_to_list(Self), RunningCosts, "\n", + format_subcalls(LN, Calls, Opts), + "\n"]). format_subcalls(_, [], _) -> - []; + []; %% @todo We don't need to write the filename for functions in the same module. %% @todo We also don't want to put the full file name; instead we should remove %% the prefix (path to the release). %% %% We only look at where the function is defined, we can't really get %% the actual line number where the call happened, unfortunately. -format_subcalls(LN, [#call{mfa=MFA, source={Source, TargetLN}, incl=Incl, - wait_incl=Wait, wait_count_incl=WaitCount, count=Count, calls=_Calls}|Tail], Opts) -> - RunningCosts = case Opts of - #{running := true} -> - [ - " ", integer_to_list(Incl - Wait), - " ", integer_to_list(Wait), - " ", integer_to_list(WaitCount) - ]; - _ -> - [] - end, - [[ - "cfi=", Source, "\n" - "cfn=", atom_to_list(MFA), "\n" - "calls=", integer_to_list(Count), " ", integer_to_list(TargetLN), "\n", - integer_to_list(LN), " ", integer_to_list(Incl), RunningCosts, "\n" - ]|format_subcalls(LN, Tail, Opts)]. +format_subcalls(LN, [#call{mfa = MFA, source = {Source, TargetLN}, incl = Incl, + wait_incl = Wait, wait_count_incl = WaitCount, count = Count, calls = _Calls} | Tail], Opts) -> + RunningCosts = case Opts of + #{running := true} -> + [ + " ", integer_to_list(Incl - Wait), + " ", integer_to_list(Wait), + " ", integer_to_list(WaitCount) + ]; + _ -> + [] + end, + [[ + "cfi=", Source, "\n" + "cfn=", atom_to_list(MFA), "\n" + "calls=", integer_to_list(Count), " ", integer_to_list(TargetLN), "\n", + integer_to_list(LN), " ", integer_to_list(Incl), RunningCosts, "\n" + ] | format_subcalls(LN, Tail, Opts)]. convert_mfa(undefined) -> - undefined; + undefined; convert_mfa({M0, F0, A0}) -> - M = atom_to_binary(M0, latin1), - F = atom_to_binary(F0, latin1), - A = integer_to_binary(A0), - binary_to_atom(<>, latin1). - -find_source(MFA, State0=#state{sources=Cache}) -> - case Cache of - #{MFA := Source} -> - {Source, State0}; - _ -> - State = #state{sources=#{MFA := Source}} = cache_module(MFA, State0), - {Source, State} - end. + M = atom_to_binary(M0, latin1), + F = atom_to_binary(F0, latin1), + A = integer_to_binary(A0), + binary_to_atom(<>, latin1). + +find_source(MFA, State0 = #state{sources = Cache}) -> + case Cache of + #{MFA := Source} -> + {Source, State0}; + _ -> + State = #state{sources = #{MFA := Source}} = cache_module(MFA, State0), + {Source, State} + end. %% We extract the line number of the functions by loading the %% beam file (which is already loaded when we reach this function) @@ -473,40 +473,40 @@ find_source(MFA, State0=#state{sources=Cache}) -> %% %% While this is an expensive operation, we cache the result %% and therefore this function will only be called once per module. -cache_module(MFA={Module, _, _}, State0=#state{sources=Cache}) -> - try - %% If the module is in the path, we can simply query - %% it for the source file. - Info = Module:module_info(compile), - %% @todo We don't want to return an absolute path, - %% but rather the app/src/file.erl path if it's in - %% an application, or just folder/file.erl if not. - %% This allows different users to point to the - %% same source at different locations on their machine. - {_, Src} = lists:keyfind(source, 1, Info), - cache_module(MFA, State0, Src) - catch _:_ -> - %% Either the module was not found, or it doesn't - %% have a 'source' key in the compile info. - %% - %% We can't cache the module; on the other hand - %% we can cache the result of this operation. - %% Just append .erl to the module name and set the - %% line number to 1, which is of course incorrect. - State0#state{sources=Cache#{MFA => {atom_to_list(Module) ++ ".erl", 1}}} - end. - -cache_module(MFA={Module, _, _}, State=#state{sources=Cache0}, Src) -> - {Module, Beam, _} = code:get_object_code(Module), - {ok, {Module, Chunks}} = beam_lib:chunks(Beam, [abstract_code]), - [{abstract_code, {raw_abstract_v1, Forms}}] = Chunks, - Funcs = [{{Module, F, A}, LN} || {function, LN, F, A, _} <- Forms], - Cache1 = lists:foldl(fun({Key, LN}, Acc) -> Acc#{Key => {Src, LN}} end, Cache0, Funcs), - %% We cannot currently retrieve line number information - %% for list comprehensions and funs. We therefore - %% cache the correct file with line number set to 1. - Cache = case Cache1 of - #{MFA := _} -> Cache1; - _ -> Cache1#{MFA => {Src, 1}} - end, - State#state{sources=Cache}. +cache_module(MFA = {Module, _, _}, State0 = #state{sources = Cache}) -> + try + %% If the module is in the path, we can simply query + %% it for the source file. + Info = Module:module_info(compile), + %% @todo We don't want to return an absolute path, + %% but rather the app/src/file.erl path if it's in + %% an application, or just folder/file.erl if not. + %% This allows different users to point to the + %% same source at different locations on their machine. + {_, Src} = lists:keyfind(source, 1, Info), + cache_module(MFA, State0, Src) + catch _:_ -> + %% Either the module was not found, or it doesn't + %% have a 'source' key in the compile info. + %% + %% We can't cache the module; on the other hand + %% we can cache the result of this operation. + %% Just append .erl to the module name and set the + %% line number to 1, which is of course incorrect. + State0#state{sources = Cache#{MFA => {atom_to_list(Module) ++ ".erl", 1}}} + end. + +cache_module(MFA = {Module, _, _}, State = #state{sources = Cache0}, Src) -> + {Module, Beam, _} = code:get_object_code(Module), + {ok, {Module, Chunks}} = beam_lib:chunks(Beam, [abstract_code]), + [{abstract_code, {raw_abstract_v1, Forms}}] = Chunks, + Funcs = [{{Module, F, A}, LN} || {function, LN, F, A, _} <- Forms], + Cache1 = lists:foldl(fun({Key, LN}, Acc) -> Acc#{Key => {Src, LN}} end, Cache0, Funcs), + %% We cannot currently retrieve line number information + %% for list comprehensions and funs. We therefore + %% cache the correct file with line number set to 1. + Cache = case Cache1 of + #{MFA := _} -> Cache1; + _ -> Cache1#{MFA => {Src, 1}} + end, + State#state{sources = Cache}. diff --git a/src/profile/lg_file_reader.erl b/src/profile/lg_file_reader.erl index d6bca3c..823f8f1 100644 --- a/src/profile/lg_file_reader.erl +++ b/src/profile/lg_file_reader.erl @@ -22,85 +22,85 @@ -export([close/1]). -record(state, { - io_device :: file:io_device(), - ctx :: lz4f:dctx(), - buffer = <<>> :: binary(), - offset = 0 :: non_neg_integer(), - uncompressed_offset = 0 :: non_neg_integer() + io_device :: file:io_device(), + ctx :: lz4f:dctx(), + buffer = <<>> :: binary(), + offset = 0 :: non_neg_integer(), + uncompressed_offset = 0 :: non_neg_integer() }). %% High level API. fold(Fun, Acc, Filename) -> - {ok, IoDevice} = open(Filename), - Ctx = lz4f:create_decompression_context(), - Ret = fold1(#state{io_device=IoDevice, ctx=Ctx}, Fun, Acc), - ok = close(IoDevice), - Ret. + {ok, IoDevice} = open(Filename), + Ctx = lz4f:create_decompression_context(), + Ret = fold1(#state{io_device = IoDevice, ctx = Ctx}, Fun, Acc), + ok = close(IoDevice), + Ret. fold1(State0, Fun, Acc0) -> - case read_event(State0) of - {ok, Event, State} -> - Acc = Fun(Event, Acc0), - fold1(State, Fun, Acc); - eof -> - {ok, Acc0}; - Error = {error, _, _} -> - Error - end. + case read_event(State0) of + {ok, Event, State} -> + Acc = Fun(Event, Acc0), + fold1(State, Fun, Acc); + eof -> + {ok, Acc0}; + Error = {error, _, _} -> + Error + end. foreach(Fun, Filename) -> - {ok, IoDevice} = open(Filename), - Ctx = lz4f:create_decompression_context(), - Ret = foreach1(#state{io_device=IoDevice, ctx=Ctx}, Fun), - ok = close(IoDevice), - Ret. + {ok, IoDevice} = open(Filename), + Ctx = lz4f:create_decompression_context(), + Ret = foreach1(#state{io_device = IoDevice, ctx = Ctx}, Fun), + ok = close(IoDevice), + Ret. foreach1(State0, Fun) -> - case read_event(State0) of - {ok, Event, State} -> - _ = Fun(Event), - foreach1(State, Fun); - eof -> - ok; - Error = {error, _, _} -> - Error - end. + case read_event(State0) of + {ok, Event, State} -> + _ = Fun(Event), + foreach1(State, Fun); + eof -> + ok; + Error = {error, _, _} -> + Error + end. %% Low level API. open(Filename) -> - file:open(Filename, [read, binary]). + file:open(Filename, [read, binary]). -read_event(State=#state{buffer=Buffer}) -> - case Buffer of - <> -> - convert_event_body(State#state{buffer=Rest}, Bin); - _ -> - read_file(State) - end. +read_event(State = #state{buffer = Buffer}) -> + case Buffer of + <> -> + convert_event_body(State#state{buffer = Rest}, Bin); + _ -> + read_file(State) + end. -read_file(State=#state{io_device=IoDevice, ctx=Ctx, buffer=Buffer, offset=Offset}) -> - case file:read(IoDevice, 1000) of - {ok, Data0} -> - Data = iolist_to_binary(lz4f:decompress(Ctx, Data0)), - read_event(State#state{buffer= <>, - offset=Offset + byte_size(Data0)}); - eof -> - eof; - {error, Reason} -> - {error, Reason, - 'An error occurred while trying to read from the file.'} - end. +read_file(State = #state{io_device = IoDevice, ctx = Ctx, buffer = Buffer, offset = Offset}) -> + case file:read(IoDevice, 1000) of + {ok, Data0} -> + Data = iolist_to_binary(lz4f:decompress(Ctx, Data0)), + read_event(State#state{buffer = <>, + offset = Offset + byte_size(Data0)}); + eof -> + eof; + {error, Reason} -> + {error, Reason, + 'An error occurred while trying to read from the file.'} + end. -convert_event_body(State=#state{offset=Offset, uncompressed_offset=UnOffset}, Bin) -> - try binary_to_term(Bin) of - Term -> - {ok, Term, State#state{uncompressed_offset=UnOffset + byte_size(Bin)}} - catch Class:Reason -> - {error, {crash, Class, Reason, Offset, UnOffset}, - 'The binary form of an event could not be decoded to an Erlang term.'} - end. +convert_event_body(State = #state{offset = Offset, uncompressed_offset = UnOffset}, Bin) -> + try binary_to_term(Bin) of + Term -> + {ok, Term, State#state{uncompressed_offset = UnOffset + byte_size(Bin)}} + catch Class:Reason -> + {error, {crash, Class, Reason, Offset, UnOffset}, + 'The binary form of an event could not be decoded to an Erlang term.'} + end. close(IoDevice) -> - file:close(IoDevice). + file:close(IoDevice). diff --git a/src/profile/lg_file_tracer.erl b/src/profile/lg_file_tracer.erl index b8e8da7..e507776 100644 --- a/src/profile/lg_file_tracer.erl +++ b/src/profile/lg_file_tracer.erl @@ -22,80 +22,80 @@ -export([system_code_change/4]). -record(state, { - parent :: pid(), - filename :: file:filename_all(), - size = 0 :: non_neg_integer(), - max_size :: infinity | non_neg_integer(), - io_device :: file:io_device(), - events_per_frame :: pos_integer(), - events_this_frame = 0 :: non_neg_integer(), - buffer = <<>> :: binary() + parent :: pid(), + filename :: file:filename_all(), + size = 0 :: non_neg_integer(), + max_size :: infinity | non_neg_integer(), + io_device :: file:io_device(), + events_per_frame :: pos_integer(), + events_this_frame = 0 :: non_neg_integer(), + buffer = <<>> :: binary() }). start_link(Nth, Prefix) when is_list(Prefix) -> - start_link(Nth, #{filename_prefix => Prefix}); + start_link(Nth, #{filename_prefix => Prefix}); start_link(Nth, Opts) when is_map(Opts) -> - Pid = proc_lib:spawn_link(?MODULE, init, [self(), Nth, Opts]), - {ok, Pid}. + Pid = proc_lib:spawn_link(?MODULE, init, [self(), Nth, Opts]), + {ok, Pid}. init(Parent, Nth, Opts) -> - %% Store all messages off the heap to avoid unnecessary GC. - process_flag(message_queue_data, off_heap), - %% We need to trap exit signals in order to shutdown properly. - process_flag(trap_exit, true), - %% No need to close the file, it'll be closed when the process exits. - Filename = filename:flatten([ - maps:get(filename_prefix, Opts, "traces.lz4"), - ".", integer_to_list(Nth)]), - {ok, IoDevice} = file:open(Filename, [write, raw]), - loop(#state{parent=Parent, filename=Filename, io_device=IoDevice, - max_size=maps:get(max_size, Opts, infinity), - events_per_frame=maps:get(events_per_frame, Opts, 100000)}). + %% Store all messages off the heap to avoid unnecessary GC. + process_flag(message_queue_data, off_heap), + %% We need to trap exit signals in order to shutdown properly. + process_flag(trap_exit, true), + %% No need to close the file, it'll be closed when the process exits. + Filename = filename:flatten([ + maps:get(filename_prefix, Opts, "traces.lz4"), + ".", integer_to_list(Nth)]), + {ok, IoDevice} = file:open(Filename, [write, raw]), + loop(#state{parent = Parent, filename = Filename, io_device = IoDevice, + max_size = maps:get(max_size, Opts, infinity), + events_per_frame = maps:get(events_per_frame, Opts, 100000)}). -loop(State=#state{parent=Parent, size=Size, io_device=IoDevice, - events_per_frame=MaxEvents, events_this_frame=NumEvents0, buffer=Buffer0}) -> - receive - {'EXIT', Parent, Reason} -> - terminate(Reason, State); - {system, From, Request} -> - sys:handle_system_msg(Request, From, Parent, ?MODULE, [], State); - Msg0 -> - Msg = lg_term:truncate(Msg0), - Bin = term_to_binary(Msg), - BinSize = byte_size(Bin), - Buffer = <>, - NumEvents = NumEvents0 + 1, - if - MaxEvents =:= NumEvents -> - Frame = lz4f:compress_frame(Buffer), - ok = file:write(IoDevice, Frame), - maybe_rotate(State#state{size=Size + byte_size(Frame), - events_this_frame=0, buffer= <<>>}); - true -> - loop(State#state{events_this_frame=NumEvents, buffer=Buffer}) - end - end. +loop(State = #state{parent = Parent, size = Size, io_device = IoDevice, + events_per_frame = MaxEvents, events_this_frame = NumEvents0, buffer = Buffer0}) -> + receive + {'EXIT', Parent, Reason} -> + terminate(Reason, State); + {system, From, Request} -> + sys:handle_system_msg(Request, From, Parent, ?MODULE, [], State); + Msg0 -> + Msg = lg_term:truncate(Msg0), + Bin = term_to_binary(Msg), + BinSize = byte_size(Bin), + Buffer = <>, + NumEvents = NumEvents0 + 1, + if + MaxEvents =:= NumEvents -> + Frame = lz4f:compress_frame(Buffer), + ok = file:write(IoDevice, Frame), + maybe_rotate(State#state{size = Size + byte_size(Frame), + events_this_frame = 0, buffer = <<>>}); + true -> + loop(State#state{events_this_frame = NumEvents, buffer = Buffer}) + end + end. -maybe_rotate(State=#state{filename=Filename, size=Size, max_size=MaxSize, - io_device=OldIoDevice}) when Size > MaxSize -> - ok = file:close(OldIoDevice), - ok = file:rename(Filename, Filename ++ ".bak"), - {ok, NewIoDevice} = file:open(Filename, [write, raw]), - loop(State#state{size=0, io_device=NewIoDevice}); +maybe_rotate(State = #state{filename = Filename, size = Size, max_size = MaxSize, + io_device = OldIoDevice}) when Size > MaxSize -> + ok = file:close(OldIoDevice), + ok = file:rename(Filename, Filename ++ ".bak"), + {ok, NewIoDevice} = file:open(Filename, [write, raw]), + loop(State#state{size = 0, io_device = NewIoDevice}); maybe_rotate(State) -> - loop(State). + loop(State). system_continue(_, _, State) -> - loop(State). + loop(State). -spec system_terminate(any(), _, _, #state{}) -> no_return(). system_terminate(Reason, _, _, State) -> - terminate(Reason, State). + terminate(Reason, State). system_code_change(Misc, _, _, _) -> - {ok, Misc}. + {ok, Misc}. -spec terminate(any(), #state{}) -> no_return(). -terminate(Reason, #state{io_device=IoDevice, buffer=Buffer}) -> - _ = file:write(IoDevice, lz4f:compress_frame(Buffer)), - exit(Reason). +terminate(Reason, #state{io_device = IoDevice, buffer = Buffer}) -> + _ = file:write(IoDevice, lz4f:compress_frame(Buffer)), + exit(Reason). diff --git a/src/profile/lg_flame.erl b/src/profile/lg_flame.erl index b86e75c..f70e209 100644 --- a/src/profile/lg_flame.erl +++ b/src/profile/lg_flame.erl @@ -18,194 +18,194 @@ -export([profile_many/2]). -record(state, { - output_path="", - pid, - last_ts, - count=0, - acc=[]}). % per-process state + output_path = "", + pid, + last_ts, + count = 0, + acc = []}). % per-process state -spec profile(file:filename_all(), file:filename_all()) -> ok. profile(Input, Output) -> - InitialState = exp1_init(Output), - {ok, FinalState} = lg_file_reader:fold(fun handle_event/2, InitialState, Input), - flush(FinalState). + InitialState = exp1_init(Output), + {ok, FinalState} = lg_file_reader:fold(fun handle_event/2, InitialState, Input), + flush(FinalState). -spec profile_many(file:filename(), file:filename()) -> ok. profile_many(Wildcard, Output) -> - InitialState = exp1_init(Output), - Files = filelib:wildcard(Wildcard), - FinalState = lists:foldl(fun(Input, State0) -> - case lg_file_reader:fold(fun handle_event/2, State0, Input) of - {ok, State} -> - State; - {error, Reason, HumanReadable} -> - io:format("Error ~p while reading ~s:~n~s~n", - [Reason, Input, HumanReadable]), - State0 - end - end, InitialState, Files), - flush(FinalState). + InitialState = exp1_init(Output), + Files = filelib:wildcard(Wildcard), + FinalState = lists:foldl(fun(Input, State0) -> + case lg_file_reader:fold(fun handle_event/2, State0, Input) of + {ok, State} -> + State; + {error, Reason, HumanReadable} -> + io:format("Error ~p while reading ~s:~n~s~n", + [Reason, Input, HumanReadable]), + State0 + end + end, InitialState, Files), + flush(FinalState). -flush(#state{output_path=OutputPath}) -> - PidStates = get(), - {ok, FH} = file:open(OutputPath, [write, raw, binary, delayed_write]), - io:format("\n\nWriting to ~s for ~w processes... ", [OutputPath, length(PidStates)]), - _ = [ - [begin - Pid_str0 = lists:flatten(io_lib:format("~w", [Pid])), - Size = length(Pid_str0), - Pid_str = [$(, lists:sublist(Pid_str0, 2, Size-2), $)], - Time_str = integer_to_list(Time), - file:write(FH, [Pid_str, $;, intersperse($;, lists:reverse(Stack)), 32, Time_str, 10]) - end || {Stack, Time} <- Acc] - || {Pid, #state{acc=Acc} = _S} <- PidStates], - _ = file:close(FH), - io:format("finished!\n"), - ok. +flush(#state{output_path = OutputPath}) -> + PidStates = get(), + {ok, FH} = file:open(OutputPath, [write, raw, binary, delayed_write]), + io:format("\n\nWriting to ~s for ~w processes... ", [OutputPath, length(PidStates)]), + _ = [ + [begin + Pid_str0 = lists:flatten(io_lib:format("~w", [Pid])), + Size = length(Pid_str0), + Pid_str = [$(, lists:sublist(Pid_str0, 2, Size - 2), $)], + Time_str = integer_to_list(Time), + file:write(FH, [Pid_str, $;, intersperse($;, lists:reverse(Stack)), 32, Time_str, 10]) + end || {Stack, Time} <- Acc] + || {Pid, #state{acc = Acc} = _S} <- PidStates], + _ = file:close(FH), + io:format("finished!\n"), + ok. handle_event({Type, Pid, Ts, Arg}, State) -> - exp1({trace_ts, Pid, Type, Arg, Ts}, State); + exp1({trace_ts, Pid, Type, Arg, Ts}, State); handle_event({Type, Pid, Ts, Arg, ExtraOrMspec}, State) -> - exp1({trace_ts, Pid, Type, Arg, ExtraOrMspec, Ts}, State); + exp1({trace_ts, Pid, Type, Arg, ExtraOrMspec, Ts}, State); handle_event({Type, Pid, Ts, Arg, Extra, Mspec}, State) -> - exp1({trace_ts, Pid, Type, Arg, Extra, Mspec, Ts}, State). + exp1({trace_ts, Pid, Type, Arg, Extra, Mspec, Ts}, State). %% Below is Scott L. Fritchie's ISC licensed work with only a handful changes. exp1_init(OutputPath) -> - #state{output_path=OutputPath}. + #state{output_path = OutputPath}. -exp1(T, #state{output_path=OutputPath} = S) -> - trace_ts = element(1, T), - Pid = element(2, T), - PidState = case erlang:get(Pid) of - undefined -> - io:format("~p ", [Pid]), - #state{output_path=OutputPath}; - SomeState -> - SomeState - end, - NewPidState = exp1_inner(T, PidState), - erlang:put(Pid, NewPidState), - S. +exp1(T, #state{output_path = OutputPath} = S) -> + trace_ts = element(1, T), + Pid = element(2, T), + PidState = case erlang:get(Pid) of + undefined -> + io:format("~p ", [Pid]), + #state{output_path = OutputPath}; + SomeState -> + SomeState + end, + NewPidState = exp1_inner(T, PidState), + erlang:put(Pid, NewPidState), + S. -exp1_inner({trace_ts, _Pid, InOut, _MFA, _TS}, #state{last_ts=undefined} = S) - when InOut == in; InOut == out -> - %% in & out, without call context, don't help us - S; -exp1_inner({trace_ts, _Pid, Return, _MFA, _TS}, #state{last_ts=undefined} = S) - when Return == return_from; Return == return_to -> - %% return_from and return_to, without call context, don't help us - S; +exp1_inner({trace_ts, _Pid, InOut, _MFA, _TS}, #state{last_ts = undefined} = S) + when InOut == in; InOut == out -> + %% in & out, without call context, don't help us + S; +exp1_inner({trace_ts, _Pid, Return, _MFA, _TS}, #state{last_ts = undefined} = S) + when Return == return_from; Return == return_to -> + %% return_from and return_to, without call context, don't help us + S; exp1_inner({trace_ts, Pid, call, MFA, BIN, TS}, - #state{last_ts=LastTS, acc=Acc, count=Count} = S) -> - try - %% Calculate time elapsed, TS-LastTs. - %% 0. If Acc is empty, then skip step #1. - %% 1. Credit elapsed time to the stack on the top of Acc. - %% 2. Push a 0 usec item with this stack onto Acc. - Stak = lists:filter(fun(<<"unknown function">>) -> false; - (_) -> true - end, stak_binify(BIN)), - Stack0 = stak_trim(Stak), - MFA_bin = mfa_binify(MFA), - Stack1 = [MFA_bin|lists:reverse(Stack0)], - Acc2 = case Acc of - [] -> + #state{last_ts = LastTS, acc = Acc, count = Count} = S) -> + try + %% Calculate time elapsed, TS-LastTs. + %% 0. If Acc is empty, then skip step #1. + %% 1. Credit elapsed time to the stack on the top of Acc. + %% 2. Push a 0 usec item with this stack onto Acc. + Stak = lists:filter(fun(<<"unknown function">>) -> false; + (_) -> true + end, stak_binify(BIN)), + Stack0 = stak_trim(Stak), + MFA_bin = mfa_binify(MFA), + Stack1 = [MFA_bin | lists:reverse(Stack0)], + Acc2 = case Acc of + [] -> [{Stack1, 0}]; - [{LastStack, LastTime}|Tail] -> + [{LastStack, LastTime} | Tail] -> USec = TS - LastTS, % io:format("Stack1: ~p ~p\n", [Stack1, USec]), [{Stack1, 0}, - {LastStack, LastTime + USec}|Tail] - end, - %% TODO: more state tracking here. - S#state{pid=Pid, last_ts=TS, count=Count+1, acc=Acc2} - catch XX:YY:ZZ -> - io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, XX, YY, ZZ]), - S - end; -exp1_inner({trace_ts, _Pid, return_to, MFA, TS}, #state{last_ts=LastTS, acc=Acc} = S) -> - try - %% Calculate time elapsed, TS-LastTs. - %% 1. Credit elapsed time to the stack on the top of Acc. - %% 2. Push a 0 usec item with the "best" stack onto Acc. - %% "best" = MFA exists in the middle of the stack onto Acc, - %% or else MFA exists at the top of a stack elsewhere in Acc. - [{LastStack, LastTime}|Tail] = Acc, - MFA_bin = mfa_binify(MFA), - BestStack = lists:dropwhile(fun(SomeMFA) when SomeMFA /= MFA_bin -> true; - (_) -> false - end, find_matching_stack(MFA_bin, Acc)), - USec = TS - LastTS, - Acc2 = [{BestStack, 0}, - {LastStack, LastTime + USec}|Tail], + {LastStack, LastTime + USec} | Tail] + end, + %% TODO: more state tracking here. + S#state{pid = Pid, last_ts = TS, count = Count + 1, acc = Acc2} + catch XX:YY:ZZ -> + io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, XX, YY, ZZ]), + S + end; +exp1_inner({trace_ts, _Pid, return_to, MFA, TS}, #state{last_ts = LastTS, acc = Acc} = S) -> + try + %% Calculate time elapsed, TS-LastTs. + %% 1. Credit elapsed time to the stack on the top of Acc. + %% 2. Push a 0 usec item with the "best" stack onto Acc. + %% "best" = MFA exists in the middle of the stack onto Acc, + %% or else MFA exists at the top of a stack elsewhere in Acc. + [{LastStack, LastTime} | Tail] = Acc, + MFA_bin = mfa_binify(MFA), + BestStack = lists:dropwhile(fun(SomeMFA) when SomeMFA /= MFA_bin -> true; + (_) -> false + end, find_matching_stack(MFA_bin, Acc)), + USec = TS - LastTS, + Acc2 = [{BestStack, 0}, + {LastStack, LastTime + USec} | Tail], % io:format(user, "return-to: ~p\n", [lists:sublist(Acc2, 4)]), - S#state{last_ts=TS, acc=Acc2} - catch XX:YY:ZZ -> - io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, XX, YY, ZZ]), - S - end; - -exp1_inner({trace_ts, _Pid, gc_start, _Info, TS}, #state{last_ts=LastTS, acc=Acc} = S) -> - try - %% Push a 0 usec item onto Acc. - [{LastStack, LastTime}|Tail] = Acc, - NewStack = [<<"GARBAGE-COLLECTION">>|LastStack], - USec = TS - LastTS, - Acc2 = [{NewStack, 0}, - {LastStack, LastTime + USec}|Tail], + S#state{last_ts = TS, acc = Acc2} + catch XX:YY:ZZ -> + io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, XX, YY, ZZ]), + S + end; + +exp1_inner({trace_ts, _Pid, gc_start, _Info, TS}, #state{last_ts = LastTS, acc = Acc} = S) -> + try + %% Push a 0 usec item onto Acc. + [{LastStack, LastTime} | Tail] = Acc, + NewStack = [<<"GARBAGE-COLLECTION">> | LastStack], + USec = TS - LastTS, + Acc2 = [{NewStack, 0}, + {LastStack, LastTime + USec} | Tail], % io:format(user, "GC 1: ~p\n", [lists:sublist(Acc2, 4)]), - S#state{last_ts=TS, acc=Acc2} - catch _XX:_YY:_ZZ -> - %% io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, _XX, _YY, _ZZ]), - S - end; -exp1_inner({trace_ts, _Pid, gc_end, _Info, TS}, #state{last_ts=LastTS, acc=Acc} = S) -> - try - %% Push the GC time onto Acc, then push 0 usec item from last exec - %% stack onto Acc. - [{GCStack, GCTime},{LastExecStack,_}|Tail] = Acc, - USec = TS - LastTS, - Acc2 = [{LastExecStack, 0}, {GCStack, GCTime + USec}|Tail], + S#state{last_ts = TS, acc = Acc2} + catch _XX:_YY:_ZZ -> + %% io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, _XX, _YY, _ZZ]), + S + end; +exp1_inner({trace_ts, _Pid, gc_end, _Info, TS}, #state{last_ts = LastTS, acc = Acc} = S) -> + try + %% Push the GC time onto Acc, then push 0 usec item from last exec + %% stack onto Acc. + [{GCStack, GCTime}, {LastExecStack, _} | Tail] = Acc, + USec = TS - LastTS, + Acc2 = [{LastExecStack, 0}, {GCStack, GCTime + USec} | Tail], % io:format(user, "GC 2: ~p\n", [lists:sublist(Acc2, 4)]), - S#state{last_ts=TS, acc=Acc2} - catch _XX:_YY:_ZZ -> - %% io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, _XX, _YY, _ZZ]), - S - end; + S#state{last_ts = TS, acc = Acc2} + catch _XX:_YY:_ZZ -> + %% io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, _XX, _YY, _ZZ]), + S + end; -exp1_inner({trace_ts, _Pid, out, MFA, TS}, #state{last_ts=LastTS, acc=Acc} = S) -> - try - %% Push a 0 usec item onto Acc. - %% The MFA reported here probably doesn't appear in the stacktrace - %% given to us by the last 'call', so add it here. - [{LastStack, LastTime}|Tail] = Acc, - MFA_bin = mfa_binify(MFA), - NewStack = [<<"SLEEP">>,MFA_bin|LastStack], - USec = TS - LastTS, - Acc2 = [{NewStack, 0}, - {LastStack, LastTime + USec}|Tail], - S#state{last_ts=TS, acc=Acc2} - catch XX:YY:ZZ -> - io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, XX, YY, ZZ]), - S - end; -exp1_inner({trace_ts, _Pid, in, MFA, TS}, #state{last_ts=LastTS, acc=Acc} = S) -> - try - %% Push the Sleep time onto Acc, then push 0 usec item from last - %% exec stack onto Acc. - %% The MFA reported here probably doesn't appear in the stacktrace - %% given to us by the last 'call', so add it here. - MFA_bin = mfa_binify(MFA), - [{SleepStack, SleepTime},{LastExecStack,_}|Tail] = Acc, - USec = TS - LastTS, - Acc2 = [{[MFA_bin|LastExecStack], 0}, {SleepStack, SleepTime + USec}|Tail], - S#state{last_ts=TS, acc=Acc2} - catch XX:YY:ZZ -> - io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, XX, YY, ZZ]), - S - end; +exp1_inner({trace_ts, _Pid, out, MFA, TS}, #state{last_ts = LastTS, acc = Acc} = S) -> + try + %% Push a 0 usec item onto Acc. + %% The MFA reported here probably doesn't appear in the stacktrace + %% given to us by the last 'call', so add it here. + [{LastStack, LastTime} | Tail] = Acc, + MFA_bin = mfa_binify(MFA), + NewStack = [<<"SLEEP">>, MFA_bin | LastStack], + USec = TS - LastTS, + Acc2 = [{NewStack, 0}, + {LastStack, LastTime + USec} | Tail], + S#state{last_ts = TS, acc = Acc2} + catch XX:YY:ZZ -> + io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, XX, YY, ZZ]), + S + end; +exp1_inner({trace_ts, _Pid, in, MFA, TS}, #state{last_ts = LastTS, acc = Acc} = S) -> + try + %% Push the Sleep time onto Acc, then push 0 usec item from last + %% exec stack onto Acc. + %% The MFA reported here probably doesn't appear in the stacktrace + %% given to us by the last 'call', so add it here. + MFA_bin = mfa_binify(MFA), + [{SleepStack, SleepTime}, {LastExecStack, _} | Tail] = Acc, + USec = TS - LastTS, + Acc2 = [{[MFA_bin | LastExecStack], 0}, {SleepStack, SleepTime + USec} | Tail], + S#state{last_ts = TS, acc = Acc2} + catch XX:YY:ZZ -> + io:format(user, "~p: ~p:~p @ ~p\n", [?LINE, XX, YY, ZZ]), + S + end; %exp1_inner(end_of_trace = _Else, #state{pid=Pid, output_path=OutputPath, acc=Acc} = S) -> % {ok, FH} = file:open(OutputPath, [write, raw, binary, delayed_write]), @@ -220,22 +220,22 @@ exp1_inner({trace_ts, _Pid, in, MFA, TS}, #state{last_ts=LastTS, acc=Acc} = S) - % S; exp1_inner(_Else, S) -> % io:format("?? ~P\n", [_Else, 10]), - S. + S. -find_matching_stack(MFA_bin, [{H,_Time}|_] = Acc) -> - case lists:member(MFA_bin, H) of - true -> - H; - false -> - find_matching_stack2(MFA_bin, Acc) - end. +find_matching_stack(MFA_bin, [{H, _Time} | _] = Acc) -> + case lists:member(MFA_bin, H) of + true -> + H; + false -> + find_matching_stack2(MFA_bin, Acc) + end. -find_matching_stack2(MFA_bin, [{[MFA_bin|_StackTail]=Stack,_Time}|_]) -> - Stack; -find_matching_stack2(MFA_bin, [_H|T]) -> - find_matching_stack2(MFA_bin, T); +find_matching_stack2(MFA_bin, [{[MFA_bin | _StackTail] = Stack, _Time} | _]) -> + Stack; +find_matching_stack2(MFA_bin, [_H | T]) -> + find_matching_stack2(MFA_bin, T); find_matching_stack2(_MFA_bin, []) -> - [<<"FIND-MATCHING-FAILED">>]. + [<<"FIND-MATCHING-FAILED">>]. %%%%%%%%%%%%%%%%%%%%%%%%%%%%%% @@ -243,46 +243,46 @@ intersperse(_, []) -> []; intersperse(_, [X]) -> [X]; intersperse(Sep, [X | Xs]) -> [X, Sep | intersperse(Sep, Xs)]. -stak_trim([<<"proc_lib:init_p_do_apply/3">>,<<"gen_fsm:decode_msg/9">>,<<"gen_fsm:handle_msg/7">>,<<"gen_fsm:loop/7">>|T]) -> - stak_trim([<<"GEN-FSM">>|T]); -stak_trim([<<"GEN-FSM">>,<<"gen_fsm:decode_msg/9">>,<<"gen_fsm:handle_msg/7">>,<<"gen_fsm:loop/7">>|T]) -> - stak_trim([<<"GEN-FSM">>|T]); +stak_trim([<<"proc_lib:init_p_do_apply/3">>, <<"gen_fsm:decode_msg/9">>, <<"gen_fsm:handle_msg/7">>, <<"gen_fsm:loop/7">> | T]) -> + stak_trim([<<"GEN-FSM">> | T]); +stak_trim([<<"GEN-FSM">>, <<"gen_fsm:decode_msg/9">>, <<"gen_fsm:handle_msg/7">>, <<"gen_fsm:loop/7">> | T]) -> + stak_trim([<<"GEN-FSM">> | T]); stak_trim(Else) -> - Else. + Else. stak_binify(Bin) when is_binary(Bin) -> - [list_to_binary(X) || X <- stak(Bin)]; + [list_to_binary(X) || X <- stak(Bin)]; stak_binify(X) -> - list_to_binary(io_lib:format("~w", [X])). + list_to_binary(io_lib:format("~w", [X])). -mfa_binify({M,F,A}) -> - list_to_binary(io_lib:format("~w:~w/~w", [M, F, A])); +mfa_binify({M, F, A}) -> + list_to_binary(io_lib:format("~w:~w/~w", [M, F, A])); mfa_binify(X) -> - list_to_binary(io_lib:format("~w", [X])). + list_to_binary(io_lib:format("~w", [X])). %% Borrowed from redbug.erl stak(Bin) -> - lists:foldl(fun munge/2,[],string:tokens(binary_to_list(Bin),"\n")). + lists:foldl(fun munge/2, [], string:tokens(binary_to_list(Bin), "\n")). -munge(I,Out) -> - case I of %% lists:reverse(I) of - "..."++_ -> ["truncated!!!"|Out]; - _ -> - case string:str(I, "Return addr") of - 0 -> - case string:str(I, "cp = ") of - 0 -> Out; - _ -> [mfaf(I)|Out] - end; - _ -> - case string:str(I, "erminate process normal") of - 0 -> [mfaf(I)|Out]; - _ -> Out - end - end - end. +munge(I, Out) -> + case I of %% lists:reverse(I) of + "..." ++ _ -> ["truncated!!!" | Out]; + _ -> + case string:str(I, "Return addr") of + 0 -> + case string:str(I, "cp = ") of + 0 -> Out; + _ -> [mfaf(I) | Out] + end; + _ -> + case string:str(I, "erminate process normal") of + 0 -> [mfaf(I) | Out]; + _ -> Out + end + end + end. mfaf(I) -> - [_, C|_] = string:tokens(I,"()+"), - string:strip(C). + [_, C | _] = string:tokens(I, "()+"), + string:strip(C). diff --git a/src/profile/lg_messages.erl b/src/profile/lg_messages.erl index a35874d..56318b8 100644 --- a/src/profile/lg_messages.erl +++ b/src/profile/lg_messages.erl @@ -18,197 +18,197 @@ -export([profile_many/1]). -record(state, { - meta = #{} :: map(), - senders = #{} :: #{pid() => pos_integer()}, - receivers = #{} :: #{pid() => pos_integer()}, - pairs = #{} :: #{{pid(), pid()} => pos_integer()}, - non_existing = #{} :: #{pid() => pos_integer()}, - last_msgs = #{} :: #{pid() => atom()} + meta = #{} :: map(), + senders = #{} :: #{pid() => pos_integer()}, + receivers = #{} :: #{pid() => pos_integer()}, + pairs = #{} :: #{{pid(), pid()} => pos_integer()}, + non_existing = #{} :: #{pid() => pos_integer()}, + last_msgs = #{} :: #{pid() => atom()} }). -spec profile(file:filename_all()) -> ok. profile(Input) -> - {ok, FinalState} = lg_file_reader:fold(fun handle_event/2, #state{}, Input), - flush(FinalState). + {ok, FinalState} = lg_file_reader:fold(fun handle_event/2, #state{}, Input), + flush(FinalState). -spec profile_many(file:filename()) -> ok. profile_many(Wildcard) -> - Files = filelib:wildcard(Wildcard), - FinalState = lists:foldl(fun(Input, State0) -> - {ok, State} = lg_file_reader:fold(fun handle_event/2, State0, Input), - State - end, #state{}, Files), - flush(FinalState). + Files = filelib:wildcard(Wildcard), + FinalState = lists:foldl(fun(Input, State0) -> + {ok, State} = lg_file_reader:fold(fun handle_event/2, State0, Input), + State + end, #state{}, Files), + flush(FinalState). %% @todo Later we may want to look at the latency of gen_server call/reply. %% @todo Later we may want to look at particular messages, have some sort of callback. -handle_event({send, From, _, Info, lg}, State=#state{meta=Meta0}) -> - Meta = case Meta0 of - #{From := Info0} -> Meta0#{From => maps:merge(Info0, Info)}; - _ -> Meta0#{From => Info} - end, - State#state{meta=Meta}; +handle_event({send, From, _, Info, lg}, State = #state{meta = Meta0}) -> + Meta = case Meta0 of + #{From := Info0} -> Meta0#{From => maps:merge(Info0, Info)}; + _ -> Meta0#{From => Info} + end, + State#state{meta = Meta}; handle_event({send, From, _, Msg, To}, - State=#state{senders=Senders, receivers=Receivers, pairs=Pairs, last_msgs=Msgs}) -> - SendersCount = maps:get(From, Senders, 0), - ReceiversCount = maps:get(To, Receivers, 0), - PairsCount = maps:get({From, To}, Pairs, 0), - State#state{ - senders=Senders#{From => SendersCount + 1}, - receivers=Receivers#{To => ReceiversCount + 1}, - pairs=Pairs#{{From, To} => PairsCount + 1}, - last_msgs=Msgs#{From => Msg}}; + State = #state{senders = Senders, receivers = Receivers, pairs = Pairs, last_msgs = Msgs}) -> + SendersCount = maps:get(From, Senders, 0), + ReceiversCount = maps:get(To, Receivers, 0), + PairsCount = maps:get({From, To}, Pairs, 0), + State#state{ + senders = Senders#{From => SendersCount + 1}, + receivers = Receivers#{To => ReceiversCount + 1}, + pairs = Pairs#{{From, To} => PairsCount + 1}, + last_msgs = Msgs#{From => Msg}}; handle_event({send_to_non_existing_process, From, _, Msg, _}, - State=#state{non_existing=Map, last_msgs=Msgs}) -> - Count = maps:get(From, Map, 0), - State#state{ - non_existing=Map#{From => Count + 1}, - last_msgs=Msgs#{From => Msg}}; + State = #state{non_existing = Map, last_msgs = Msgs}) -> + Count = maps:get(From, Map, 0), + State#state{ + non_existing = Map#{From => Count + 1}, + last_msgs = Msgs#{From => Msg}}; %% Ignore all other events. We only care about messages. handle_event(_, State) -> - State. + State. %% Output of the profiling. flush(State) -> - flush_most_active_senders(State), - flush_most_active_receivers(State), - flush_most_non_existing(State), - flush_most_active_pair_unidirectional(State), - flush_most_active_pair_bidirectional(State), - io:format("~n"), - flush_digraph(State), - ok. - -flush_most_active_senders(State=#state{senders=Procs}) -> - List = lists:sublist( - lists:reverse(lists:keysort(2, maps:to_list(Procs))), - 1, 100), - format_by_count("They sent the most messages", List, State). - -flush_most_active_receivers(State=#state{receivers=Procs}) -> - List = lists:sublist( - lists:reverse(lists:keysort(2, maps:to_list(Procs))), - 1, 100), - format_by_count("They received the most messages", List, State). - -flush_most_non_existing(State=#state{non_existing=Procs}) -> - List = lists:sublist( - lists:reverse(lists:keysort(2, maps:to_list(Procs))), - 1, 100), - format_by_count("They sent the most messages to dead processes", List, State). + flush_most_active_senders(State), + flush_most_active_receivers(State), + flush_most_non_existing(State), + flush_most_active_pair_unidirectional(State), + flush_most_active_pair_bidirectional(State), + io:format("~n"), + flush_digraph(State), + ok. + +flush_most_active_senders(State = #state{senders = Procs}) -> + List = lists:sublist( + lists:reverse(lists:keysort(2, maps:to_list(Procs))), + 1, 100), + format_by_count("They sent the most messages", List, State). + +flush_most_active_receivers(State = #state{receivers = Procs}) -> + List = lists:sublist( + lists:reverse(lists:keysort(2, maps:to_list(Procs))), + 1, 100), + format_by_count("They received the most messages", List, State). + +flush_most_non_existing(State = #state{non_existing = Procs}) -> + List = lists:sublist( + lists:reverse(lists:keysort(2, maps:to_list(Procs))), + 1, 100), + format_by_count("They sent the most messages to dead processes", List, State). format_by_count(Title, List, State) -> - MsgCols = case io:columns() of - {ok, Cols} -> Cols; - _ -> 80 - end, - io:format( - "~n~s~n~s~n~n" - "Process ID Count (Label) OR Message sent~n" - "---------- ----- -----------------------~n", - [Title, lists:duplicate(length(Title), $=)]), - _ = [begin - {Prefix, Label, Suffix} = label_or_msg(P, State), - io:format("~-15w ~-10b ~s~" ++ integer_to_list(MsgCols) ++ "P~s~n", - [P, C, Prefix, Label, 5, Suffix]) - end || {P, C} <- List], - ok. - -label_or_msg(P, #state{meta=Meta, last_msgs=Msgs}) -> - case maps:get(P, Meta, #{}) of - #{process_type := PT} -> {"(", PT, ")"}; - _ -> {"", maps:get(P, Msgs, ''), ""} - end. - -flush_most_active_pair_unidirectional(State=#state{pairs=Procs}) -> - List = lists:sublist( - lists:reverse(lists:keysort(2, maps:to_list(Procs))), - 1, 100), - Title = "They sent the most messages to one other process", - MsgCols = case io:columns() of - {ok, Cols} -> Cols; - _ -> 80 - end, - io:format( - "~n~s~n~s~n~n" - "From pid To pid Count (Label) OR Message sent~n" - "-------- ------ ----- -----------------------~n", - [Title, lists:duplicate(length(Title), $=)]), - _ = [begin - {Prefix, Label, Suffix} = label_or_msg(F, State), - io:format("~-15w ~-15w ~-10b ~s~" ++ integer_to_list(MsgCols) ++ "P~s~n", - [F, T, C, Prefix, Label, 5, Suffix]) - end || {{F, T}, C} <- List], - ok. - -flush_most_active_pair_bidirectional(State=#state{pairs=Procs0}) -> - Procs = maps:fold(fun merge_pairs/3, #{}, Procs0), - List = lists:sublist( - lists:reverse(lists:keysort(2, maps:to_list(Procs))), - 1, 100), - Title = "They sent the most messages to each other", - MsgCols = case io:columns() of - {ok, Cols} -> Cols; - _ -> 80 - end, - io:format( - "~n~s~n~s~n~n" - "Count Pid 1 (Label) OR Message sent~n" - " Pid 2 by the corresponding process~n" - "----- ----- ----------------------------~n", - [Title, lists:duplicate(length(Title), $=)]), - _ = [begin - {FPrefix, FLabel, FSuffix} = label_or_msg(F, State), - {TPrefix, TLabel, TSuffix} = label_or_msg(T, State), - io:format( - "~-10b ~-15w ~s~" ++ integer_to_list(MsgCols) ++ "P~s~n" - " ~-15w ~s~" ++ integer_to_list(MsgCols) ++ "P~s~n", - [C, F, FPrefix, FLabel, 5, FSuffix, - T, TPrefix, TLabel, 5, TSuffix]) - end || {{F, T}, C} <- List], - ok. - -flush_digraph(State=#state{pairs=Procs0}) -> - Procs = maps:fold(fun group_pairs/3, #{}, Procs0), - List = maps:to_list(Procs), - ok = file:write_file("digraph.gv", [ - "digraph {\n" - " concentrate=true;\n" - " splines=ortho;\n" - " edge [arrowhead=none, labelfontsize=12.0, minlen=3];\n" - "\n", - [io_lib:format(" \"~w~s\" -> \"~w~s\" [taillabel=~b, headlabel=~b];~n", - [F, label(F, State), T, label(T, State), FC, TC]) || {{F, T}, {FC, TC}} <- List], - "}\n" - ]), - io:format( - "The file digraph.gv was created. Use GraphViz to make a PNG.~n" - "$ dot -Tpng -O digraph.gv~n" - "~n" - "You can also edit the file to remove uninteresting processes.~n" - "One line in the file is equal to a connection between two processes.~n"), - ok. - -label(P, #state{meta=Meta}) -> - case maps:get(P, Meta, #{}) of - #{process_type := PT} -> io_lib:format(" (~w)", [PT]); - _ -> "" - end. + MsgCols = case io:columns() of + {ok, Cols} -> Cols; + _ -> 80 + end, + io:format( + "~n~s~n~s~n~n" + "Process ID Count (Label) OR Message sent~n" + "---------- ----- -----------------------~n", + [Title, lists:duplicate(length(Title), $=)]), + _ = [begin + {Prefix, Label, Suffix} = label_or_msg(P, State), + io:format("~-15w ~-10b ~s~" ++ integer_to_list(MsgCols) ++ "P~s~n", + [P, C, Prefix, Label, 5, Suffix]) + end || {P, C} <- List], + ok. + +label_or_msg(P, #state{meta = Meta, last_msgs = Msgs}) -> + case maps:get(P, Meta, #{}) of + #{process_type := PT} -> {"(", PT, ")"}; + _ -> {"", maps:get(P, Msgs, ''), ""} + end. + +flush_most_active_pair_unidirectional(State = #state{pairs = Procs}) -> + List = lists:sublist( + lists:reverse(lists:keysort(2, maps:to_list(Procs))), + 1, 100), + Title = "They sent the most messages to one other process", + MsgCols = case io:columns() of + {ok, Cols} -> Cols; + _ -> 80 + end, + io:format( + "~n~s~n~s~n~n" + "From pid To pid Count (Label) OR Message sent~n" + "-------- ------ ----- -----------------------~n", + [Title, lists:duplicate(length(Title), $=)]), + _ = [begin + {Prefix, Label, Suffix} = label_or_msg(F, State), + io:format("~-15w ~-15w ~-10b ~s~" ++ integer_to_list(MsgCols) ++ "P~s~n", + [F, T, C, Prefix, Label, 5, Suffix]) + end || {{F, T}, C} <- List], + ok. + +flush_most_active_pair_bidirectional(State = #state{pairs = Procs0}) -> + Procs = maps:fold(fun merge_pairs/3, #{}, Procs0), + List = lists:sublist( + lists:reverse(lists:keysort(2, maps:to_list(Procs))), + 1, 100), + Title = "They sent the most messages to each other", + MsgCols = case io:columns() of + {ok, Cols} -> Cols; + _ -> 80 + end, + io:format( + "~n~s~n~s~n~n" + "Count Pid 1 (Label) OR Message sent~n" + " Pid 2 by the corresponding process~n" + "----- ----- ----------------------------~n", + [Title, lists:duplicate(length(Title), $=)]), + _ = [begin + {FPrefix, FLabel, FSuffix} = label_or_msg(F, State), + {TPrefix, TLabel, TSuffix} = label_or_msg(T, State), + io:format( + "~-10b ~-15w ~s~" ++ integer_to_list(MsgCols) ++ "P~s~n" + " ~-15w ~s~" ++ integer_to_list(MsgCols) ++ "P~s~n", + [C, F, FPrefix, FLabel, 5, FSuffix, + T, TPrefix, TLabel, 5, TSuffix]) + end || {{F, T}, C} <- List], + ok. + +flush_digraph(State = #state{pairs = Procs0}) -> + Procs = maps:fold(fun group_pairs/3, #{}, Procs0), + List = maps:to_list(Procs), + ok = file:write_file("digraph.gv", [ + "digraph {\n" + " concentrate=true;\n" + " splines=ortho;\n" + " edge [arrowhead=none, labelfontsize=12.0, minlen=3];\n" + "\n", + [io_lib:format(" \"~w~s\" -> \"~w~s\" [taillabel=~b, headlabel=~b];~n", + [F, label(F, State), T, label(T, State), FC, TC]) || {{F, T}, {FC, TC}} <- List], + "}\n" + ]), + io:format( + "The file digraph.gv was created. Use GraphViz to make a PNG.~n" + "$ dot -Tpng -O digraph.gv~n" + "~n" + "You can also edit the file to remove uninteresting processes.~n" + "One line in the file is equal to a connection between two processes.~n"), + ok. + +label(P, #state{meta = Meta}) -> + case maps:get(P, Meta, #{}) of + #{process_type := PT} -> io_lib:format(" (~w)", [PT]); + _ -> "" + end. merge_pairs({From, To}, Count, Acc) -> - Key = if - From < To -> {From, To}; - true -> {To, From} - end, - AccCount = maps:get(Key, Acc, 0), - Acc#{Key => AccCount + Count}. + Key = if + From < To -> {From, To}; + true -> {To, From} + end, + AccCount = maps:get(Key, Acc, 0), + Acc#{Key => AccCount + Count}. group_pairs({From, To}, Count, Acc) when From < To -> - Key = {From, To}, - {_, AccCount} = maps:get(Key, Acc, {0, 0}), - Acc#{Key => {Count, AccCount}}; + Key = {From, To}, + {_, AccCount} = maps:get(Key, Acc, {0, 0}), + Acc#{Key => {Count, AccCount}}; group_pairs({From, To}, Count, Acc) -> - Key = {To, From}, - {AccCount, _} = maps:get(Key, Acc, {0, 0}), - Acc#{Key => {AccCount, Count}}. + Key = {To, From}, + {AccCount, _} = maps:get(Key, Acc, {0, 0}), + Acc#{Key => {AccCount, Count}}. diff --git a/src/profile/lg_messages_seqdiag.erl b/src/profile/lg_messages_seqdiag.erl index 3033a66..233aef0 100644 --- a/src/profile/lg_messages_seqdiag.erl +++ b/src/profile/lg_messages_seqdiag.erl @@ -18,127 +18,127 @@ -export([profile_many/2]). -record(state, { - meta = #{} :: map(), - events = [], - pids + meta = #{} :: map(), + events = [], + pids }). -spec profile(file:filename_all(), list()) -> ok. profile(Input, Pids) -> - {ok, FinalState} = lg_file_reader:fold(fun handle_event/2, - #state{pids=prepare_pids(Pids)}, Input), - flush(FinalState). + {ok, FinalState} = lg_file_reader:fold(fun handle_event/2, + #state{pids = prepare_pids(Pids)}, Input), + flush(FinalState). -spec profile_many(file:filename(), list()) -> ok. profile_many(Wildcard, Pids) -> - Files = filelib:wildcard(Wildcard), - FinalState = lists:foldl(fun(Input, State0) -> - {ok, State} = lg_file_reader:fold(fun handle_event/2, State0, Input), - State - end, #state{pids=prepare_pids(Pids)}, Files), - flush(FinalState). + Files = filelib:wildcard(Wildcard), + FinalState = lists:foldl(fun(Input, State0) -> + {ok, State} = lg_file_reader:fold(fun handle_event/2, State0, Input), + State + end, #state{pids = prepare_pids(Pids)}, Files), + flush(FinalState). -handle_event({send, From, _, Info, lg}, State=#state{meta=Meta0}) -> - Meta = case Meta0 of - #{From := Info0} -> Meta0#{From => maps:merge(Info0, Info)}; - _ -> Meta0#{From => Info} - end, - State#state{meta=Meta}; +handle_event({send, From, _, Info, lg}, State = #state{meta = Meta0}) -> + Meta = case Meta0 of + #{From := Info0} -> Meta0#{From => maps:merge(Info0, Info)}; + _ -> Meta0#{From => Info} + end, + State#state{meta = Meta}; handle_event(Event = {Type, From, _, _, To}, State) - when Type =:= send; Type =:= send_to_non_existing_process -> - maybe_keep_event(Event, From, To, State); + when Type =:= send; Type =:= send_to_non_existing_process -> + maybe_keep_event(Event, From, To, State); handle_event(Event = {spawn, From, _, To, _}, State) -> - maybe_keep_event(Event, From, To, State); -handle_event(Event = {exit, Pid0, _, _}, State=#state{events=Events, pids=Pids}) -> - Pid = hide_pid_node(Pid0), - case lists:member(Pid, Pids) of - true -> State#state{events=[Event|Events]}; - _ -> State - end; + maybe_keep_event(Event, From, To, State); +handle_event(Event = {exit, Pid0, _, _}, State = #state{events = Events, pids = Pids}) -> + Pid = hide_pid_node(Pid0), + case lists:member(Pid, Pids) of + true -> State#state{events = [Event | Events]}; + _ -> State + end; %% Ignore all other events. We only care about messages and spawns/exits. handle_event(_, State) -> - State. + State. -maybe_keep_event(Event, From0, To0, State=#state{events=Events, pids=Pids}) -> - From = hide_pid_node(From0), - To = hide_pid_node(To0), - case {lists:member(From, Pids), lists:member(To, Pids)} of - {true, true} -> State#state{events=[Event|Events]}; - _ -> State - end. +maybe_keep_event(Event, From0, To0, State = #state{events = Events, pids = Pids}) -> + From = hide_pid_node(From0), + To = hide_pid_node(To0), + case {lists:member(From, Pids), lists:member(To, Pids)} of + {true, true} -> State#state{events = [Event | Events]}; + _ -> State + end. prepare_pids(Pids) -> - [hide_pid_node(Pid) || Pid <- Pids]. + [hide_pid_node(Pid) || Pid <- Pids]. hide_pid_node(Pid) when is_pid(Pid) -> hide_pid_node(pid_to_list(Pid)); -hide_pid_node([$<, _, $.|Tail]) -> "<***." ++ Tail; -hide_pid_node([$<, _, _, $.|Tail]) -> "<***." ++ Tail; -hide_pid_node([$<, _, _, _, $.|Tail]) -> "<***." ++ Tail; -hide_pid_node([$<, _, _, _, _, $.|Tail]) -> "<***." ++ Tail; -hide_pid_node([$<, _, _, _, _, _, $.|Tail]) -> "<***." ++ Tail; +hide_pid_node([$<, _, $. | Tail]) -> "<***." ++ Tail; +hide_pid_node([$<, _, _, $. | Tail]) -> "<***." ++ Tail; +hide_pid_node([$<, _, _, _, $. | Tail]) -> "<***." ++ Tail; +hide_pid_node([$<, _, _, _, _, $. | Tail]) -> "<***." ++ Tail; +hide_pid_node([$<, _, _, _, _, _, $. | Tail]) -> "<***." ++ Tail; hide_pid_node(Name) -> Name. -flush(State=#state{events=Events0}) -> - %% Sort by timestamp from oldest to newest. - Events = lists:keysort(3, Events0), - %% Initialize the formatting state. - put(num_calls, 0), - %% Output everything. - ok = file:write_file("seq.diag", [ - "seqdiag {\n" - " edge_length = 300;\n" - " activation = none;\n" - "\n", - [format_event(Event, State) || Event <- Events], - "}\n" - ]), - io:format( - "The file seq.diag was created. Use seqdiag to make a PNG.~n" - "$ seqdiag -Tpng --no-transparency seq.diag~n" - "~n" - "To use a custom font, use the -f modifier:~n" - "$ seqdiag -Tpng --no-transparency -f /usr/share/fonts/TTF/verdana.ttf seq.diag~n" - "~n" - "You can also edit the file to remove uninteresting messages.~n" - "One line in the file is equal to a message sent by a process to another.~n"), - ok. +flush(State = #state{events = Events0}) -> + %% Sort by timestamp from oldest to newest. + Events = lists:keysort(3, Events0), + %% Initialize the formatting state. + put(num_calls, 0), + %% Output everything. + ok = file:write_file("seq.diag", [ + "seqdiag {\n" + " edge_length = 300;\n" + " activation = none;\n" + "\n", + [format_event(Event, State) || Event <- Events], + "}\n" + ]), + io:format( + "The file seq.diag was created. Use seqdiag to make a PNG.~n" + "$ seqdiag -Tpng --no-transparency seq.diag~n" + "~n" + "To use a custom font, use the -f modifier:~n" + "$ seqdiag -Tpng --no-transparency -f /usr/share/fonts/TTF/verdana.ttf seq.diag~n" + "~n" + "You can also edit the file to remove uninteresting messages.~n" + "One line in the file is equal to a message sent by a process to another.~n"), + ok. format_event({spawn, From, _, To, MFA}, State) -> - io_lib:format(" \"~w~s\" ->> \"~w~s\" [label=\"spawn ~9999P\"];~n", [ - From, label(From, State), To, label(To, State), MFA, 8]); + io_lib:format(" \"~w~s\" ->> \"~w~s\" [label=\"spawn ~9999P\"];~n", [ + From, label(From, State), To, label(To, State), MFA, 8]); format_event({exit, Pid, _, Reason}, State) -> - PidLabel = label(Pid, State), - io_lib:format(" \"~w~s\" ->> \"~w~s\" [label=\"exit ~9999P\"];~n", [ - Pid, PidLabel, Pid, PidLabel, Reason, 8]); + PidLabel = label(Pid, State), + io_lib:format(" \"~w~s\" ->> \"~w~s\" [label=\"exit ~9999P\"];~n", [ + Pid, PidLabel, Pid, PidLabel, Reason, 8]); format_event({Type, From, _, {'$gen_call', {From, Ref}, Msg}, To}, State) -> - NumCalls = get(num_calls) + 1, - put(num_calls, NumCalls), - put(Ref, NumCalls), - io_lib:format(" \"~w~s\" ~s \"~w~s\" [label=\"gen:call #~w ~9999P\"];~n", [ - From, label(From, State), - case Type of send -> "->"; _ -> "-->" end, - To, label(To, State), NumCalls, Msg, 8]); -format_event(Event={Type, From, _, {Ref, Msg}, To}, State) -> - case get(Ref) of - undefined -> - default_format_event(Event, State); - NumCall -> - io_lib:format(" \"~w~s\" ~s \"~w~s\" [label=\"#~w ~9999P\"];~n", [ - From, label(From, State), - case Type of send -> "->"; _ -> "-->" end, - To, label(To, State), NumCall, Msg, 8]) - end; + NumCalls = get(num_calls) + 1, + put(num_calls, NumCalls), + put(Ref, NumCalls), + io_lib:format(" \"~w~s\" ~s \"~w~s\" [label=\"gen:call #~w ~9999P\"];~n", [ + From, label(From, State), + case Type of send -> "->"; _ -> "-->" end, + To, label(To, State), NumCalls, Msg, 8]); +format_event(Event = {Type, From, _, {Ref, Msg}, To}, State) -> + case get(Ref) of + undefined -> + default_format_event(Event, State); + NumCall -> + io_lib:format(" \"~w~s\" ~s \"~w~s\" [label=\"#~w ~9999P\"];~n", [ + From, label(From, State), + case Type of send -> "->"; _ -> "-->" end, + To, label(To, State), NumCall, Msg, 8]) + end; format_event(Event, State) -> - default_format_event(Event, State). + default_format_event(Event, State). default_format_event({Type, From, _, Msg, To}, State) -> - io_lib:format(" \"~w~s\" ~s \"~w~s\" [label=\"~9999P\"];~n", [ - From, label(From, State), - case Type of send -> "->"; _ -> "-->" end, - To, label(To, State), Msg, 8]). + io_lib:format(" \"~w~s\" ~s \"~w~s\" [label=\"~9999P\"];~n", [ + From, label(From, State), + case Type of send -> "->"; _ -> "-->" end, + To, label(To, State), Msg, 8]). -label(P, #state{meta=Meta}) -> - case maps:get(P, Meta, #{}) of - #{process_type := PT} -> io_lib:format(" (~w)", [PT]); - _ -> "" - end. +label(P, #state{meta = Meta}) -> + case maps:get(P, Meta, #{}) of + #{process_type := PT} -> io_lib:format(" (~w)", [PT]); + _ -> "" + end. diff --git a/src/profile/lg_rabbit_hole.erl b/src/profile/lg_rabbit_hole.erl index 688e0ce..ffedb26 100644 --- a/src/profile/lg_rabbit_hole.erl +++ b/src/profile/lg_rabbit_hole.erl @@ -36,24 +36,24 @@ -spec start_link() -> {ok, pid()}. start_link() -> - gen_server:start_link({local, lg}, ?MODULE, [], []). + gen_server:start_link({local, lg}, ?MODULE, [], []). %% gen_server. init([]) -> - {ok, undefined}. + {ok, undefined}. handle_call(_Request, _From, State) -> - {reply, ignored, State}. + {reply, ignored, State}. handle_cast(_Msg, State) -> - {noreply, State}. + {noreply, State}. handle_info(_Info, State) -> - {noreply, State}. + {noreply, State}. terminate(_Reason, _State) -> - ok. + ok. code_change(_OldVsn, State, _Extra) -> - {ok, State}. + {ok, State}. diff --git a/src/profile/lg_raw_console_tracer.erl b/src/profile/lg_raw_console_tracer.erl index a6f02f0..551bd00 100644 --- a/src/profile/lg_raw_console_tracer.erl +++ b/src/profile/lg_raw_console_tracer.erl @@ -23,31 +23,31 @@ -export([system_code_change/4]). start_link(_Nth, _Opts) -> - Pid = proc_lib:spawn_link(?MODULE, init, [self()]), - {ok, Pid}. + Pid = proc_lib:spawn_link(?MODULE, init, [self()]), + {ok, Pid}. init(Parent) -> - %% Store all messages off the heap to avoid unnecessary GC. - process_flag(message_queue_data, off_heap), - loop(Parent). + %% Store all messages off the heap to avoid unnecessary GC. + process_flag(message_queue_data, off_heap), + loop(Parent). loop(Parent) -> - receive - {system, From, Request} -> - sys:handle_system_msg(Request, From, Parent, ?MODULE, [], Parent); - Msg0 -> - %% Convert the event's monotonic time to its system time. - Msg = setelement(3, Msg0, erlang:time_offset(microsecond) + element(3, Msg0)), - erlang:display(Msg), - loop(Parent) - end. + receive + {system, From, Request} -> + sys:handle_system_msg(Request, From, Parent, ?MODULE, [], Parent); + Msg0 -> + %% Convert the event's monotonic time to its system time. + Msg = setelement(3, Msg0, erlang:time_offset(microsecond) + element(3, Msg0)), + erlang:display(Msg), + loop(Parent) + end. system_continue(_, _, Parent) -> - loop(Parent). + loop(Parent). -spec system_terminate(any(), _, _, _) -> no_return(). system_terminate(Reason, _, _, _) -> - exit(Reason). + exit(Reason). system_code_change(Misc, _, _, _) -> - {ok, Misc}. + {ok, Misc}. diff --git a/src/profile/lg_socket_client.erl b/src/profile/lg_socket_client.erl index 21aa5ae..ad44e9b 100644 --- a/src/profile/lg_socket_client.erl +++ b/src/profile/lg_socket_client.erl @@ -29,89 +29,89 @@ -export([terminate/3]). -record(state, { - port :: inet:port_number(), - base_filename :: file:filename_all(), - nth = 0 :: non_neg_integer(), - socket :: inet:socket() | undefined, - io_device :: file:io_device() | undefined, - events_per_frame = 100000 :: pos_integer(), - events_this_frame = 0 :: non_neg_integer(), - buffer = <<>> :: binary() + port :: inet:port_number(), + base_filename :: file:filename_all(), + nth = 0 :: non_neg_integer(), + socket :: inet:socket() | undefined, + io_device :: file:io_device() | undefined, + events_per_frame = 100000 :: pos_integer(), + events_this_frame = 0 :: non_neg_integer(), + buffer = <<>> :: binary() }). start_link(Port, BaseFilename) -> - gen_statem:start_link(?MODULE, [Port, BaseFilename], []). + gen_statem:start_link(?MODULE, [Port, BaseFilename], []). stop(Pid) -> - gen_statem:stop(Pid). + gen_statem:stop(Pid). callback_mode() -> - state_functions. + state_functions. init([Port, BaseFilename]) -> - %% Store all messages off the heap to avoid unnecessary GC. - process_flag(message_queue_data, off_heap), - %% We need to trap exit signals in order to shutdown properly. - process_flag(trap_exit, true), - {ok, connect, #state{port=Port, base_filename=BaseFilename}, - {next_event, internal, run}}. + %% Store all messages off the heap to avoid unnecessary GC. + process_flag(message_queue_data, off_heap), + %% We need to trap exit signals in order to shutdown properly. + process_flag(trap_exit, true), + {ok, connect, #state{port = Port, base_filename = BaseFilename}, + {next_event, internal, run}}. connect(internal, _, State) -> - do_connect(State); + do_connect(State); connect({timeout, retry}, retry, State) -> - do_connect(State); + do_connect(State); connect(_, _, State) -> - {keep_state, State}. - -do_connect(State=#state{port=Port}) -> - case gen_tcp:connect("localhost", Port, [binary, {packet, 2}, {active, true}]) of - {ok, Socket} -> - {next_state, open_file, State#state{socket=Socket}, - {next_event, internal, run}}; - {error, _} -> - {keep_state, State, [{{timeout, retry}, 1000, retry}]} - end. - -open_file(internal, _, State=#state{base_filename=Filename0, nth=Nth}) -> - Filename = filename:flatten([Filename0, ".", integer_to_list(Nth)]), - {ok, IoDevice} = file:open(Filename, [write, raw]), - {next_state, process_events, State#state{nth=Nth + 1, io_device=IoDevice}}. - -process_events(info, {tcp, Socket, Bin}, State=#state{socket=Socket, io_device=IoDevice, - events_per_frame=MaxEvents, events_this_frame=NumEvents0, buffer=Buffer0}) -> - BinSize = byte_size(Bin), - Buffer = <>, - NumEvents = NumEvents0 + 1, - if - MaxEvents =:= NumEvents -> - ok = file:write(IoDevice, lz4f:compress_frame(Buffer)), - {keep_state, State#state{events_this_frame=0, buffer= <<>>}}; - true -> - {keep_state, State#state{events_this_frame=NumEvents, buffer=Buffer}} - end; -process_events(info, {tcp_closed, Socket}, State=#state{socket=Socket}) -> - {next_state, close_file, State#state{socket=undefined}, - {next_event, internal, run}}; -process_events(info, {tcp_error, Socket, _}, State=#state{socket=Socket}) -> - _ = gen_tcp:close(Socket), - {next_state, close_file, State#state{socket=undefined}, - {next_event, internal, run}}. + {keep_state, State}. + +do_connect(State = #state{port = Port}) -> + case gen_tcp:connect("localhost", Port, [binary, {packet, 2}, {active, true}]) of + {ok, Socket} -> + {next_state, open_file, State#state{socket = Socket}, + {next_event, internal, run}}; + {error, _} -> + {keep_state, State, [{{timeout, retry}, 1000, retry}]} + end. + +open_file(internal, _, State = #state{base_filename = Filename0, nth = Nth}) -> + Filename = filename:flatten([Filename0, ".", integer_to_list(Nth)]), + {ok, IoDevice} = file:open(Filename, [write, raw]), + {next_state, process_events, State#state{nth = Nth + 1, io_device = IoDevice}}. + +process_events(info, {tcp, Socket, Bin}, State = #state{socket = Socket, io_device = IoDevice, + events_per_frame = MaxEvents, events_this_frame = NumEvents0, buffer = Buffer0}) -> + BinSize = byte_size(Bin), + Buffer = <>, + NumEvents = NumEvents0 + 1, + if + MaxEvents =:= NumEvents -> + ok = file:write(IoDevice, lz4f:compress_frame(Buffer)), + {keep_state, State#state{events_this_frame = 0, buffer = <<>>}}; + true -> + {keep_state, State#state{events_this_frame = NumEvents, buffer = Buffer}} + end; +process_events(info, {tcp_closed, Socket}, State = #state{socket = Socket}) -> + {next_state, close_file, State#state{socket = undefined}, + {next_event, internal, run}}; +process_events(info, {tcp_error, Socket, _}, State = #state{socket = Socket}) -> + _ = gen_tcp:close(Socket), + {next_state, close_file, State#state{socket = undefined}, + {next_event, internal, run}}. close_file(internal, _, State) -> - do_close_file(State), - {next_state, connect, State#state{io_device=undefined}, - {next_event, internal, run}}. + do_close_file(State), + {next_state, connect, State#state{io_device = undefined}, + {next_event, internal, run}}. -do_close_file(#state{io_device=IoDevice, buffer=Buffer}) -> - _ = file:write(IoDevice, lz4f:compress_frame(Buffer)), - _ = file:close(IoDevice), - ok. +do_close_file(#state{io_device = IoDevice, buffer = Buffer}) -> + _ = file:write(IoDevice, lz4f:compress_frame(Buffer)), + _ = file:close(IoDevice), + ok. code_change(_OldVsn, OldState, OldData, _Extra) -> - {callback_mode(), OldState, OldData}. + {callback_mode(), OldState, OldData}. -terminate(_, _, #state{io_device=undefined}) -> - ok; +terminate(_, _, #state{io_device = undefined}) -> + ok; terminate(_, _, State) -> - do_close_file(State), - ok. + do_close_file(State), + ok. diff --git a/src/profile/lg_socket_tracer.erl b/src/profile/lg_socket_tracer.erl index 0238f2d..bf3be75 100644 --- a/src/profile/lg_socket_tracer.erl +++ b/src/profile/lg_socket_tracer.erl @@ -22,127 +22,127 @@ -export([system_code_change/4]). -record(state, { - parent :: pid(), - lsocket :: inet:socket(), - timeout_ref :: reference() | undefined + parent :: pid(), + lsocket :: inet:socket(), + timeout_ref :: reference() | undefined }). start_link(Nth, BasePort) -> - Pid = proc_lib:spawn_link(?MODULE, init, [self(), BasePort + Nth - 1]), - {ok, Pid}. + Pid = proc_lib:spawn_link(?MODULE, init, [self(), BasePort + Nth - 1]), + {ok, Pid}. init(Parent, Port) -> - %% Store all messages off the heap to avoid unnecessary GC. - process_flag(message_queue_data, off_heap), - %% We need to trap exit signals in order to shutdown properly. - process_flag(trap_exit, true), - %% Open the listening socket. - {ok, LSocket} = gen_tcp:listen(Port, [ - binary, {reuseaddr, true}, {nodelay, true}, - %% We encode all events to binary inside a 2-byte length frame. - {packet, 2}, - %% We expect the client to send pings every second or so and - %% nothing else, so using active mode is faster and still safe. - {active, true}, - %% We only expect one connection at a time. We don't need - %% a backlog except for the cases where the connection is - %% lost and will reconnect immediately before we get a - %% chance to accept again. - {backlog, 1} - %% We are using non-blocking TCP send. We therefore do not - %% need to configure send timeout options. - ]), - %% We reject all messages until we get a connection. - accept(#state{parent=Parent, lsocket=LSocket}). - -accept(State=#state{lsocket=LSocket}) -> - {ok, AcceptRef} = prim_inet:async_accept(LSocket, -1), - accept_loop(State, AcceptRef). - -accept_loop(State=#state{parent=Parent, lsocket=LSocket}, AcceptRef) -> - receive - {'EXIT', Parent, Reason} -> - exit(Reason); - {system, From, Request} -> - sys:handle_system_msg(Request, From, Parent, ?MODULE, [], - {accept_loop, State, AcceptRef}); - {inet_async, LSocket, AcceptRef, {ok, CSocket}} -> - trace_loop(set_timeout(State), CSocket); - {inet_async, LSocket, AcceptRef, Error} -> - exit({accept_error, Error}); - %% We discard all trace events when no client is connected. - %% We may also end up discarding old timeouts or TCP messages. - _ -> - accept_loop(State, AcceptRef) - end. - -trace_loop(State=#state{parent=Parent, timeout_ref=TRef}, CSocket) -> - receive - {'EXIT', Parent, Reason} -> - exit(Reason); - {system, From, Request} -> - sys:handle_system_msg(Request, From, Parent, ?MODULE, [], - {trace_loop, State, CSocket}); - %% Reset the timeout when we receive data. - {tcp, CSocket, _} -> - trace_loop(reset_timeout(State), CSocket); - {tcp_closed, CSocket} -> - close(State, CSocket); - {tcp_error, CSocket, _} -> - close(State, CSocket); - {timeout, TRef, ?MODULE} -> - close(State, CSocket); - %% Discard the non-blocking send reply when successful. - {inet_reply, CSocket, ok} -> - trace_loop(State, CSocket); - %% And close the socket when an error occured. - {inet_reply, CSocket, _} -> - close(State, CSocket); - %% Discard TCP messages from closed sockets. - {tcp, _, _} -> - trace_loop(State, CSocket); - {tcp_closed, _} -> - trace_loop(State, CSocket); - {tcp_error, _, _} -> - trace_loop(State, CSocket); - %% Discard any previous timeout. - {timeout, _, ?MODULE} -> - trace_loop(State, CSocket); - Msg -> - Bin = term_to_binary(Msg), - _ = byte_size(Bin), - case erlang:port_command(CSocket, <>, [nosuspend]) of - true -> - trace_loop(State, CSocket); - %% The send buffer is full. - false -> - close(State, CSocket) - end - end. + %% Store all messages off the heap to avoid unnecessary GC. + process_flag(message_queue_data, off_heap), + %% We need to trap exit signals in order to shutdown properly. + process_flag(trap_exit, true), + %% Open the listening socket. + {ok, LSocket} = gen_tcp:listen(Port, [ + binary, {reuseaddr, true}, {nodelay, true}, + %% We encode all events to binary inside a 2-byte length frame. + {packet, 2}, + %% We expect the client to send pings every second or so and + %% nothing else, so using active mode is faster and still safe. + {active, true}, + %% We only expect one connection at a time. We don't need + %% a backlog except for the cases where the connection is + %% lost and will reconnect immediately before we get a + %% chance to accept again. + {backlog, 1} + %% We are using non-blocking TCP send. We therefore do not + %% need to configure send timeout options. + ]), + %% We reject all messages until we get a connection. + accept(#state{parent = Parent, lsocket = LSocket}). + +accept(State = #state{lsocket = LSocket}) -> + {ok, AcceptRef} = prim_inet:async_accept(LSocket, -1), + accept_loop(State, AcceptRef). + +accept_loop(State = #state{parent = Parent, lsocket = LSocket}, AcceptRef) -> + receive + {'EXIT', Parent, Reason} -> + exit(Reason); + {system, From, Request} -> + sys:handle_system_msg(Request, From, Parent, ?MODULE, [], + {accept_loop, State, AcceptRef}); + {inet_async, LSocket, AcceptRef, {ok, CSocket}} -> + trace_loop(set_timeout(State), CSocket); + {inet_async, LSocket, AcceptRef, Error} -> + exit({accept_error, Error}); + %% We discard all trace events when no client is connected. + %% We may also end up discarding old timeouts or TCP messages. + _ -> + accept_loop(State, AcceptRef) + end. + +trace_loop(State = #state{parent = Parent, timeout_ref = TRef}, CSocket) -> + receive + {'EXIT', Parent, Reason} -> + exit(Reason); + {system, From, Request} -> + sys:handle_system_msg(Request, From, Parent, ?MODULE, [], + {trace_loop, State, CSocket}); + %% Reset the timeout when we receive data. + {tcp, CSocket, _} -> + trace_loop(reset_timeout(State), CSocket); + {tcp_closed, CSocket} -> + close(State, CSocket); + {tcp_error, CSocket, _} -> + close(State, CSocket); + {timeout, TRef, ?MODULE} -> + close(State, CSocket); + %% Discard the non-blocking send reply when successful. + {inet_reply, CSocket, ok} -> + trace_loop(State, CSocket); + %% And close the socket when an error occured. + {inet_reply, CSocket, _} -> + close(State, CSocket); + %% Discard TCP messages from closed sockets. + {tcp, _, _} -> + trace_loop(State, CSocket); + {tcp_closed, _} -> + trace_loop(State, CSocket); + {tcp_error, _, _} -> + trace_loop(State, CSocket); + %% Discard any previous timeout. + {timeout, _, ?MODULE} -> + trace_loop(State, CSocket); + Msg -> + Bin = term_to_binary(Msg), + _ = byte_size(Bin), + case erlang:port_command(CSocket, <>, [nosuspend]) of + true -> + trace_loop(State, CSocket); + %% The send buffer is full. + false -> + close(State, CSocket) + end + end. close(State, CSocket) -> - _ = gen_tcp:close(CSocket), - accept(cancel_timeout(State)). + _ = gen_tcp:close(CSocket), + accept(cancel_timeout(State)). system_continue(_, _, {accept_loop, State, AcceptRef}) -> - accept_loop(State, AcceptRef); + accept_loop(State, AcceptRef); system_continue(_, _, {trace_loop, State, CSocket}) -> - trace_loop(State, CSocket). + trace_loop(State, CSocket). -spec system_terminate(any(), _, _, _) -> no_return(). system_terminate(Reason, _, _, _) -> - exit(Reason). + exit(Reason). system_code_change(Misc, _, _, _) -> - {ok, Misc}. + {ok, Misc}. reset_timeout(State) -> - set_timeout(cancel_timeout(State)). + set_timeout(cancel_timeout(State)). set_timeout(State) -> - TRef = erlang:start_timer(5000, self(), ?MODULE), - State#state{timeout_ref=TRef}. + TRef = erlang:start_timer(5000, self(), ?MODULE), + State#state{timeout_ref = TRef}. -cancel_timeout(State=#state{timeout_ref=TRef}) -> - _ = erlang:cancel_timer(TRef, [{async, true}, {info, false}]), - State#state{timeout_ref=undefined}. +cancel_timeout(State = #state{timeout_ref = TRef}) -> + _ = erlang:cancel_timer(TRef, [{async, true}, {info, false}]), + State#state{timeout_ref = undefined}. diff --git a/src/profile/lg_term.erl b/src/profile/lg_term.erl index 0093a59..db0aab6 100644 --- a/src/profile/lg_term.erl +++ b/src/profile/lg_term.erl @@ -29,98 +29,98 @@ -define(MAX_TUPLE_SIZE, 32). truncate(Term) -> - truncate(Term, 1). + truncate(Term, 1). truncate(_, Depth) when Depth > ?MAX_DEPTH -> - '$truncated'; + '$truncated'; truncate(Term, _) when bit_size(Term) > ?MAX_BITSTRING_SIZE -> - <> = Term, - <>; + <> = Term, + <>; truncate(Term, Depth) when is_list(Term), Depth =:= ?MAX_DEPTH -> - ['$truncated']; + ['$truncated']; truncate(Term, Depth) when is_list(Term) -> - truncate_list(Term, Depth, 0, ?MAX_LIST_LENGTH, 0); + truncate_list(Term, Depth, 0, ?MAX_LIST_LENGTH, 0); truncate(Term, Depth) when is_map(Term), Depth =:= ?MAX_DEPTH -> - #{'$truncated' => '$truncated'}; + #{'$truncated' => '$truncated'}; truncate(Term, Depth) when is_map(Term) -> - maps:from_list(truncate_map(maps_to_list(Term, ?MAX_MAP_SIZE), Depth, 0)); + maps:from_list(truncate_map(maps_to_list(Term, ?MAX_MAP_SIZE), Depth, 0)); truncate(Term, Depth) when is_tuple(Term), Depth =:= ?MAX_DEPTH -> - {'$truncated'}; + {'$truncated'}; truncate(Term, Depth) when is_tuple(Term) -> - list_to_tuple(truncate_list(tuple_to_list(Term), Depth, 0, ?MAX_TUPLE_SIZE, 0)); + list_to_tuple(truncate_list(tuple_to_list(Term), Depth, 0, ?MAX_TUPLE_SIZE, 0)); truncate(Term, _) -> - Term. + Term. truncate_list([], _, _, _, _) -> - []; + []; truncate_list(_, _, Len, MaxLen, _) when Len > MaxLen -> - ['$truncated']; + ['$truncated']; truncate_list(_, _, _, _, NumStructs) when NumStructs > ?MAX_DATA_STRUCTURES -> - ['$truncated']; -truncate_list([Term|Tail], Depth, Len, MaxLen, NumStructs) -> - [truncate(Term, Depth + 1) - %% if List was a cons, Tail can be anything - |truncate_list(Tail, Depth, Len + 1, MaxLen, NumStructs + is_struct(Term))]; + ['$truncated']; +truncate_list([Term | Tail], Depth, Len, MaxLen, NumStructs) -> + [truncate(Term, Depth + 1) + %% if List was a cons, Tail can be anything + | truncate_list(Tail, Depth, Len + 1, MaxLen, NumStructs + is_struct(Term))]; truncate_list(Term, Depth, _, _, _) -> %% if List was a cons - truncate(Term, Depth + 1). + truncate(Term, Depth + 1). truncate_map([], _, _) -> - []; + []; truncate_map(_, _, NumStructs) when NumStructs > ?MAX_DATA_STRUCTURES -> - [{'$truncated', '$truncated'}]; -truncate_map([{Key, Value}|Tail], Depth, NumStructs) -> - AddStruct = is_struct(Key) + is_struct(Value), - [{truncate(Key, Depth + 1), truncate(Value, Depth + 1)} - |truncate_map(Tail, Depth, NumStructs + AddStruct)]. + [{'$truncated', '$truncated'}]; +truncate_map([{Key, Value} | Tail], Depth, NumStructs) -> + AddStruct = is_struct(Key) + is_struct(Value), + [{truncate(Key, Depth + 1), truncate(Value, Depth + 1)} + | truncate_map(Tail, Depth, NumStructs + AddStruct)]. is_struct(Term) -> - if - is_list(Term) -> 1; - is_map(Term) -> 1; - is_tuple(Term) -> 1; - true -> 0 - end. + if + is_list(Term) -> 1; + is_map(Term) -> 1; + is_tuple(Term) -> 1; + true -> 0 + end. %% Map iterators were introduced in Erlang/OTP 21. They replace %% the undocumented function erts_internal:maps_to_list/2. -ifdef(OTP_RELEASE). maps_to_list(Map, MaxSize) -> - I = maps:iterator(Map), - maps_to_list(maps:next(I), MaxSize, []). + I = maps:iterator(Map), + maps_to_list(maps:next(I), MaxSize, []). %% Returns elements in arbitrary order. We reverse when we truncate %% so that the truncated elements come at the end to avoid having %% two truncated elements in the final output. maps_to_list(none, _, Acc) -> - Acc; + Acc; maps_to_list(_, 0, Acc) -> - lists:reverse([{'$truncated', '$truncated'}|Acc]); + lists:reverse([{'$truncated', '$truncated'} | Acc]); maps_to_list({K, V, I}, N, Acc) -> - maps_to_list(maps:next(I), N - 1, [{K, V}|Acc]). + maps_to_list(maps:next(I), N - 1, [{K, V} | Acc]). -else. maps_to_list(Map, MaxSize) -> - erts_internal:maps_to_list(Map, MaxSize). + erts_internal:maps_to_list(Map, MaxSize). -endif. -ifdef(TEST). maps_to_list_test() -> - [] = maps_to_list(#{}, 10), - [{'$truncated', '$truncated'}] = maps_to_list(#{a => b}, 0), - [{a, b}] = maps_to_list(#{a => b}, 10), - [{a, b}, {c, d}, {e, f}] = lists:sort(maps_to_list( - #{a => b, c => d, e => f}, 3)), - [{'$truncated', '$truncated'}, {a, b}, {c, d}, {e, f}] = lists:sort(maps_to_list( - #{a => b, c => d, e => f, g => h}, 3)), - [{'$truncated', '$truncated'}, {a, b}, {c, d}, {e, f}] = lists:sort(maps_to_list( - #{a => b, c => d, e => f, g => h, i => j}, 3)), - %% Confirm that truncated values are at the end. - [_, _, _, {'$truncated', '$truncated'}] = maps_to_list( - #{a => b, c => d, e => f, g => h, i => j}, 3), - ok. + [] = maps_to_list(#{}, 10), + [{'$truncated', '$truncated'}] = maps_to_list(#{a => b}, 0), + [{a, b}] = maps_to_list(#{a => b}, 10), + [{a, b}, {c, d}, {e, f}] = lists:sort(maps_to_list( + #{a => b, c => d, e => f}, 3)), + [{'$truncated', '$truncated'}, {a, b}, {c, d}, {e, f}] = lists:sort(maps_to_list( + #{a => b, c => d, e => f, g => h}, 3)), + [{'$truncated', '$truncated'}, {a, b}, {c, d}, {e, f}] = lists:sort(maps_to_list( + #{a => b, c => d, e => f, g => h, i => j}, 3)), + %% Confirm that truncated values are at the end. + [_, _, _, {'$truncated', '$truncated'}] = maps_to_list( + #{a => b, c => d, e => f, g => h, i => j}, 3), + ok. -endif. diff --git a/src/profile/lg_tracer.erl b/src/profile/lg_tracer.erl index 1eba511..81b0d13 100644 --- a/src/profile/lg_tracer.erl +++ b/src/profile/lg_tracer.erl @@ -24,27 +24,27 @@ -on_load(on_load/0). on_load() -> - case code:priv_dir(looking_glass) of - {error, _} -> - {error, {load_failed, "Could not determine the looking_glass priv/ directory."}}; - Path -> - erlang:load_nif(filename:join(Path, atom_to_list(?MODULE)), 0) - end. + case code:priv_dir(looking_glass) of + {error, _} -> + {error, {load_failed, "Could not determine the looking_glass priv/ directory."}}; + Path -> + erlang:load_nif(filename:join(Path, atom_to_list(?MODULE)), 0) + end. enabled(_, _, _) -> - erlang:nif_error({not_loaded, ?MODULE}). + erlang:nif_error({not_loaded, ?MODULE}). enabled_call(_, _, _) -> - erlang:nif_error({not_loaded, ?MODULE}). + erlang:nif_error({not_loaded, ?MODULE}). enabled_procs(_, _, _) -> - erlang:nif_error({not_loaded, ?MODULE}). + erlang:nif_error({not_loaded, ?MODULE}). enabled_running_procs(_, _, _) -> - erlang:nif_error({not_loaded, ?MODULE}). + erlang:nif_error({not_loaded, ?MODULE}). enabled_send(_, _, _) -> - erlang:nif_error({not_loaded, ?MODULE}). + erlang:nif_error({not_loaded, ?MODULE}). trace(_, _, _, _, _) -> - erlang:nif_error({not_loaded, ?MODULE}). + erlang:nif_error({not_loaded, ?MODULE}). diff --git a/src/profile/lg_tracer_pool.erl b/src/profile/lg_tracer_pool.erl index f9fd30d..aee5bcd 100644 --- a/src/profile/lg_tracer_pool.erl +++ b/src/profile/lg_tracer_pool.erl @@ -20,15 +20,15 @@ -export([tracers/1]). start_link(NumTracers, TracerMod, Opts) -> - supervisor:start_link(?MODULE, [NumTracers, TracerMod, Opts]). + supervisor:start_link(?MODULE, [NumTracers, TracerMod, Opts]). init([NumTracers, TracerMod, Opts]) -> - Procs = [#{ - id => {tracer, N}, - start => {TracerMod, start_link, [N, Opts]}, - restart => temporary - } || N <- lists:seq(1, NumTracers)], - {ok, {#{strategy => one_for_all}, Procs}}. + Procs = [#{ + id => {tracer, N}, + start => {TracerMod, start_link, [N, Opts]}, + restart => temporary + } || N <- lists:seq(1, NumTracers)], + {ok, {#{strategy => one_for_all}, Procs}}. tracers(PoolPid) -> - [Pid || {_, Pid, _, _} <- supervisor:which_children(PoolPid)]. + [Pid || {_, Pid, _, _} <- supervisor:which_children(PoolPid)]. diff --git a/src/profile/looking_glass_app.erl b/src/profile/looking_glass_app.erl index c8f3b53..3fd13e7 100644 --- a/src/profile/looking_glass_app.erl +++ b/src/profile/looking_glass_app.erl @@ -19,7 +19,7 @@ -export([stop/1]). start(_Type, _Args) -> - looking_glass_sup:start_link(). + looking_glass_sup:start_link(). stop(_State) -> - ok. + ok. diff --git a/src/profile/looking_glass_sup.erl b/src/profile/looking_glass_sup.erl index 613ea87..ebf4d31 100644 --- a/src/profile/looking_glass_sup.erl +++ b/src/profile/looking_glass_sup.erl @@ -19,11 +19,11 @@ -export([init/1]). start_link() -> - supervisor:start_link({local, ?MODULE}, ?MODULE, []). + supervisor:start_link({local, ?MODULE}, ?MODULE, []). init([]) -> - Procs = [ - {lg_rabbit_hole, {lg_rabbit_hole, start_link, []}, - permanent, 5000, worker, [lg_rabbit_hole]} - ], - {ok, {{one_for_one, 1, 5}, Procs}}. + Procs = [ + {lg_rabbit_hole, {lg_rabbit_hole, start_link, []}, + permanent, 5000, worker, [lg_rabbit_hole]} + ], + {ok, {{one_for_one, 1, 5}, Procs}}. diff --git a/test/lg_SUITE.erl b/test/lg_SUITE.erl index 8765b83..f9d12cf 100644 --- a/test/lg_SUITE.erl +++ b/test/lg_SUITE.erl @@ -7,283 +7,283 @@ %% ct. all() -> - [{group, all}]. + [{group, all}]. %% We cannot run the tests in parallel or they would %% interfere with each other. groups() -> - [{all, [], ct_helper:all(?MODULE)}]. + [{all, [], ct_helper:all(?MODULE)}]. %% Tests. app(Config) -> - doc("Trace a specific application."), - eTpf:trace({app, stdlib}, lg_file_tracer, config(priv_dir, Config) ++ "/app.lz4"), - lists:seq(1,10), - eTpf:stop(), - do_ensure_decompress(config(priv_dir, Config) ++ "/app.lz4"). + doc("Trace a specific application."), + eTpf:trace({app, stdlib}, lg_file_tracer, config(priv_dir, Config) ++ "/app.lz4"), + lists:seq(1, 10), + eTpf:stop(), + do_ensure_decompress(config(priv_dir, Config) ++ "/app.lz4"). callback(Config) -> - doc("Trace using patterns from a callback function."), - eTpf:trace({callback, ?MODULE, do_callback}, lg_file_tracer, - config(priv_dir, Config) ++ "/callback.lz4"), - lists:seq(1,10), - eTpf:stop(), - do_ensure_decompress(config(priv_dir, Config) ++ "/callback.lz4"). + doc("Trace using patterns from a callback function."), + eTpf:trace({callback, ?MODULE, do_callback}, lg_file_tracer, + config(priv_dir, Config) ++ "/callback.lz4"), + lists:seq(1, 10), + eTpf:stop(), + do_ensure_decompress(config(priv_dir, Config) ++ "/callback.lz4"). do_callback() -> - [{scope, [self()]}, lists]. + [{scope, [self()]}, lists]. callgrind_running(Config) -> - doc("Save events to files on disk then build callgrind files."), - PrivDir = config(priv_dir, Config), - eTpf:trace([{scope, [self()]}, ?MODULE, {app, stdlib}], lg_file_tracer, - PrivDir ++ "/callgrind_running.lz4", - #{mode => profile, running => true}), - do_callgrind_running(), - eTpf:stop(), - lg_callgrind:profile_many( - PrivDir ++ "/callgrind_running.lz4.*", - PrivDir ++ "/callgrind_running.out", - #{running => true}), - %% For debugging purposes, print the contents of the callgrind.out files. - %% Uncomment for easier debugging, otherwise look into the files directly. + doc("Save events to files on disk then build callgrind files."), + PrivDir = config(priv_dir, Config), + eTpf:trace([{scope, [self()]}, ?MODULE, {app, stdlib}], lg_file_tracer, + PrivDir ++ "/callgrind_running.lz4", + #{mode => profile, running => true}), + do_callgrind_running(), + eTpf:stop(), + lg_callgrind:profile_many( + PrivDir ++ "/callgrind_running.lz4.*", + PrivDir ++ "/callgrind_running.out", + #{running => true}), + %% For debugging purposes, print the contents of the callgrind.out files. + %% Uncomment for easier debugging, otherwise look into the files directly. % _ = [begin % {ok, File} = file:read_file(PrivDir ++ "/callgrind_running.out." ++ integer_to_list(N)), % io:format(user, "# callgrind_running.out.~p~n~s", [N, File]), % lg_file_reader:foreach(fun(E) -> io:format(user, "~p~n", [E]) end, % PrivDir ++ "/callgrind_running.lz4." ++ integer_to_list(N)) % end || N <- lists:seq(1, erlang:system_info(schedulers))], - ok. + ok. do_callgrind_running() -> - timer:sleep(1000), - Ref = make_ref(), - erlang:send_after(1000, self(), {go, Ref}), - lists:seq(1,100), - do_callgrind_running_receive(Ref), - lists:seq(1,100), - ok. + timer:sleep(1000), + Ref = make_ref(), + erlang:send_after(1000, self(), {go, Ref}), + lists:seq(1, 100), + do_callgrind_running_receive(Ref), + lists:seq(1, 100), + ok. do_callgrind_running_receive(Ref) -> - receive - {go, Ref} -> - ok - end. + receive + {go, Ref} -> + ok + end. callgrind_running_cycle(Config) -> - doc("Save events to files on disk then build callgrind files. " - "Create a recursive cycle using two functions calling each other."), - PrivDir = config(priv_dir, Config), - eTpf:trace([{scope, [self()]}, ?MODULE, {app, stdlib}], lg_file_tracer, - PrivDir ++ "/callgrind_running_cycle.lz4", - #{mode => profile, running => true}), - do_callgrind_running_cycle(), - eTpf:stop(), - lg_callgrind:profile_many( - PrivDir ++ "/callgrind_running_cycle.lz4.*", - PrivDir ++ "/callgrind_running_cycle.out", - #{running => true}), - %% For debugging purposes, print the contents of the callgrind.out files. - %% Uncomment for easier debugging, otherwise look into the files directly. + doc("Save events to files on disk then build callgrind files. " + "Create a recursive cycle using two functions calling each other."), + PrivDir = config(priv_dir, Config), + eTpf:trace([{scope, [self()]}, ?MODULE, {app, stdlib}], lg_file_tracer, + PrivDir ++ "/callgrind_running_cycle.lz4", + #{mode => profile, running => true}), + do_callgrind_running_cycle(), + eTpf:stop(), + lg_callgrind:profile_many( + PrivDir ++ "/callgrind_running_cycle.lz4.*", + PrivDir ++ "/callgrind_running_cycle.out", + #{running => true}), + %% For debugging purposes, print the contents of the callgrind.out files. + %% Uncomment for easier debugging, otherwise look into the files directly. % _ = [begin % {ok, File} = file:read_file(PrivDir ++ "/callgrind_running_cycle.out." ++ integer_to_list(N)), % io:format(user, "# callgrind_running_cycle.out.~p~n~s", [N, File]), % lg_file_reader:foreach(fun(E) -> io:format(user, "~p~n", [E]) end, % PrivDir ++ "/callgrind_running_cycle.lz4." ++ integer_to_list(N)) % end || N <- lists:seq(1, erlang:system_info(schedulers))], - ok. + ok. do_callgrind_running_cycle() -> - timer:sleep(1000), - lists:seq(1,100), - do_callgrind_running_cycle1(do_callgrind_running_cycle_timer(20)), - lists:seq(1,100), - ok. + timer:sleep(1000), + lists:seq(1, 100), + do_callgrind_running_cycle1(do_callgrind_running_cycle_timer(20)), + lists:seq(1, 100), + ok. do_callgrind_running_cycle_timer(N) -> - erlang:start_timer(N * 10, self(), N). + erlang:start_timer(N * 10, self(), N). do_callgrind_running_cycle1(Ref) -> - receive - {timeout, Ref, 0} -> - ok; - {timeout, Ref, N} when N rem 5 =:= 0 -> - do_callgrind_running_cycle2(do_callgrind_running_cycle_timer(N - 1)); - {timeout, Ref, N} -> - do_callgrind_running_cycle1(do_callgrind_running_cycle_timer(N - 1)) - end. + receive + {timeout, Ref, 0} -> + ok; + {timeout, Ref, N} when N rem 5 =:= 0 -> + do_callgrind_running_cycle2(do_callgrind_running_cycle_timer(N - 1)); + {timeout, Ref, N} -> + do_callgrind_running_cycle1(do_callgrind_running_cycle_timer(N - 1)) + end. do_callgrind_running_cycle2(Ref) -> - receive - {timeout, Ref, 0} -> - ok; - {timeout, Ref, N} when N rem 4 =:= 0 -> - do_callgrind_running_cycle1(do_callgrind_running_cycle_timer(N - 1)); - {timeout, Ref, N} -> - do_callgrind_running_cycle2(do_callgrind_running_cycle_timer(N - 1)) - end. + receive + {timeout, Ref, 0} -> + ok; + {timeout, Ref, N} when N rem 4 =:= 0 -> + do_callgrind_running_cycle1(do_callgrind_running_cycle_timer(N - 1)); + {timeout, Ref, N} -> + do_callgrind_running_cycle2(do_callgrind_running_cycle_timer(N - 1)) + end. file_tracer(Config) -> - doc("Save events to files on disk."), - eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/file_tracer.lz4"), - lists:seq(1,10), - eTpf:stop(), - do_ensure_decompress(config(priv_dir, Config) ++ "/file_tracer.lz4"). + doc("Save events to files on disk."), + eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/file_tracer.lz4"), + lists:seq(1, 10), + eTpf:stop(), + do_ensure_decompress(config(priv_dir, Config) ++ "/file_tracer.lz4"). file_tracer_rotation(Config) -> - doc("Save events to files on disk; rotate the files if they get too big."), - Prefix = config(priv_dir, Config) ++ "/file_tracer.lz4", - eTpf:trace(lists, lg_file_tracer, #{ - filename_prefix => Prefix, - max_size => 100, %% Intentionally low. - events_per_frame => 10 %% Needed to trigger the rotation, default is too high. - }), - lists:seq(1,1000), - eTpf:stop(), - %% We should have one or more rotated files. - Result = [begin - Filename = Prefix ++ "." ++ integer_to_list(N) ++ ".bak", - filelib:is_file(Filename) - end || N <- lists:seq(1, erlang:system_info(schedulers))], - true = lists:member(true, lists:usort(Result)), - ok. + doc("Save events to files on disk; rotate the files if they get too big."), + Prefix = config(priv_dir, Config) ++ "/file_tracer.lz4", + eTpf:trace(lists, lg_file_tracer, #{ + filename_prefix => Prefix, + max_size => 100, %% Intentionally low. + events_per_frame => 10 %% Needed to trigger the rotation, default is too high. + }), + lists:seq(1, 1000), + eTpf:stop(), + %% We should have one or more rotated files. + Result = [begin + Filename = Prefix ++ "." ++ integer_to_list(N) ++ ".bak", + filelib:is_file(Filename) + end || N <- lists:seq(1, erlang:system_info(schedulers))], + true = lists:member(true, lists:usort(Result)), + ok. mod(Config) -> - doc("Trace a specific module."), - eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/mod.lz4"), - lists:seq(1,10), - eTpf:stop(), - do_ensure_decompress(config(priv_dir, Config) ++ "/mod.lz4"). + doc("Trace a specific module."), + eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/mod.lz4"), + lists:seq(1, 10), + eTpf:stop(), + do_ensure_decompress(config(priv_dir, Config) ++ "/mod.lz4"). profile_mode(Config) -> - doc("Trace a specific module in profile mode."), - eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/profile_mode.lz4", - #{mode => profile}), - lists:seq(1,10), - eTpf:stop(), - do_ensure_decompress(config(priv_dir, Config) ++ "/profile_mode.lz4"). + doc("Trace a specific module in profile mode."), + eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/profile_mode.lz4", + #{mode => profile}), + lists:seq(1, 10), + eTpf:stop(), + do_ensure_decompress(config(priv_dir, Config) ++ "/profile_mode.lz4"). raw_console_tracer(_) -> - doc("Print raw events to the console."), - ct:print("Start tracing to the console."), - %% @todo It seems the order matters when starting. Should it? - eTpf:trace([{scope, [self()]}, lists]), - lists:seq(1,10), - eTpf:stop(), - ct:print("Stop tracing to the console."). + doc("Print raw events to the console."), + ct:print("Start tracing to the console."), + %% @todo It seems the order matters when starting. Should it? + eTpf:trace([{scope, [self()]}, lists]), + lists:seq(1, 10), + eTpf:stop(), + ct:print("Stop tracing to the console."). running_true(Config) -> - doc("Trace a specific module with running option enabled."), - eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/running_true.lz4", - #{running => true}), - lists:seq(1,10), - eTpf:stop(), - do_ensure_decompress(config(priv_dir, Config) ++ "/running_true.lz4"). + doc("Trace a specific module with running option enabled."), + eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/running_true.lz4", + #{running => true}), + lists:seq(1, 10), + eTpf:stop(), + do_ensure_decompress(config(priv_dir, Config) ++ "/running_true.lz4"). send_true(Config) -> - doc("Trace a specific module with send option enabled."), - eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/send_true.lz4", - #{send => true}), - Self = self(), - %% Send a message to and from an existing process. - Pid = spawn(fun() -> - receive {msg_from, Self} -> - Self ! {msg_from, self()} - end - end), - Pid ! {msg_from, Self}, - receive {msg_from, Pid} -> ok end, - %% Also send a message to a non existing process. - DeadPid = spawn(fun() -> ok end), - receive after 100 -> ok end, - DeadPid ! {msg_from, Self}, - eTpf:stop(), - do_ensure_decompress(config(priv_dir, Config) ++ "/send_true.lz4"). + doc("Trace a specific module with send option enabled."), + eTpf:trace(lists, lg_file_tracer, config(priv_dir, Config) ++ "/send_true.lz4", + #{send => true}), + Self = self(), + %% Send a message to and from an existing process. + Pid = spawn(fun() -> + receive {msg_from, Self} -> + Self ! {msg_from, self()} + end + end), + Pid ! {msg_from, Self}, + receive {msg_from, Pid} -> ok end, + %% Also send a message to a non existing process. + DeadPid = spawn(fun() -> ok end), + receive after 100 -> ok end, + DeadPid ! {msg_from, Self}, + eTpf:stop(), + do_ensure_decompress(config(priv_dir, Config) ++ "/send_true.lz4"). socket_tracer(_) -> - doc("Send events to a socket."), - Port = 61234, - eTpf:trace(lists, lg_socket_tracer, Port, #{pool_size => 1}), - {ok, Socket} = gen_tcp:connect("localhost", Port, - [binary, {packet, 2}, {active, true}]), - lists:seq(1,10), - eTpf:stop(), - do_socket_tracer_recv(Socket). + doc("Send events to a socket."), + Port = 61234, + eTpf:trace(lists, lg_socket_tracer, Port, #{pool_size => 1}), + {ok, Socket} = gen_tcp:connect("localhost", Port, + [binary, {packet, 2}, {active, true}]), + lists:seq(1, 10), + eTpf:stop(), + do_socket_tracer_recv(Socket). socket_tracer_client(Config) -> - doc("Send events to a socket client."), - Port = 61234, - eTpf:trace(lists, lg_socket_tracer, Port, #{pool_size => 1}), - BaseFilename = config(priv_dir, Config) ++ "/socket_tracer_client.lz4", - {ok, Pid} = lg_socket_client:start_link(Port, BaseFilename), - timer:sleep(1000), - lists:seq(1,10), - eTpf:stop(), - lg_socket_client:stop(Pid), - {ok, File} = file:read_file(BaseFilename ++ ".0"), - _ = lz4f:decompress(File), - true = filelib:file_size(BaseFilename ++ ".0") > 0, - ok. + doc("Send events to a socket client."), + Port = 61234, + eTpf:trace(lists, lg_socket_tracer, Port, #{pool_size => 1}), + BaseFilename = config(priv_dir, Config) ++ "/socket_tracer_client.lz4", + {ok, Pid} = lg_socket_client:start_link(Port, BaseFilename), + timer:sleep(1000), + lists:seq(1, 10), + eTpf:stop(), + lg_socket_client:stop(Pid), + {ok, File} = file:read_file(BaseFilename ++ ".0"), + _ = lz4f:decompress(File), + true = filelib:file_size(BaseFilename ++ ".0") > 0, + ok. socket_tracer_many(_) -> - doc("Send events to many sockets."), - Port = 61234, - eTpf:trace(lists, lg_socket_tracer, Port, #{pool_size => 5}), - {ok, _} = gen_tcp:connect("localhost", Port, []), - {ok, _} = gen_tcp:connect("localhost", Port + 1, []), - {ok, _} = gen_tcp:connect("localhost", Port + 2, []), - {ok, _} = gen_tcp:connect("localhost", Port + 3, []), - {ok, _} = gen_tcp:connect("localhost", Port + 4, []), - {error, _} = gen_tcp:connect("localhost", Port + 5, []), - eTpf:stop(). + doc("Send events to many sockets."), + Port = 61234, + eTpf:trace(lists, lg_socket_tracer, Port, #{pool_size => 5}), + {ok, _} = gen_tcp:connect("localhost", Port, []), + {ok, _} = gen_tcp:connect("localhost", Port + 1, []), + {ok, _} = gen_tcp:connect("localhost", Port + 2, []), + {ok, _} = gen_tcp:connect("localhost", Port + 3, []), + {ok, _} = gen_tcp:connect("localhost", Port + 4, []), + {error, _} = gen_tcp:connect("localhost", Port + 5, []), + eTpf:stop(). socket_tracer_reconnect(_) -> - doc("Confirm we can reconnect to the tracer."), - Port = 61234, - eTpf:trace(lists, lg_socket_tracer, Port, #{pool_size => 1}), - {ok, Socket0} = gen_tcp:connect("localhost", Port, - [binary, {packet, 2}, {active, true}]), - ok = gen_tcp:close(Socket0), - {ok, Socket} = gen_tcp:connect("localhost", Port, - [binary, {packet, 2}, {active, true}]), - lists:seq(1,10), - eTpf:stop(), - do_socket_tracer_recv(Socket). + doc("Confirm we can reconnect to the tracer."), + Port = 61234, + eTpf:trace(lists, lg_socket_tracer, Port, #{pool_size => 1}), + {ok, Socket0} = gen_tcp:connect("localhost", Port, + [binary, {packet, 2}, {active, true}]), + ok = gen_tcp:close(Socket0), + {ok, Socket} = gen_tcp:connect("localhost", Port, + [binary, {packet, 2}, {active, true}]), + lists:seq(1, 10), + eTpf:stop(), + do_socket_tracer_recv(Socket). do_socket_tracer_recv(Socket) -> - receive - {tcp, Socket, Data} -> - Term = binary_to_term(Data), - true = is_tuple(Term), - do_socket_tracer_recv(Socket); - {tcp_closed, Socket} -> - ok - after 1000 -> - error(timeout) - end. + receive + {tcp, Socket, Data} -> + Term = binary_to_term(Data), + true = is_tuple(Term), + do_socket_tracer_recv(Socket); + {tcp_closed, Socket} -> + ok + after 1000 -> + error(timeout) + end. stop_while_trace_is_running(Config) -> - doc("Stop tracing while events are still coming in."), - Self = self(), - Pid = spawn_link(fun() -> Self ! {self(), continue}, lists:seq(1,10000000) end), - eTpf:trace([{scope, [Pid]}, lists], lg_file_tracer, - config(priv_dir, Config) ++ "/stop_while_trace_is_running.lz4"), - receive {Pid, continue} -> ok after 100 -> error(timeout) end, - eTpf:stop(), - do_ensure_decompress(config(priv_dir, Config) ++ "/stop_while_trace_is_running.lz4"). + doc("Stop tracing while events are still coming in."), + Self = self(), + Pid = spawn_link(fun() -> Self ! {self(), continue}, lists:seq(1, 10000000) end), + eTpf:trace([{scope, [Pid]}, lists], lg_file_tracer, + config(priv_dir, Config) ++ "/stop_while_trace_is_running.lz4"), + receive {Pid, continue} -> ok after 100 -> error(timeout) end, + eTpf:stop(), + do_ensure_decompress(config(priv_dir, Config) ++ "/stop_while_trace_is_running.lz4"). %% Internal. do_ensure_decompress(Prefix) -> - %% Ensure the files can be decompressed. - Sizes = [begin - Filename = Prefix ++ "." ++ integer_to_list(N), - {ok, File} = file:read_file(Filename), - _ = lz4f:decompress(File), - filelib:file_size(Filename) - end || N <- lists:seq(1, erlang:system_info(schedulers))], - %% We also need to make sure there is actual data in the files, - %% as lz4f:decompress will succeed when provided with no data. - true = 0 < lists:sum(Sizes), - ok. + %% Ensure the files can be decompressed. + Sizes = [begin + Filename = Prefix ++ "." ++ integer_to_list(N), + {ok, File} = file:read_file(Filename), + _ = lz4f:decompress(File), + filelib:file_size(Filename) + end || N <- lists:seq(1, erlang:system_info(schedulers))], + %% We also need to make sure there is actual data in the files, + %% as lz4f:decompress will succeed when provided with no data. + true = 0 < lists:sum(Sizes), + ok.