From 093903fd61089f7207453236c177d8ca9f3cfdad Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Mon, 17 May 2010 17:20:18 +0200 Subject: Teach eprof to use the new breakpoints --- lib/tools/src/eprof.erl | 696 +++++++++++++++++++++++------------------------- 1 file changed, 328 insertions(+), 368 deletions(-) (limited to 'lib/tools/src/eprof.erl') diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl index b4313d6888..e14574fd59 100644 --- a/lib/tools/src/eprof.erl +++ b/lib/tools/src/eprof.erl @@ -23,456 +23,416 @@ -module(eprof). -behaviour(gen_server). --export([start/0, stop/0, dump/0, total_analyse/0, - start_profiling/1, profile/2, profile/4, profile/1, - stop_profiling/0, analyse/0, log/1]). +-export([start/0, + stop/0, + dump/0, + start_profiling/1, start_profiling/2, + profile/1, profile/2, profile/3, profile/4, profile/5, + stop_profiling/0, + analyze/0, analyze/1, analyze/2, + log/1]). %% Internal exports -export([init/1, - call/4, handle_call/3, handle_cast/2, handle_info/2, terminate/2, code_change/3]). +-record(bpd, { + n = 0, + us = 0, + p = gb_trees:empty(), + mfa = [] + }). --include_lib("stdlib/include/qlc.hrl"). +-record(state, { + profiling = false, + pattern = {'_','_','_'}, + rootset = [], + reply = undefined, + bpd = #bpd{} + }). --import(lists, [flatten/1,reverse/1,keysort/2]). --record(state, {table = notable, - proc = noproc, - profiling = false, - pfunc = undefined, - pop = running, - ptime = 0, - overhead = 0, - rootset = []}). - -%%%%%%%%%%%%%% +%% -------------------------------------------------------------------- %% +%% +%% API +%% +%% -------------------------------------------------------------------- %% -start() -> gen_server:start({local, eprof}, eprof, [], []). -stop() -> gen_server:call(eprof, stop, infinity). +start() -> gen_server:start({local, ?MODULE}, ?MODULE, [], []). +stop() -> gen_server:call(?MODULE, stop, infinity). +profile(Fun) when is_function(Fun) -> + profile([], Fun); +profile(Rs) when is_list(Rs) -> + start_profiling(Rs). profile(Pids, Fun) -> - start(), - gen_server:call(eprof, {profile,Pids,erlang,apply,[Fun,[]]},infinity). + profile(Pids, Fun, {'_','_','_'}). + +profile(Pids, Fun, Pattern) -> + profile(Pids, Pattern, erlang, apply, [Fun,[]]). profile(Pids, M, F, A) -> + profile(Pids, {'_','_','_'}, M, F, A). + +profile(Pids, Pattern, M, F, A) -> start(), - gen_server:call(eprof, {profile,Pids,M,F,A},infinity). + gen_server:call(?MODULE, {profile,Pids,Pattern, M,F,A},infinity). dump() -> - gen_server:call(eprof, dump, infinity). + gen_server:call(?MODULE, dump, infinity). -analyse() -> - gen_server:call(eprof, analyse, infinity). +analyze() -> + analyze(procs). -log(File) -> - gen_server:call(eprof, {logfile, File}, infinity). +analyze(Type) when is_atom(Type) -> + analyze(Type, []); +analyze(Opts) when is_list(Opts) -> + analyze(procs, Opts). +analyze(Type, Opts) when is_list(Opts) -> + gen_server:call(?MODULE, {analyze, Type, Opts}, infinity). -total_analyse() -> - gen_server:call(eprof, total_analyse, infinity). +log(File) -> + gen_server:call(?MODULE, {logfile, File}, infinity). start_profiling(Rootset) -> + start_profiling(Rootset, {'_','_','_'}). +start_profiling(Rootset, Pattern) -> start(), - gen_server:call(eprof, {profile, Rootset}, infinity). + gen_server:call(?MODULE, {profile, Rootset, Pattern}, infinity). stop_profiling() -> - gen_server:call(eprof, stop_profiling, infinity). + gen_server:call(?MODULE, stop_profiling, infinity). -profile(Rs) -> - start_profiling(Rs). -%%%%%%%%%%%%%%%% +%% -------------------------------------------------------------------- %% +%% +%% init +%% +%% -------------------------------------------------------------------- %% -init(_) -> +init([]) -> process_flag(trap_exit, true), - process_flag(priority, max), - put(three_one, {3,1}), %To avoid building garbage. {ok, #state{}}. -subtr({X1,Y1,Z1}, {X1,Y1,Z2}) -> - Z1 - Z2; -subtr({X1,Y1,Z1}, {X2,Y2,Z2}) -> - (((X1-X2) * 1000000) + Y1 - Y2) * 1000000 + Z1 - Z2. +%% -------------------------------------------------------------------- %% +%% +%% handle_call +%% +%% -------------------------------------------------------------------- %% + +%% analyze + +sum_bp_total_n_us(Mfas) -> + lists:foldl(fun ({_, {Ci,Usi}}, {Co, Uso}) -> {Co + Ci, Uso + Usi} end, {0,0}, Mfas). + +print_bp_mfa(Mfas, {_Tn, Tus}, Opts) -> + print(["FUNCTION", "CALLS", " %", "TIME", "uS / CALLS"]), + print(["--------", "-----", "---", "----", "----------"]), + lists:foreach(fun + ({_, {Count, Time}}) when Count =:= 0; Time < 1 -> + ok; + ({Mfa, {Count, Time}}) -> + print([s(Mfa), s(Time), s(Count), s("~.2f", [100*(Time/Tus)]), s("~.2f", [Time/Count])]), + ok + end, filter_mfa(sort_mfa(Mfas, proplists:get_value(sort, Opts)), proplists:get_value(thresholds, Opts))), + ok. -update_call_statistics(Tab, Key, Time) -> - try ets:update_counter(Tab, Key, Time) of - NewTime when is_integer(NewTime) -> - ets:update_counter(Tab, Key, get(three_one)) - catch - error:badarg -> - ets:insert(Tab, {Key,Time,1}) - end. +handle_call({analyze, _, _}, _, #state{ bpd = #bpd{ p = {0,nil}, us = 0, n = 0} = Bpd } = S) when is_record(Bpd, bpd) -> + {reply, nothing_to_analyze, S}; +handle_call({analyze, procs, Opts}, _, #state{ bpd = #bpd{ p = Ps, us = Tus} = Bpd} = S) when is_record(Bpd, bpd) -> + lists:foreach(fun + ({Pid, Mfas}) -> + {Pn, Pus} = sum_bp_total_n_us(Mfas), + io:format("~n****** Process ~w -- ~s % of profiled time *** ~n", [Pid, s("~.2f", [100.0*(Pus/Tus)])]), + print_bp_mfa(Mfas, {Pn,Pus}, Opts), + ok + end, gb_trees:to_list(Ps)), + {reply, ok, S}; -update_other_statistics(Tab, Key, Time) -> - try - ets:update_counter(Tab, Key, Time) - catch - error:badarg -> - ets:insert(Tab, {Key,Time,0}) - end. +handle_call({analyze, total, Opts}, _, #state{ bpd = #bpd{ mfa = Mfas, n = Tn, us = Tus} = Bpd} = S) when is_record(Bpd, bpd) -> + print_bp_mfa(Mfas, {Tn, Tus}, Opts), + {reply, ok, S}; -do_messages({trace_ts,From,Op,Mfa,Time}, Tab, undefined,_PrevOp0,_PrevTime0) -> - PrevFunc = [From|Mfa], - receive - {trace_ts,_,_,_,_}=Ts -> do_messages(Ts, Tab, PrevFunc, Op, Time) - after 0 -> - {PrevFunc,Op,Time} - end; -do_messages({trace_ts,From,Op,Mfa,Time}, Tab, PrevFunc0, call, PrevTime0) -> - update_call_statistics(Tab, PrevFunc0, subtr(Time, PrevTime0)), - PrevFunc = case Op of - exit -> undefined; - out -> undefined; - _ -> [From|Mfa] - end, - receive - {trace_ts,_,_,_,_}=Ts -> do_messages(Ts, Tab, PrevFunc, Op, Time) - after 0 -> - {PrevFunc,Op,Time} - end; -do_messages({trace_ts,From,Op,Mfa,Time}, Tab, PrevFunc0, _PrevOp0, PrevTime0) -> - update_other_statistics(Tab, PrevFunc0, subtr(Time, PrevTime0)), - PrevFunc = case Op of - exit -> undefined; - out -> undefined; - _ -> [From|Mfa] - end, - receive - {trace_ts,_,_,_,_}=Ts -> do_messages(Ts, Tab, PrevFunc, Op, Time) - after 0 -> - {PrevFunc,Op,Time} - end. +handle_call({analyze, Type, _Opts}, _, S) -> + {reply, {error, {undefined, Type}}, S}; -%%%%%%%%%%%%%%%%%% +%% profile -handle_cast(_Req, S) -> {noreply, S}. +handle_call({profile, _Rootset, _Pattern, _M,_F,_A}, _From, #state{ profiling = true } = S)-> + {reply, {error, already_profiling}, S}; -terminate(_Reason,_S) -> - call_trace_for_all(false), - normal. +handle_call({profile, Rootset, Pattern, M,F,A}, From, S) -> -%%%%%%%%%%%%%%%%%% + set_pattern_trace(false, S#state.pattern), + set_process_trace(false, S#state.rootset), -handle_call({logfile, F}, _FromTag, Status) -> - case file:open(F, [write]) of - {ok, Fd} -> - case get(fd) of - undefined -> ok; - FdOld -> file:close(FdOld) - end, - put(fd, Fd), - {reply, ok, Status}; - {error, _} -> - {reply, error, Status} - end; - -handle_call({profile, Rootset}, {From, _Tag}, S) -> - link(From), - maybe_delete(S#state.table), - io:format("eprof: Starting profiling ..... ~n",[]), - ptrac(S#state.rootset, false, all()), - flush_receive(), - Tab = ets:new(eprof, [set, public]), - case ptrac(Rootset, true, all()) of - false -> - {reply, error, #state{}}; + Pid = setup_profiling(M,F,A), + case set_process_trace(true, [Pid|Rootset]) of true -> - uni_schedule(), - call_trace_for_all(true), - erase(replyto), - {reply, profiling, #state{table = Tab, - proc = From, - profiling = true, - rootset = Rootset}} + set_pattern_trace(true, Pattern), + execute_profiling(Pid), + {noreply, #state{ + profiling = true, + rootset = [Pid|Rootset], + reply = From, + pattern = Pattern + }}; + false -> + exit(Pid, kill), + {reply, error, #state{}} end; -handle_call(stop_profiling, _FromTag, S) when S#state.profiling -> - ptrac(S#state.rootset, false, all()), - call_trace_for_all(false), - multi_schedule(), - io:format("eprof: Stop profiling~n",[]), - ets:delete(S#state.table, nofunc), - {reply, profiling_stopped, S#state{profiling = false}}; +handle_call({profile, Rootset, Pattern}, From, S) -> -handle_call(stop_profiling, _FromTag, S) -> - {reply, profiling_already_stopped, S}; + set_pattern_trace(false, S#state.pattern), + set_process_trace(false, S#state.rootset), -handle_call({profile, Rootset, M, F, A}, FromTag, S) -> - io:format("eprof: Starting profiling..... ~n", []), - maybe_delete(S#state.table), - ptrac(S#state.rootset, false, all()), - flush_receive(), - put(replyto, FromTag), - Tab = ets:new(eprof, [set, public]), - P = spawn_link(eprof, call, [self(), M, F, A]), - case ptrac([P|Rootset], true, all()) of + case set_process_trace(true, Rootset) of true -> - uni_schedule(), - call_trace_for_all(true), - P ! {self(),go}, - {noreply, #state{table = Tab, - profiling = true, - rootset = [P|Rootset]}}; + T0 = now(), + set_pattern_trace(true, Pattern), + {reply, profiling, #state{ + profiling = true, + rootset = Rootset, + start_ts = T0, + reply = From, + pattern = Pattern + }}; false -> - exit(P, kill), - erase(replyto), {reply, error, #state{}} end; -handle_call(dump, _FromTag, S) -> - {reply, dump(S#state.table), S}; - -handle_call(analyse, _FromTag, S) -> - {reply, analyse(S), S}; +handle_call(stop_profiling, _From, #state{ profiling = false } = S) -> + {reply, profiling_already_stopped, S}; -handle_call(total_analyse, _FromTag, S) -> - {reply, total_analyse(S), S}; +handle_call(stop_profiling, _From, #state{ profiling = true } = S) -> -handle_call(stop, _FromTag, S) -> - multi_schedule(), - {stop, normal, stopped, S}. - -%%%%%%%%%%%%%%%%%%% - -handle_info({trace_ts,_From,_Op,_Func,_Time}=M, S0) when S0#state.profiling -> - Start = erlang:now(), - #state{table=Tab,pop=PrevOp0,ptime=PrevTime0,pfunc=PrevFunc0, - overhead=Overhead0} = S0, - {PrevFunc,PrevOp,PrevTime} = do_messages(M, Tab, PrevFunc0, PrevOp0, PrevTime0), - Overhead = Overhead0 + subtr(erlang:now(), Start), - S = S0#state{overhead=Overhead,pfunc=PrevFunc,pop=PrevOp,ptime=PrevTime}, - {noreply,S}; - -handle_info({trace_ts, From, _, _, _}, S) when not S#state.profiling -> - ptrac([From], false, all()), - {noreply, S}; + set_pattern_trace(pause, S#state.pattern), -handle_info({_P, {answer, A}}, S) -> - ptrac(S#state.rootset, false, all()), - io:format("eprof: Stop profiling~n",[]), - {From,_Tag} = get(replyto), - catch unlink(From), - ets:delete(S#state.table, nofunc), - gen_server:reply(erase(replyto), {ok, A}), - multi_schedule(), - {noreply, S#state{profiling = false, - rootset = []}}; - -handle_info({'EXIT', P, Reason}, - #state{profiling=true,proc=P,table=T,rootset=RootSet}) -> - maybe_delete(T), - ptrac(RootSet, false, all()), - multi_schedule(), - io:format("eprof: Profiling failed\n",[]), - case erase(replyto) of - undefined -> - {noreply, #state{}}; - FromTag -> - gen_server:reply(FromTag, {error, Reason}), - {noreply, #state{}} - end; + Bpd = collect_bpd(), -handle_info({'EXIT',_P,_Reason}, S) -> - {noreply, S}. + set_process_trace(false, S#state.rootset), + set_pattern_trace(false, S#state.pattern), -uni_schedule() -> - erlang:system_flag(multi_scheduling, block). + {reply, profiling_stopped, S#state{ + profiling = false, + rootset = [], + pattern = {'_','_','_'}, + bpd = Bpd + }}; -multi_schedule() -> - erlang:system_flag(multi_scheduling, unblock). +handle_call(stop, _FromTag, S) -> + {stop, normal, stopped, S}; -%%%%%%%%%%%%%%%%%% +handle_call(Command, _From, State)-> + io:format("handle_call: ~p~nstate: ~p~n", [Command,State]), + {reply, Command, State}. -call(Top, M, F, A) -> - receive - {Top,go} -> - Top ! {self(), {answer, apply(M,F,A)}} - end. +%% -------------------------------------------------------------------- %% +%% +%% handle_cast +%% +%% -------------------------------------------------------------------- %% -call_trace_for_all(Flag) -> - erlang:trace_pattern(on_load, Flag, [local]), - erlang:trace_pattern({'_','_','_'}, Flag, [local]). +handle_cast(_Msg, State) -> + {noreply, State}. -ptrac([P|T], How, Flags) when is_pid(P) -> - case dotrace(P, How, Flags) of - true -> - ptrac(T, How, Flags); - false when How -> - false; - false -> - ptrac(T, How, Flags) - end; +%% -------------------------------------------------------------------- %% +%% +%% handle_info +%% +%% -------------------------------------------------------------------- %% -ptrac([P|T], How, Flags) when is_atom(P) -> - case whereis(P) of - undefined when How -> - false; - undefined when not How -> - ptrac(T, How, Flags); - Pid -> - ptrac([Pid|T], How, Flags) - end; +handle_info({trace, _Pid, _Cmd, _Type}, S) -> + {noreply, S}; +handle_info({trace, _Parent, spawn, _Pid, _Mfa}, S) -> + {noreply, S}; +handle_info({'EXIT', _, normal}, S) -> + {noreply, S}; +handle_info({'EXIT', _, Reason}, #state{ reply = FromTag } = S) -> -ptrac([H|_],_How,_Flags) -> - io:format("** eprof bad process ~w~n",[H]), - false; + set_process_trace(false, S#state.rootset), + set_pattern_trace(false, S#state.pattern), -ptrac([],_,_) -> true. + gen_server:reply(FromTag, {error, Reason}), + {noreply, S#state{ + profiling = false, + rootset = [], + pattern = {'_','_','_'} + }}; -dotrace(P, How, What) -> - case (catch erlang:trace(P, How, What)) of - 1 -> - true; - _Other when not How -> - true; - _Other -> - io:format("** eprof: bad process: ~p,~p,~p~n", [P,How,What]), - false - end. +% check if Pid is spawned process? +handle_info({_Pid, {answer, Result}}, #state{ reply = {From,_} = FromTag} = S) -> -all() -> [call,arity,return_to,running,timestamp,set_on_spawn]. - -total_analyse(#state{table=notable}) -> - nothing_to_analyse; -total_analyse(S) -> - #state{table = T, overhead = Overhead} = S, - QH = qlc:q([{{From,Mfa},Time,Count} || - {[From|Mfa],Time,Count} <- ets:table(T)]), - Pcalls = reverse(keysort(2, replicas(qlc:eval(QH)))), - Time = collect_times(Pcalls), - format("FUNCTION~44s TIME ~n", ["CALLS"]), - printit(Pcalls, Time), - format("\nTotal time: ~.2f\n", [Time / 1000000]), - format("Measurement overhead: ~.2f\n", [Overhead / 1000000]). - -analyse(#state{table=notable}) -> - nothing_to_analyse; -analyse(S) -> - #state{table = T, overhead = Overhead} = S, - Pids = ordsets:from_list(flatten(ets:match(T, {['$1'|'_'],'_', '_'}))), - Times = sum(ets:match(T, {'_','$1', '_'})), - format("FUNCTION~44s TIME ~n", ["CALLS"]), - do_pids(Pids, T, 0, Times), - format("\nTotal time: ~.2f\n", [Times / 1000000]), - format("Measurement overhead: ~.2f\n", [Overhead / 1000000]). - -do_pids([Pid|Tail], T, AckTime, Total) -> - Pcalls = - reverse(keysort(2, to_tups(ets:match(T, {[Pid|'$1'], '$2','$3'})))), - Time = collect_times(Pcalls), - PercentTotal = 100 * (divide(Time, Total)), - format("~n****** Process ~w -- ~s % of profiled time *** ~n", - [Pid, fpf(PercentTotal)]), - printit(Pcalls, Time), - do_pids(Tail, T, AckTime + Time, Total); -do_pids([], _, _, _) -> - ok. + set_pattern_trace(pause, S#state.pattern), -printit([],_) -> ok; -printit([{{Mod,Fun,Arity}, Time, Calls} |Tail], ProcTime) -> - format("~s ~s ~s % ~n", [ff(Mod,Fun,Arity), fint(Calls), - fpf(100*(divide(Time,ProcTime)))]), - printit(Tail, ProcTime); -printit([{{_,{Mod,Fun,Arity}}, Time, Calls} |Tail], ProcTime) -> - format("~s ~s ~s % ~n", [ff(Mod,Fun,Arity), fint(Calls), - fpf(100*(divide(Time,ProcTime)))]), - printit(Tail, ProcTime); -printit([_|T], Time) -> - printit(T, Time). - -ff(Mod,Fun,Arity) -> - pad(flatten(io_lib:format("~w:~w/~w", [Mod,Fun, Arity])),45). - -pad(Str, Len) -> - Strlen = length(Str), - if - Strlen > Len -> strip_tail(Str, 45); - true -> lists:append(Str, mklist(Len-Strlen)) - end. + Bpd = collect_bpd(), -strip_tail([_|_], 0) ->[]; -strip_tail([H|T], I) -> [H|strip_tail(T, I-1)]; -strip_tail([],_I) -> []. + set_process_trace(false, S#state.rootset), + set_pattern_trace(false, S#state.pattern), -fpf(F) -> strip_tail(flatten(io_lib:format("~w", [round(F)])), 5). -fint(Int) -> pad(flatten(io_lib:format("~w",[Int])), 10). + catch unlink(From), + gen_server:reply(FromTag, {ok, Result}), + {noreply, S#state{ + profiling = false, + rootset = [], + pattern = {'_','_','_'}, + bpd = Bpd + }}; + +handle_info(Info, State) -> + io:format("handle_info: ~p~nstate: ~p~n", [Info,State]), + {noreply, State}. + +%% -------------------------------------------------------------------- %% +%% +%% termination +%% +%% -------------------------------------------------------------------- %% -mklist(0) -> []; -mklist(I) -> [$ |mklist(I-1)]. +terminate(_Reason, _State) -> + set_pattern_trace(false, {'_','_','_'}), + ok. -to_tups(L) -> lists:map(fun(List) -> erlang:list_to_tuple(List) end, L). +%% -------------------------------------------------------------------- %% +%% +%% code_change +%% +%% -------------------------------------------------------------------- %% -divide(X,Y) -> X / Y. +code_change(_OldVsn, State, _Extra) -> + {ok, State}. -collect_times([]) -> 0; -collect_times([Tup|Tail]) -> element(2, Tup) + collect_times(Tail). -dump(T) -> - L = ets:tab2list(T), - format(L). +%% -------------------------------------------------------------------- %% +%% +%% AUX Functions +%% +%% -------------------------------------------------------------------- %% -format([H|T]) -> - format("~p~n", [H]), format(T); -format([]) -> ok. +setup_profiling(M,F,A) -> + spawn_link(fun() -> sprint_profile(M,F,A) end). -format(F, A) -> - io:format(F,A), - case get(fd) of - undefined -> ok; - Fd -> io:format(Fd, F,A) +sprint_profile(M, F, A) -> + receive + {Pid, execute} -> + Pid ! {self(), {answer, erlang:apply(M,F,A)}} end. -maybe_delete(T) -> - catch ets:delete(T). +execute_profiling(Pid) -> + Pid ! {self(), execute}. -sum([[H]|T]) -> H + sum(T); -sum([]) -> 0. - -replicas(L) -> - replicas(L, []). +set_pattern_trace(Flag, Pattern) -> + erlang:system_flag(multi_scheduling, block), + erlang:trace_pattern(on_load, Flag, [call_time]), + erlang:trace_pattern(Pattern, Flag, [call_time]), + erlang:system_flag(multi_scheduling, unblock), + ok. -replicas([{{Pid, {Mod,Fun,Arity}}, Ack,Calls} |Tail], Result) -> - case search({Mod,Fun,Arity},Result) of - false -> - replicas(Tail, [{{Pid, {Mod,Fun,Arity}}, Ack,Calls} |Result]); - {Ack2, Calls2} -> - Result2 = del({Mod,Fun,Arity}, Result), - replicas(Tail, [{{Pid, {Mod,Fun,Arity}}, - Ack+Ack2,Calls+Calls2} |Result2]) - end; +set_process_trace(Flag, Pids) -> + % do we need procs for meta info? + % could be useful + set_process_trace(Flag, Pids, [call, set_on_spawn]). +set_process_trace(_, [], _) -> true; +set_process_trace(Flag, [Pid|Pids], Options) when is_pid(Pid) -> + try + erlang:trace(Pid, Flag, Options) + catch + _:_ -> + false + end, + set_process_trace(Flag, Pids, Options); +set_process_trace(Flag, [Name|Pids], Options) when is_atom(Name) -> + case whereis(Name) of + undefined -> + set_process_trace(Flag, Pids, Options); + Pid -> + set_process_trace(Flag, [Pid|Pids], Options) + end. -replicas([_|T], Ack) -> %% Whimpy - replicas(T, Ack); - -replicas([], Res) -> Res. - -search(Key, [{{_,Key}, Ack, Calls}|_]) -> - {Ack, Calls}; -search(Key, [_|T]) -> - search(Key, T); -search(_Key,[]) -> false. - -del(Key, [{{_,Key},_Ack,_Calls}|T]) -> - T; -del(Key, [H | Tail]) -> - [H|del(Key, Tail)]; -del(_Key,[]) -> []. - -flush_receive() -> - receive - {trace_ts, From, _, _, _} when is_pid(From) -> - ptrac([From], false, all()), - flush_receive(); - _ -> - flush_receive() - after 0 -> - ok +collect_bpd() -> + collect_bpd([M || M <- [element(1, Mi) || Mi <- code:all_loaded()], M =/= ?MODULE]). + +collect_bpd(Ms) when is_list(Ms) -> + collect_bpdf(collect_mfas(Ms) ++ erlang:system_info(snifs)). + +collect_mfas(Ms) -> + lists:foldl(fun + (M, Mfas) -> + Mfas ++ [{M, F, A} || {F, A} <- M:module_info(functions)] + end, [], Ms). + +collect_bpdf(Mfas) -> + collect_bpdf(Mfas, #bpd{}). +collect_bpdf([], Bpd) -> + Bpd; +collect_bpdf([Mfa|Mfas], #bpd{n = N, us = Us, p = Tree, mfa = Code } = Bpd) -> + case erlang:trace_info(Mfa, call_time) of + {call_time, []} -> + collect_bpdf(Mfas, Bpd); + {call_time, Data} when is_list(Data) -> + {CTn, CTus, CTree} = collect_bpdfp(Mfa, Tree, Data), + collect_bpdf(Mfas, Bpd#bpd{ + n = CTn + N, + us = CTus + Us, + p = CTree, + mfa = [{Mfa, {CTn, CTus}}|Code] + }); + {call_time, false} -> + collect_bpdf(Mfas, Bpd); + {call_time, _Other} -> + collect_bpdf(Mfas, Bpd) end. -code_change(_OldVsn, State, _Extra) -> - {ok,State}. +collect_bpdfp(Mfa, Tree, Data) -> + lists:foldl(fun + ({Pid, Ni, Si, Usi}, {PTno, PTuso, To}) -> + Time = Si * 1000000 + Usi, + Ti1 = case gb_trees:lookup(Pid, To) of + none -> + gb_trees:enter(Pid, [{Mfa, {Ni, Time}}], To); + {value, Pmfas} -> + gb_trees:enter(Pid, [{Mfa, {Ni, Time}}|Pmfas], To) + end, + {PTno + Ni, PTuso + Time, Ti1} + end, {0,0, Tree}, Data). + +%% manipulators + +sort_mfa(Bpfs, ascending) when is_list(Bpfs) -> + lists:sort(fun + ({_,{_,A}}, {_,{_,B}}) when A > B -> true; + (_, _) -> false + end, Bpfs); +sort_mfa(Bpfs, descending) when is_list(Bpfs) -> + lists:sort(fun + ({_,{_,A}}, {_,{_,B}}) when A < B -> true; + (_, _) -> false + end, Bpfs); +sort_mfa(Bpfs, _) when is_list(Bpfs) -> sort_mfa(Bpfs, ascending). + +filter_mfa(Bpfs, Ts) when is_list(Ts) -> + filter_mfa(Bpfs, [], proplists:get_value(calls, Ts, 0), proplists:get_value(time, Ts, 0)); +filter_mfa(Bpfs, _) -> Bpfs. +filter_mfa([], Out, _, _) -> lists:reverse(Out); +filter_mfa([{_, {C, T}}=Bpf|Bpfs], Out, Ct, Tt) when C >= Ct, T >= Tt -> filter_mfa(Bpfs, [Bpf|Out], Ct, Tt); +filter_mfa([_|Bpfs], Out, Ct, Tt) -> filter_mfa(Bpfs, Out, Ct, Tt). + + +s({M,F,A}) -> s("~w:~w/~w",[M,F,A]); +s(Term) -> s("~p", [Term]). +s(Format, Terms) -> lists:flatten(io_lib:format(Format, Terms)). + +print([_,_,_] = Strings) -> + print("~.44s ~14s ~14s~n", Strings); +print([_,_,_,_] = Strings) -> + print("~.44s ~14s ~14s ~7s ~n", Strings); +print(Strings) -> + print("~.44s ~14s ~14s ~7s [~7s]~n", Strings). +print(Format, Strings) -> + io:format(Format, Strings). -- cgit v1.2.3 From 1123a641f8a8c397aa90cac5ffb3c0ec53505735 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Thu, 20 May 2010 11:54:54 +0200 Subject: Add start timestamp to eprof profiling --- lib/tools/src/eprof.erl | 15 +++++++-------- 1 file changed, 7 insertions(+), 8 deletions(-) (limited to 'lib/tools/src/eprof.erl') diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl index e14574fd59..b70b020550 100644 --- a/lib/tools/src/eprof.erl +++ b/lib/tools/src/eprof.erl @@ -50,6 +50,7 @@ profiling = false, pattern = {'_','_','_'}, rootset = [], + start_ts = undefined, reply = undefined, bpd = #bpd{} }). @@ -137,7 +138,7 @@ print_bp_mfa(Mfas, {_Tn, Tus}, Opts) -> ({_, {Count, Time}}) when Count =:= 0; Time < 1 -> ok; ({Mfa, {Count, Time}}) -> - print([s(Mfa), s(Time), s(Count), s("~.2f", [100*(Time/Tus)]), s("~.2f", [Time/Count])]), + print([s(Mfa), s(Count), s("~.2f", [100*(Time/Tus)]), s(Time), s("~.2f", [Time/Count])]), ok end, filter_mfa(sort_mfa(Mfas, proplists:get_value(sort, Opts)), proplists:get_value(thresholds, Opts))), ok. @@ -175,10 +176,12 @@ handle_call({profile, Rootset, Pattern, M,F,A}, From, S) -> case set_process_trace(true, [Pid|Rootset]) of true -> set_pattern_trace(true, Pattern), + T0 = now(), execute_profiling(Pid), {noreply, #state{ profiling = true, rootset = [Pid|Rootset], + start_ts = T0, reply = From, pattern = Pattern }}; @@ -227,11 +230,7 @@ handle_call(stop_profiling, _From, #state{ profiling = true } = S) -> }}; handle_call(stop, _FromTag, S) -> - {stop, normal, stopped, S}; - -handle_call(Command, _From, State)-> - io:format("handle_call: ~p~nstate: ~p~n", [Command,State]), - {reply, Command, State}. + {stop, normal, stopped, S}. %% -------------------------------------------------------------------- %% %% @@ -316,9 +315,9 @@ code_change(_OldVsn, State, _Extra) -> %% -------------------------------------------------------------------- %% setup_profiling(M,F,A) -> - spawn_link(fun() -> sprint_profile(M,F,A) end). + spawn_link(fun() -> spin_profile(M,F,A) end). -sprint_profile(M, F, A) -> +spin_profile(M, F, A) -> receive {Pid, execute} -> Pid ! {self(), {answer, erlang:apply(M,F,A)}} -- cgit v1.2.3 From 9a33a27398d4479c01dfd229091f5972c585b271 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Thu, 27 May 2010 16:14:52 +0200 Subject: Add log functionality to eprof --- lib/tools/src/eprof.erl | 79 ++++++++++++++++++++++++++++++++----------------- 1 file changed, 52 insertions(+), 27 deletions(-) (limited to 'lib/tools/src/eprof.erl') diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl index b70b020550..ca04b28be8 100644 --- a/lib/tools/src/eprof.erl +++ b/lib/tools/src/eprof.erl @@ -50,6 +50,7 @@ profiling = false, pattern = {'_','_','_'}, rootset = [], + fd = undefined, start_ts = undefined, reply = undefined, bpd = #bpd{} @@ -131,32 +132,33 @@ init([]) -> sum_bp_total_n_us(Mfas) -> lists:foldl(fun ({_, {Ci,Usi}}, {Co, Uso}) -> {Co + Ci, Uso + Usi} end, {0,0}, Mfas). -print_bp_mfa(Mfas, {_Tn, Tus}, Opts) -> - print(["FUNCTION", "CALLS", " %", "TIME", "uS / CALLS"]), - print(["--------", "-----", "---", "----", "----------"]), +print_bp_mfa(Mfas, {_Tn, Tus}, Fd, Opts) -> + print(Fd, ["FUNCTION", "CALLS", " %", "TIME", "uS / CALLS"]), + print(Fd, ["--------", "-----", "---", "----", "----------"]), lists:foreach(fun ({_, {Count, Time}}) when Count =:= 0; Time < 1 -> ok; ({Mfa, {Count, Time}}) -> - print([s(Mfa), s(Count), s("~.2f", [100*(Time/Tus)]), s(Time), s("~.2f", [Time/Count])]), + print(Fd, [s(Mfa), s(Count), s("~.2f", [100*(Time/Tus)]), s(Time), s("~.2f", [Time/Count])]), ok end, filter_mfa(sort_mfa(Mfas, proplists:get_value(sort, Opts)), proplists:get_value(thresholds, Opts))), ok. handle_call({analyze, _, _}, _, #state{ bpd = #bpd{ p = {0,nil}, us = 0, n = 0} = Bpd } = S) when is_record(Bpd, bpd) -> {reply, nothing_to_analyze, S}; -handle_call({analyze, procs, Opts}, _, #state{ bpd = #bpd{ p = Ps, us = Tus} = Bpd} = S) when is_record(Bpd, bpd) -> + +handle_call({analyze, procs, Opts}, _, #state{ bpd = #bpd{ p = Ps, us = Tus} = Bpd, fd = Fd} = S) when is_record(Bpd, bpd) -> lists:foreach(fun ({Pid, Mfas}) -> {Pn, Pus} = sum_bp_total_n_us(Mfas), - io:format("~n****** Process ~w -- ~s % of profiled time *** ~n", [Pid, s("~.2f", [100.0*(Pus/Tus)])]), - print_bp_mfa(Mfas, {Pn,Pus}, Opts), + format(Fd, "~n****** Process ~w -- ~s % of profiled time *** ~n", [Pid, s("~.2f", [100.0*(Pus/Tus)])]), + print_bp_mfa(Mfas, {Pn,Pus}, Fd, Opts), ok end, gb_trees:to_list(Ps)), {reply, ok, S}; -handle_call({analyze, total, Opts}, _, #state{ bpd = #bpd{ mfa = Mfas, n = Tn, us = Tus} = Bpd} = S) when is_record(Bpd, bpd) -> - print_bp_mfa(Mfas, {Tn, Tus}, Opts), +handle_call({analyze, total, Opts}, _, #state{ bpd = #bpd{ mfa = Mfas, n = Tn, us = Tus} = Bpd, fd = Fd} = S) when is_record(Bpd, bpd) -> + print_bp_mfa(Mfas, {Tn, Tus}, Fd, Opts), {reply, ok, S}; handle_call({analyze, Type, _Opts}, _, S) -> @@ -167,7 +169,7 @@ handle_call({analyze, Type, _Opts}, _, S) -> handle_call({profile, _Rootset, _Pattern, _M,_F,_A}, _From, #state{ profiling = true } = S)-> {reply, {error, already_profiling}, S}; -handle_call({profile, Rootset, Pattern, M,F,A}, From, S) -> +handle_call({profile, Rootset, Pattern, M,F,A}, From, #state{fd = Fd } = S) -> set_pattern_trace(false, S#state.pattern), set_process_trace(false, S#state.rootset), @@ -183,14 +185,15 @@ handle_call({profile, Rootset, Pattern, M,F,A}, From, S) -> rootset = [Pid|Rootset], start_ts = T0, reply = From, + fd = Fd, pattern = Pattern }}; false -> exit(Pid, kill), - {reply, error, #state{}} + {reply, error, #state{ fd = Fd}} end; -handle_call({profile, Rootset, Pattern}, From, S) -> +handle_call({profile, Rootset, Pattern}, From, #state{ fd = Fd } = S) -> set_pattern_trace(false, S#state.pattern), set_process_trace(false, S#state.rootset), @@ -204,10 +207,11 @@ handle_call({profile, Rootset, Pattern}, From, S) -> rootset = Rootset, start_ts = T0, reply = From, + fd = Fd, pattern = Pattern }}; false -> - {reply, error, #state{}} + {reply, error, #state{ fd = Fd }} end; handle_call(stop_profiling, _From, #state{ profiling = false } = S) -> @@ -229,6 +233,19 @@ handle_call(stop_profiling, _From, #state{ profiling = true } = S) -> bpd = Bpd }}; +%% logfile +handle_call({logfile, File}, _From, #state{ fd = OldFd } = S) -> + case file:open(File, [write]) of + {ok, Fd} -> + case OldFd of + undefined -> ok; + OldFd -> file:close(OldFd) + end, + {reply, ok, S#state{ fd = Fd}}; + Error -> + {reply, Error, S} + end; + handle_call(stop, _FromTag, S) -> {stop, normal, stopped, S}. @@ -282,11 +299,7 @@ handle_info({_Pid, {answer, Result}}, #state{ reply = {From,_} = FromTag} = S) - rootset = [], pattern = {'_','_','_'}, bpd = Bpd - }}; - -handle_info(Info, State) -> - io:format("handle_info: ~p~nstate: ~p~n", [Info,State]), - {noreply, State}. + }}. %% -------------------------------------------------------------------- %% %% @@ -294,7 +307,11 @@ handle_info(Info, State) -> %% %% -------------------------------------------------------------------- %% -terminate(_Reason, _State) -> +terminate(_Reason, #state{ fd = undefined }) -> + set_pattern_trace(false, {'_','_','_'}), + ok; +terminate(_Reason, #state{ fd = Fd }) -> + file:close(Fd), set_pattern_trace(false, {'_','_','_'}), ok. @@ -427,11 +444,19 @@ s({M,F,A}) -> s("~w:~w/~w",[M,F,A]); s(Term) -> s("~p", [Term]). s(Format, Terms) -> lists:flatten(io_lib:format(Format, Terms)). -print([_,_,_] = Strings) -> - print("~.44s ~14s ~14s~n", Strings); -print([_,_,_,_] = Strings) -> - print("~.44s ~14s ~14s ~7s ~n", Strings); -print(Strings) -> - print("~.44s ~14s ~14s ~7s [~7s]~n", Strings). -print(Format, Strings) -> - io:format(Format, Strings). +print(Fd, [_,_,_] = Strings) -> + print(Fd, "~.44s ~14s ~14s~n", Strings); +print(Fd, [_,_,_,_] = Strings) -> + print(Fd, "~.44s ~14s ~14s ~7s ~n", Strings); +print(Fd, Strings) -> + print(Fd, "~.44s ~14s ~14s ~7s [~7s]~n", Strings). +print(Fd, Format, Strings) -> + format(Fd, Format, Strings). + +format(undefined, Format, Strings) -> + io:format(Format, Strings), + ok; +format(Fd, Format, Strings) -> + io:format(Fd, Format, Strings), + io:format(Format, Strings), + ok. -- cgit v1.2.3 From 671c8091fbd7b12bcaf38b04af728a68033c1b96 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Thu, 27 May 2010 16:28:11 +0200 Subject: Add dump functionality to eprof --- lib/tools/src/eprof.erl | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) (limited to 'lib/tools/src/eprof.erl') diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl index ca04b28be8..b3cedbc725 100644 --- a/lib/tools/src/eprof.erl +++ b/lib/tools/src/eprof.erl @@ -40,10 +40,10 @@ terminate/2, code_change/3]). -record(bpd, { - n = 0, - us = 0, - p = gb_trees:empty(), - mfa = [] + n = 0, % number of total calls + us = 0, % sum of uS for all calls + p = gb_trees:empty(), % tree of {Pid, {Mfa, {Count, Us}}} + mfa = [] % list of {Mfa, {Count, Us}} }). -record(state, { @@ -246,6 +246,9 @@ handle_call({logfile, File}, _From, #state{ fd = OldFd } = S) -> {reply, Error, S} end; +handle_call(dump, _From, #state{ bpd = Bpd } = S) when is_record(Bpd, bpd) -> + {reply, gb_trees:to_list(Bpd#bpd.p), S}; + handle_call(stop, _FromTag, S) -> {stop, normal, stopped, S}. @@ -439,6 +442,7 @@ filter_mfa([], Out, _, _) -> lists:reverse(Out); filter_mfa([{_, {C, T}}=Bpf|Bpfs], Out, Ct, Tt) when C >= Ct, T >= Tt -> filter_mfa(Bpfs, [Bpf|Out], Ct, Tt); filter_mfa([_|Bpfs], Out, Ct, Tt) -> filter_mfa(Bpfs, Out, Ct, Tt). +%% strings and format s({M,F,A}) -> s("~w:~w/~w",[M,F,A]); s(Term) -> s("~p", [Term]). -- cgit v1.2.3 From a65462258ce6a4ed0cb63a9fa6ee2cd686a5edfa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Wed, 2 Jun 2010 15:08:21 +0200 Subject: Teach eprof to align text output --- lib/tools/src/eprof.erl | 43 ++++++++++++++++++++++++++++++++++--------- 1 file changed, 34 insertions(+), 9 deletions(-) (limited to 'lib/tools/src/eprof.erl') diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl index b3cedbc725..6c38df8018 100644 --- a/lib/tools/src/eprof.erl +++ b/lib/tools/src/eprof.erl @@ -132,16 +132,37 @@ init([]) -> sum_bp_total_n_us(Mfas) -> lists:foldl(fun ({_, {Ci,Usi}}, {Co, Uso}) -> {Co + Ci, Uso + Usi} end, {0,0}, Mfas). +string_bp_mfa(Mfas, Tus) -> string_bp_mfa(Mfas, Tus, {0,0,0,0,0}, []). +string_bp_mfa([], _, Ws, Strings) -> {Ws, lists:reverse(Strings)}; +string_bp_mfa([{Mfa, {Count, Time}}|Mfas], Tus, {MfaW, CountW, PercW, TimeW, TpCW}, Strings) -> + Smfa = s(Mfa), + Scount = s(Count), + Stime = s(Time), + Sperc = s("~.2f", [100*(Time/Tus)]), + Stpc = s("~.2f", [Time/Count]), + + string_bp_mfa(Mfas, Tus, { + erlang:max(MfaW, length(Smfa)), + erlang:max(CountW,length(Scount)), + erlang:max(PercW, length(Sperc)), + erlang:max(TimeW, length(Stime)), + erlang:max(TpCW, length(Stpc)) + }, [[Smfa, Scount, Sperc, Stime, Stpc] | Strings]). + print_bp_mfa(Mfas, {_Tn, Tus}, Fd, Opts) -> - print(Fd, ["FUNCTION", "CALLS", " %", "TIME", "uS / CALLS"]), - print(Fd, ["--------", "-----", "---", "----", "----------"]), - lists:foreach(fun - ({_, {Count, Time}}) when Count =:= 0; Time < 1 -> - ok; - ({Mfa, {Count, Time}}) -> - print(Fd, [s(Mfa), s(Count), s("~.2f", [100*(Time/Tus)]), s(Time), s("~.2f", [Time/Count])]), - ok - end, filter_mfa(sort_mfa(Mfas, proplists:get_value(sort, Opts)), proplists:get_value(thresholds, Opts))), + Fmfas = filter_mfa(sort_mfa(Mfas, proplists:get_value(sort, Opts)), proplists:get_value(thresholds, Opts)), + {{MfaW, CountW, PercW, TimeW, TpCW}, Strs} = string_bp_mfa(Fmfas, Tus), + Ws = { + erlang:max(length("FUNCTION"), MfaW), + erlang:max(length("CALLS"), CountW), + erlang:max(length(" %"), PercW), + erlang:max(length("TIME"), TimeW), + erlang:max(length("uS / CALLS"), TpCW) + }, + print(Fd, Ws, ["FUNCTION", "CALLS", " %", "TIME", "uS / CALLS"]), + print(Fd, Ws, ["--------", "-----", "---", "----", "----------"]), + + lists:foreach(fun (String) -> print(Fd, Ws, String) end, Strs), ok. handle_call({analyze, _, _}, _, #state{ bpd = #bpd{ p = {0,nil}, us = 0, n = 0} = Bpd } = S) when is_record(Bpd, bpd) -> @@ -448,6 +469,7 @@ s({M,F,A}) -> s("~w:~w/~w",[M,F,A]); s(Term) -> s("~p", [Term]). s(Format, Terms) -> lists:flatten(io_lib:format(Format, Terms)). + print(Fd, [_,_,_] = Strings) -> print(Fd, "~.44s ~14s ~14s~n", Strings); print(Fd, [_,_,_,_] = Strings) -> @@ -457,6 +479,9 @@ print(Fd, Strings) -> print(Fd, Format, Strings) -> format(Fd, Format, Strings). + +format(Fd, {MfaW, CountW, PercW, TimeW, TpCW}, Strings) -> + format(Fd, s("~~.~ps ~~~ps ~~~ps ~~~ps [~~~ps]~~n", [MfaW, CountW, PercW, TimeW, TpCW]), Strings); format(undefined, Format, Strings) -> io:format(Format, Strings), ok; -- cgit v1.2.3 From 7727bce757f709e94ea39dae3cbcf09c370e6b12 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Thu, 3 Jun 2010 11:33:28 +0200 Subject: Rename sorting choices for eprof - Added {sort, mfa} option --- lib/tools/src/eprof.erl | 91 ++++++++++++++++++++++++++----------------------- 1 file changed, 49 insertions(+), 42 deletions(-) (limited to 'lib/tools/src/eprof.erl') diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl index 6c38df8018..2b71b16c82 100644 --- a/lib/tools/src/eprof.erl +++ b/lib/tools/src/eprof.erl @@ -129,42 +129,6 @@ init([]) -> %% analyze -sum_bp_total_n_us(Mfas) -> - lists:foldl(fun ({_, {Ci,Usi}}, {Co, Uso}) -> {Co + Ci, Uso + Usi} end, {0,0}, Mfas). - -string_bp_mfa(Mfas, Tus) -> string_bp_mfa(Mfas, Tus, {0,0,0,0,0}, []). -string_bp_mfa([], _, Ws, Strings) -> {Ws, lists:reverse(Strings)}; -string_bp_mfa([{Mfa, {Count, Time}}|Mfas], Tus, {MfaW, CountW, PercW, TimeW, TpCW}, Strings) -> - Smfa = s(Mfa), - Scount = s(Count), - Stime = s(Time), - Sperc = s("~.2f", [100*(Time/Tus)]), - Stpc = s("~.2f", [Time/Count]), - - string_bp_mfa(Mfas, Tus, { - erlang:max(MfaW, length(Smfa)), - erlang:max(CountW,length(Scount)), - erlang:max(PercW, length(Sperc)), - erlang:max(TimeW, length(Stime)), - erlang:max(TpCW, length(Stpc)) - }, [[Smfa, Scount, Sperc, Stime, Stpc] | Strings]). - -print_bp_mfa(Mfas, {_Tn, Tus}, Fd, Opts) -> - Fmfas = filter_mfa(sort_mfa(Mfas, proplists:get_value(sort, Opts)), proplists:get_value(thresholds, Opts)), - {{MfaW, CountW, PercW, TimeW, TpCW}, Strs} = string_bp_mfa(Fmfas, Tus), - Ws = { - erlang:max(length("FUNCTION"), MfaW), - erlang:max(length("CALLS"), CountW), - erlang:max(length(" %"), PercW), - erlang:max(length("TIME"), TimeW), - erlang:max(length("uS / CALLS"), TpCW) - }, - print(Fd, Ws, ["FUNCTION", "CALLS", " %", "TIME", "uS / CALLS"]), - print(Fd, Ws, ["--------", "-----", "---", "----", "----------"]), - - lists:foreach(fun (String) -> print(Fd, Ws, String) end, Strs), - ok. - handle_call({analyze, _, _}, _, #state{ bpd = #bpd{ p = {0,nil}, us = 0, n = 0} = Bpd } = S) when is_record(Bpd, bpd) -> {reply, nothing_to_analyze, S}; @@ -187,7 +151,7 @@ handle_call({analyze, Type, _Opts}, _, S) -> %% profile -handle_call({profile, _Rootset, _Pattern, _M,_F,_A}, _From, #state{ profiling = true } = S)-> +handle_call({profile, _Rootset, _Pattern, _M,_F,_A}, _From, #state{ profiling = true } = S) -> {reply, {error, already_profiling}, S}; handle_call({profile, Rootset, Pattern, M,F,A}, From, #state{fd = Fd } = S) -> @@ -214,6 +178,9 @@ handle_call({profile, Rootset, Pattern, M,F,A}, From, #state{fd = Fd } = S) -> {reply, error, #state{ fd = Fd}} end; +handle_call({profile, _Rootset, _Pattern}, _From, #state{ profiling = true } = S) -> + {reply, {error, already_profiling}, S}; + handle_call({profile, Rootset, Pattern}, From, #state{ fd = Fd } = S) -> set_pattern_trace(false, S#state.pattern), @@ -443,18 +410,22 @@ collect_bpdfp(Mfa, Tree, Data) -> end, {0,0, Tree}, Data). %% manipulators - -sort_mfa(Bpfs, ascending) when is_list(Bpfs) -> +sort_mfa(Bpfs, mfa) when is_list(Bpfs) -> lists:sort(fun - ({_,{_,A}}, {_,{_,B}}) when A > B -> true; + ({A,_}, {B,_}) when A < B -> true; (_, _) -> false end, Bpfs); -sort_mfa(Bpfs, descending) when is_list(Bpfs) -> +sort_mfa(Bpfs, time) when is_list(Bpfs) -> + lists:sort(fun + ({_,{A,_}}, {_,{B,_}}) when A < B -> true; + (_, _) -> false + end, Bpfs); +sort_mfa(Bpfs, calls) when is_list(Bpfs) -> lists:sort(fun ({_,{_,A}}, {_,{_,B}}) when A < B -> true; (_, _) -> false end, Bpfs); -sort_mfa(Bpfs, _) when is_list(Bpfs) -> sort_mfa(Bpfs, ascending). +sort_mfa(Bpfs, _) when is_list(Bpfs) -> sort_mfa(Bpfs, calls). filter_mfa(Bpfs, Ts) when is_list(Ts) -> filter_mfa(Bpfs, [], proplists:get_value(calls, Ts, 0), proplists:get_value(time, Ts, 0)); @@ -463,8 +434,44 @@ filter_mfa([], Out, _, _) -> lists:reverse(Out); filter_mfa([{_, {C, T}}=Bpf|Bpfs], Out, Ct, Tt) when C >= Ct, T >= Tt -> filter_mfa(Bpfs, [Bpf|Out], Ct, Tt); filter_mfa([_|Bpfs], Out, Ct, Tt) -> filter_mfa(Bpfs, Out, Ct, Tt). +sum_bp_total_n_us(Mfas) -> + lists:foldl(fun ({_, {Ci,Usi}}, {Co, Uso}) -> {Co + Ci, Uso + Usi} end, {0,0}, Mfas). + %% strings and format +string_bp_mfa(Mfas, Tus) -> string_bp_mfa(Mfas, Tus, {0,0,0,0,0}, []). +string_bp_mfa([], _, Ws, Strings) -> {Ws, lists:reverse(Strings)}; +string_bp_mfa([{Mfa, {Count, Time}}|Mfas], Tus, {MfaW, CountW, PercW, TimeW, TpCW}, Strings) -> + Smfa = s(Mfa), + Scount = s(Count), + Stime = s(Time), + Sperc = s("~.2f", [100*(Time/Tus)]), + Stpc = s("~.2f", [Time/Count]), + + string_bp_mfa(Mfas, Tus, { + erlang:max(MfaW, length(Smfa)), + erlang:max(CountW,length(Scount)), + erlang:max(PercW, length(Sperc)), + erlang:max(TimeW, length(Stime)), + erlang:max(TpCW, length(Stpc)) + }, [[Smfa, Scount, Sperc, Stime, Stpc] | Strings]). + +print_bp_mfa(Mfas, {_Tn, Tus}, Fd, Opts) -> + Fmfas = filter_mfa(sort_mfa(Mfas, proplists:get_value(sort, Opts)), proplists:get_value(filter, Opts)), + {{MfaW, CountW, PercW, TimeW, TpCW}, Strs} = string_bp_mfa(Fmfas, Tus), + Ws = { + erlang:max(length("FUNCTION"), MfaW), + erlang:max(length("CALLS"), CountW), + erlang:max(length(" %"), PercW), + erlang:max(length("TIME"), TimeW), + erlang:max(length("uS / CALLS"), TpCW) + }, + print(Fd, Ws, ["FUNCTION", "CALLS", " %", "TIME", "uS / CALLS"]), + print(Fd, Ws, ["--------", "-----", "---", "----", "----------"]), + + lists:foreach(fun (String) -> print(Fd, Ws, String) end, Strs), + ok. + s({M,F,A}) -> s("~w:~w/~w",[M,F,A]); s(Term) -> s("~p", [Term]). s(Format, Terms) -> lists:flatten(io_lib:format(Format, Terms)). -- cgit v1.2.3 From 3f2c888e08636c1f090e87fd009ff2416b8a978b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Mon, 7 Jun 2010 18:44:47 +0200 Subject: Switch pattern API for eprof profile with mfa --- lib/tools/src/eprof.erl | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) (limited to 'lib/tools/src/eprof.erl') diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl index 2b71b16c82..6a0bd9ff9c 100644 --- a/lib/tools/src/eprof.erl +++ b/lib/tools/src/eprof.erl @@ -76,14 +76,14 @@ profile(Pids, Fun) -> profile(Pids, Fun, {'_','_','_'}). profile(Pids, Fun, Pattern) -> - profile(Pids, Pattern, erlang, apply, [Fun,[]]). + profile(Pids, erlang, apply, [Fun,[]], Pattern). profile(Pids, M, F, A) -> - profile(Pids, {'_','_','_'}, M, F, A). + profile(Pids, M, F, A, {'_','_','_'}). -profile(Pids, Pattern, M, F, A) -> +profile(Pids, M, F, A, Pattern) -> start(), - gen_server:call(?MODULE, {profile,Pids,Pattern, M,F,A},infinity). + gen_server:call(?MODULE, {profile,Pids,Pattern,M,F,A},infinity). dump() -> gen_server:call(?MODULE, dump, infinity). -- cgit v1.2.3 From 7b2c17955337b6c171e43c4eddb44508a8667bb8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Wed, 9 Jun 2010 16:36:56 +0200 Subject: Dialyzer cleanup for eprof --- lib/tools/src/eprof.erl | 22 ++++++---------------- 1 file changed, 6 insertions(+), 16 deletions(-) (limited to 'lib/tools/src/eprof.erl') diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl index 6a0bd9ff9c..bb082a4c66 100644 --- a/lib/tools/src/eprof.erl +++ b/lib/tools/src/eprof.erl @@ -348,12 +348,12 @@ set_process_trace(Flag, Pids) -> set_process_trace(_, [], _) -> true; set_process_trace(Flag, [Pid|Pids], Options) when is_pid(Pid) -> try - erlang:trace(Pid, Flag, Options) + erlang:trace(Pid, Flag, Options), + set_process_trace(Flag, Pids, Options) catch _:_ -> false - end, - set_process_trace(Flag, Pids, Options); + end; set_process_trace(Flag, [Name|Pids], Options) when is_atom(Name) -> case whereis(Name) of undefined -> @@ -466,10 +466,10 @@ print_bp_mfa(Mfas, {_Tn, Tus}, Fd, Opts) -> erlang:max(length("TIME"), TimeW), erlang:max(length("uS / CALLS"), TpCW) }, - print(Fd, Ws, ["FUNCTION", "CALLS", " %", "TIME", "uS / CALLS"]), - print(Fd, Ws, ["--------", "-----", "---", "----", "----------"]), + format(Fd, Ws, ["FUNCTION", "CALLS", " %", "TIME", "uS / CALLS"]), + format(Fd, Ws, ["--------", "-----", "---", "----", "----------"]), - lists:foreach(fun (String) -> print(Fd, Ws, String) end, Strs), + lists:foreach(fun (String) -> format(Fd, Ws, String) end, Strs), ok. s({M,F,A}) -> s("~w:~w/~w",[M,F,A]); @@ -477,16 +477,6 @@ s(Term) -> s("~p", [Term]). s(Format, Terms) -> lists:flatten(io_lib:format(Format, Terms)). -print(Fd, [_,_,_] = Strings) -> - print(Fd, "~.44s ~14s ~14s~n", Strings); -print(Fd, [_,_,_,_] = Strings) -> - print(Fd, "~.44s ~14s ~14s ~7s ~n", Strings); -print(Fd, Strings) -> - print(Fd, "~.44s ~14s ~14s ~7s [~7s]~n", Strings). -print(Fd, Format, Strings) -> - format(Fd, Format, Strings). - - format(Fd, {MfaW, CountW, PercW, TimeW, TpCW}, Strings) -> format(Fd, s("~~.~ps ~~~ps ~~~ps ~~~ps [~~~ps]~~n", [MfaW, CountW, PercW, TimeW, TpCW]), Strings); format(undefined, Format, Strings) -> -- cgit v1.2.3 From 913c7f82cf3f2594d2f0731fd73b79cd82502ff6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Wed, 9 Jun 2010 19:42:42 +0200 Subject: Fix eprof to handle error cases --- lib/tools/src/eprof.erl | 8 +++----- 1 file changed, 3 insertions(+), 5 deletions(-) (limited to 'lib/tools/src/eprof.erl') diff --git a/lib/tools/src/eprof.erl b/lib/tools/src/eprof.erl index bb082a4c66..c25eb4479c 100644 --- a/lib/tools/src/eprof.erl +++ b/lib/tools/src/eprof.erl @@ -174,7 +174,7 @@ handle_call({profile, Rootset, Pattern, M,F,A}, From, #state{fd = Fd } = S) -> pattern = Pattern }}; false -> - exit(Pid, kill), + exit(Pid, eprof_kill), {reply, error, #state{ fd = Fd}} end; @@ -255,12 +255,10 @@ handle_cast(_Msg, State) -> %% %% -------------------------------------------------------------------- %% -handle_info({trace, _Pid, _Cmd, _Type}, S) -> - {noreply, S}; -handle_info({trace, _Parent, spawn, _Pid, _Mfa}, S) -> - {noreply, S}; handle_info({'EXIT', _, normal}, S) -> {noreply, S}; +handle_info({'EXIT', _, eprof_kill}, S) -> + {noreply, S}; handle_info({'EXIT', _, Reason}, #state{ reply = FromTag } = S) -> set_process_trace(false, S#state.rootset), -- cgit v1.2.3