diff options
Diffstat (limited to 'lib/tools/test/fprof_SUITE.erl')
-rw-r--r-- | lib/tools/test/fprof_SUITE.erl | 1493 |
1 files changed, 740 insertions, 753 deletions
diff --git a/lib/tools/test/fprof_SUITE.erl b/lib/tools/test/fprof_SUITE.erl index e8f179c630..affb45b7a6 100644 --- a/lib/tools/test/fprof_SUITE.erl +++ b/lib/tools/test/fprof_SUITE.erl @@ -1,7 +1,7 @@ %% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 2001-2012. All Rights Reserved. +%% Copyright Ericsson AB 2001-2016. All Rights Reserved. %% %% Licensed under the Apache License, Version 2.0 (the "License"); %% you may not use this file except in compliance with the License. @@ -19,28 +19,23 @@ %% -module(fprof_SUITE). --include_lib("test_server/include/test_server.hrl"). +-include_lib("common_test/include/ct.hrl"). %% Test server framework exports --export([all/0, suite/0,groups/0,init_per_suite/1, end_per_suite/1, - init_per_group/2,end_per_group/2, not_run/1]). +-export([all/0, suite/0, not_run/1]). %% Test suites -export([stack_seq/1, tail_seq/1, create_file_slow/1, spawn_simple/1, - imm_tail_seq/1, imm_create_file_slow/1, imm_compile/1, - cpu_create_file_slow/1]). + imm_tail_seq/1, imm_create_file_slow/1, imm_compile/1, + cpu_create_file_slow/1]). %% Other exports -export([create_file_slow/2]). - %% Debug exports -export([parse/1, verify/2]). -export([spawn_simple_test/3]). - --define(line_trace,true). - %-define(debug,true). -ifdef(debug). -define(dbg(Str,Args), io:format(Str,Args)). @@ -49,553 +44,495 @@ -endif. - %%%--------------------------------------------------------------------- %%% Test suites %%%--------------------------------------------------------------------- - -suite() -> [{ct_hooks,[ts_install_cth]}]. +suite() -> + [{ct_hooks,[ts_install_cth]}, + {timetrap,{seconds,60}}]. all() -> case test_server:is_native(fprof_SUITE) of - true -> [not_run]; - false -> - [stack_seq, tail_seq, create_file_slow, spawn_simple, - imm_tail_seq, imm_create_file_slow, imm_compile, - cpu_create_file_slow] + true -> [not_run]; + false -> + [stack_seq, tail_seq, create_file_slow, spawn_simple, + imm_tail_seq, imm_create_file_slow, imm_compile, + cpu_create_file_slow] end. -groups() -> - []. - -init_per_suite(Config) -> - Config. - -end_per_suite(_Config) -> - ok. - -init_per_group(_GroupName, Config) -> - Config. - -end_per_group(_GroupName, Config) -> - Config. - not_run(Config) when is_list(Config) -> {skipped, "Native code"}. %%%--------------------------------------------------------------------- -stack_seq(doc) -> - ["Tests a stack recursive variant of lists:seq/3"]; -stack_seq(suite) -> - []; +%% Tests a stack recursive variant of lists:seq/3 stack_seq(Config) when is_list(Config) -> - ?line Timetrap = ?t:timetrap(?t:seconds(20)), - ?line PrivDir = ?config(priv_dir, Config), - ?line TraceFile = - filename:join(PrivDir, ?MODULE_STRING"_stack_seq.trace"), - ?line AnalysisFile = - filename:join(PrivDir, ?MODULE_STRING"_stack_seq.analysis"), - ?line Start = 1, - ?line Stop = 1000, - ?line Succ = fun (X) -> X + 1 end, - ?line ok = fprof:stop(kill), + PrivDir = proplists:get_value(priv_dir, Config), + TraceFile = filename:join(PrivDir, + ?MODULE_STRING"_stack_seq.trace"), + AnalysisFile = filename:join(PrivDir, + ?MODULE_STRING"_stack_seq.analysis"), + Start = 1, + Stop = 1000, + Succ = fun (X) -> X + 1 end, + ok = fprof:stop(kill), %% - ?line TS0 = erlang:now(), - ?line R0 = fprof:apply(fun seq/3, [Start, Stop, Succ], [{file, TraceFile}]), - ?line TS1 = erlang:now(), - ?line R = seq(Start, Stop, Succ), - ?line TS2 = erlang:now(), - ?line ok = fprof:profile(file, TraceFile), - ?line ok = fprof:analyse(), - ?line ok = fprof:analyse(dest, AnalysisFile), - ?line ok = fprof:stop(), - ?line R = R0, + TS0 = erlang:monotonic_time(), + R0 = fprof:apply(fun seq/3, [Start, Stop, Succ], [{file, TraceFile}]), + TS1 = erlang:monotonic_time(), + R = seq(Start, Stop, Succ), + TS2 = erlang:monotonic_time(), + ok = fprof:profile(file, TraceFile), + ok = fprof:analyse(), + ok = fprof:analyse(dest, AnalysisFile), + ok = fprof:stop(), + R = R0, %% - ?line {ok, [T, P]} = parse(AnalysisFile), - ?line io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), - ?line ok = (catch verify(T, P)), - ?line Proc = pid_to_list(self()), - ?line case P of - [{analysis_options, _}, - [{totals, _, Acc, _}], - [{Proc, _, undefined, _} | _]] -> - ok - end, + {ok, [T, P]} = parse(AnalysisFile), + io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), + ok = (catch verify(T, P)), + Proc = pid_to_list(self()), + case P of + [{analysis_options, _}, + [{totals, _, Acc, _}], + [{Proc, _, undefined, _} | _]] -> + ok + end, %% - ?line check_own_and_acc(TraceFile,AnalysisFile), + check_own_and_acc(TraceFile,AnalysisFile), %% - ?line ets:delete(T), - ?line file:delete(TraceFile), - ?line file:delete(AnalysisFile), - ?line ?t:timetrap_cancel(Timetrap), - ?line Acc1 = ts_sub(TS1, TS0), - ?line Acc2 = ts_sub(TS2, TS1), - ?line io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc1, Acc2]), - {comment, io_lib:format("~p times slower", [Acc1/Acc2])}. + ets:delete(T), + file:delete(TraceFile), + file:delete(AnalysisFile), + Acc1 = TS1 - TS0, + Acc2 = TS2 - TS1, + io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc1, Acc2]), + {comment, io_lib:format("~p times slower", [divide(Acc1,Acc2)])}. %%%--------------------------------------------------------------------- -tail_seq(doc) -> - ["Tests a tail recursive variant of lists:seq/3"]; -tail_seq(suite) -> - []; +%% Tests a tail recursive variant of lists:seq/3 tail_seq(Config) when is_list(Config) -> - ?line Timetrap = ?t:timetrap(?t:seconds(10)), - ?line PrivDir = ?config(priv_dir, Config), - ?line TraceFile = - filename:join(PrivDir, ?MODULE_STRING"_tail_seq.trace"), - ?line AnalysisFile = - filename:join(PrivDir, ?MODULE_STRING"_tail_seq.analysis"), - ?line Start = 1, - ?line Stop = 1000, - ?line Succ = fun (X) -> X + 1 end, - ?line ok = fprof:stop(kill), + PrivDir = proplists:get_value(priv_dir, Config), + TraceFile = filename:join(PrivDir, + ?MODULE_STRING"_tail_seq.trace"), + AnalysisFile = filename:join(PrivDir, + ?MODULE_STRING"_tail_seq.analysis"), + Start = 1, + Stop = 1000, + Succ = fun (X) -> X + 1 end, + ok = fprof:stop(kill), %% - ?line TS0 = erlang:now(), - ?line R = seq_r(Start, Stop, Succ), - ?line TS1 = erlang:now(), + TS0 = erlang:monotonic_time(), + R = seq_r(Start, Stop, Succ), + TS1 = erlang:monotonic_time(), %% - ?line R1 = fprof:apply(fun seq_r/3, [Start, Stop, Succ], - [{file, TraceFile}]), - ?line TS2 = erlang:now(), - ?line ok = fprof:profile([{file,TraceFile}]), - ?line ok = fprof:analyse(), - ?line ok = fprof:analyse(dest, AnalysisFile), - ?line ok = fprof:stop(), - ?line R = R1, + R1 = fprof:apply(fun seq_r/3, [Start, Stop, Succ], + [{file, TraceFile}]), + TS2 = erlang:monotonic_time(), + ok = fprof:profile([{file,TraceFile}]), + ok = fprof:analyse(), + ok = fprof:analyse(dest, AnalysisFile), + ok = fprof:stop(), + R = R1, %% - ?line {ok, [T, P]} = parse(AnalysisFile), - ?line io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), - ?line ok = verify(T, P), - ?line Proc = pid_to_list(self()), - ?line case P of - [{analysis_options, _}, - [{totals, _, Acc, _}], - [{Proc, _, undefined, _} | _]] -> - ok - end, + {ok, [T, P]} = parse(AnalysisFile), + io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), + ok = verify(T, P), + Proc = pid_to_list(self()), + case P of + [{analysis_options, _}, + [{totals, _, Acc, _}], + [{Proc, _, undefined, _} | _]] -> + ok + end, %% - ?line check_own_and_acc(TraceFile,AnalysisFile), + check_own_and_acc(TraceFile,AnalysisFile), %% - ?line ets:delete(T), - ?line file:delete(TraceFile), - ?line file:delete(AnalysisFile), - ?line ?t:timetrap_cancel(Timetrap), - ?line Acc1 = ts_sub(TS1, TS0), - ?line Acc2 = ts_sub(TS2, TS1), - ?line io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc2, Acc1]), - {comment, io_lib:format("~p times slower", [Acc2/Acc1])}. + ets:delete(T), + file:delete(TraceFile), + file:delete(AnalysisFile), + Acc1 = TS1 - TS0, + Acc2 = TS2 - TS1, + io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc2, Acc1]), + {comment, io_lib:format("~p times slower", [divide(Acc2,Acc1)])}. %%%--------------------------------------------------------------------- %% Tests the create_file_slow benchmark. create_file_slow(Config) -> case test_server:is_native(lists) orelse - test_server:is_native(file) of - true -> - {skip,"Native libs -- tracing does not work"}; - false -> - do_create_file_slow(Config) + test_server:is_native(file) of + true -> + {skip,"Native libs -- tracing does not work"}; + false -> + do_create_file_slow(Config) end. do_create_file_slow(Config) -> - ?line Timetrap = ?t:timetrap(?t:seconds(40)), - ?line PrivDir = ?config(priv_dir, Config), - ?line TraceFile = - filename:join(PrivDir, ?MODULE_STRING"_create_file_slow.trace"), - ?line AnalysisFile = - filename:join(PrivDir, ?MODULE_STRING"_create_file_slow.analysis"), - ?line DataFile = - filename:join(PrivDir, ?MODULE_STRING"_create_file_slow.data"), - ?line ok = fprof:stop(kill), + PrivDir = proplists:get_value(priv_dir, Config), + TraceFile = filename:join(PrivDir, + ?MODULE_STRING"_create_file_slow.trace"), + AnalysisFile = filename:join(PrivDir, + ?MODULE_STRING"_create_file_slow.analysis"), + DataFile = filename:join(PrivDir, + ?MODULE_STRING"_create_file_slow.data"), + ok = fprof:stop(kill), %% - ?line TS0 = erlang:now(), - ?line ok = create_file_slow(DataFile, 1024), - ?line TS1 = erlang:now(), + TS0 = erlang:monotonic_time(), + ok = create_file_slow(DataFile, 1024), + TS1 = erlang:monotonic_time(), %% - ?line ok = file:delete(DataFile), - ?line TS2 = erlang:now(), - ?line ok = fprof:apply(?MODULE, create_file_slow, [DataFile, 1024], - [{file, TraceFile}]), - ?line TS3 = erlang:now(), - ?line ok = fprof:profile(file, TraceFile), - ?line ok = fprof:analyse(), - ?line ok = fprof:analyse(dest, AnalysisFile), - ?line ok = fprof:stop(), + ok = file:delete(DataFile), + TS2 = erlang:monotonic_time(), + ok = fprof:apply(?MODULE, create_file_slow, [DataFile, 1024], + [{file, TraceFile}]), + TS3 = erlang:monotonic_time(), + ok = fprof:profile(file, TraceFile), + ok = fprof:analyse(), + ok = fprof:analyse(dest, AnalysisFile), + ok = fprof:stop(), %% - ?line {ok, [T, P]} = parse(AnalysisFile), - ?line io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), - ?line ok = verify(T, P), - ?line Proc = pid_to_list(self()), - ?line case P of - [{analysis_options, _}, - [{totals, _, Acc, _}], - [{Proc, _, undefined, _} | _]] -> - ok - end, + {ok, [T, P]} = parse(AnalysisFile), + io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), + ok = verify(T, P), + Proc = pid_to_list(self()), + case P of + [{analysis_options, _}, + [{totals, _, Acc, _}], + [{Proc, _, undefined, _} | _]] -> + ok + end, %% - ?line check_own_and_acc(TraceFile,AnalysisFile), + check_own_and_acc(TraceFile,AnalysisFile), %% - ?line ets:delete(T), - ?line file:delete(DataFile), - ?line file:delete(TraceFile), - ?line file:delete(AnalysisFile), - ?line ?t:timetrap_cancel(Timetrap), - ?line Acc1 = ts_sub(TS1, TS0), - ?line Acc3 = ts_sub(TS3, TS2), - ?line io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc3, Acc1]), - {comment, io_lib:format("~p times slower", [Acc3/Acc1])}. + ets:delete(T), + file:delete(DataFile), + file:delete(TraceFile), + file:delete(AnalysisFile), + Acc1 = TS1 - TS0, + Acc3 = TS3 - TS2, + io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc3, Acc1]), + {comment, io_lib:format("~p times slower", [divide(Acc3,Acc1)])}. %%%--------------------------------------------------------------------- -spawn_simple(doc) -> - ["Tests process spawn"]; -spawn_simple(suite) -> - []; +%% Tests process spawn spawn_simple(Config) when is_list(Config) -> - ?line Timetrap = ?t:timetrap(?t:seconds(30)), - ?line PrivDir = ?config(priv_dir, Config), - ?line TraceFile = - filename:join(PrivDir, ?MODULE_STRING"_spawn_simple.trace"), - ?line AnalysisFile = - filename:join(PrivDir, ?MODULE_STRING"_spawn_simple.analysis"), - ?line Start = 1, - ?line Stop = 1000, - ?line Succ = fun (X) -> X + 1 end, - ?line ok = fprof:stop(kill), + PrivDir = proplists:get_value(priv_dir, Config), + TraceFile = filename:join(PrivDir, + ?MODULE_STRING"_spawn_simple.trace"), + AnalysisFile = filename:join(PrivDir, + ?MODULE_STRING"_spawn_simple.analysis"), + Start = 1, + Stop = 1000, + Succ = fun (X) -> X + 1 end, + ok = fprof:stop(kill), %% - ?line TS0 = erlang:now(), - ?line {{_, R1}, {_, R2}} = spawn_simple_test(Start, Stop, Succ), - ?line TS1 = erlang:now(), + TS0 = erlang:monotonic_time(), + {{_, R1}, {_, R2}} = spawn_simple_test(Start, Stop, Succ), + TS1 = erlang:monotonic_time(), %% - ?line ok = fprof:trace(start, TraceFile), - ?line {{P1, R3}, {P2, R4}} = spawn_simple_test(Start, Stop, Succ), - ?line ok = fprof:trace(stop), - ?line TS2 = erlang:now(), - ?line ok = fprof:profile(file, TraceFile), - ?line ok = fprof:analyse(), - ?line ok = fprof:analyse(dest, AnalysisFile), - ?line ok = fprof:stop(), - ?line R1 = R3, - ?line R2 = R4, + ok = fprof:trace(start, TraceFile), + {{P1, R3}, {P2, R4}} = spawn_simple_test(Start, Stop, Succ), + ok = fprof:trace(stop), + TS2 = erlang:monotonic_time(), + ok = fprof:profile(file, TraceFile), + ok = fprof:analyse(), + ok = fprof:analyse(dest, AnalysisFile), + ok = fprof:stop(), + R1 = R3, + R2 = R4, %% - ?line {ok, [T, P]} = parse(AnalysisFile), - ?line io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), - ?line ok = verify(T, P), - ?line Proc1 = pid_to_list(P1), - ?line Proc2 = pid_to_list(P2), - ?line Proc0 = pid_to_list(self()), - ?line io:format("~p~n ~p ~p ~p~n", [P, Proc0, Proc1, Proc2]), - ?line [{analysis_options, _}, [{totals, _, Acc, _}] | Procs] = P, - ?line [[{Proc0, _, undefined, _} | _]] = - lists:filter(fun ([Pt | _]) when element(1, Pt) == Proc0 -> true; - (_) -> false - end, Procs), - ?line [[{Proc1, _, undefined, _}, - {spawned_by, Proc0}, - {spawned_as, {erlang, apply, ["#Fun"++_, []]}}, - {initial_calls, [{erlang, apply, 2}, - {?MODULE, '-spawn_simple_test/3-fun-0-', 4}]} - | _]] = - lists:filter(fun ([Pt | _]) when element(1, Pt) == Proc1 -> true; - (_) -> false - end, Procs), - ?line [[{Proc2, _, undefined, _}, - {spawned_by, Proc0}, - {spawned_as, {erlang, apply, ["#Fun"++_, []]}}, - {initial_calls, [{erlang, apply, 2}, - {?MODULE, '-spawn_simple_test/3-fun-1-', 4}]} - | _]] = - lists:filter(fun ([Pt | _]) when element(1, Pt) == Proc2 -> true; - (_) -> false - end, Procs), - ?line 3 = length(Procs), - ?line R1 = lists:reverse(R2), + {ok, [T, P]} = parse(AnalysisFile), + io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), + ok = verify(T, P), + Proc1 = pid_to_list(P1), + Proc2 = pid_to_list(P2), + Proc0 = pid_to_list(self()), + io:format("~p~n ~p ~p ~p~n", [P, Proc0, Proc1, Proc2]), + [{analysis_options, _}, [{totals, _, Acc, _}] | Procs] = P, + [[{Proc0, _, undefined, _} | _]] = lists:filter( + fun ([Pt | _]) when element(1, Pt) == Proc0 -> true; + (_) -> false + end, Procs), + [[{Proc1, _, undefined, _}, + {spawned_by, Proc0}, + {spawned_as, {erlang, apply, ["#Fun"++_, []]}}, + {initial_calls, [{erlang, apply, 2}, + {?MODULE, '-spawn_simple_test/3-fun-0-', 4}]} + | _]] = lists:filter(fun ([Pt | _]) when element(1, Pt) == Proc1 -> true; + (_) -> false + end, Procs), + [[{Proc2, _, undefined, _}, + {spawned_by, Proc0}, + {spawned_as, {erlang, apply, ["#Fun"++_, []]}}, + {initial_calls, [{erlang, apply, 2}, + {?MODULE, '-spawn_simple_test/3-fun-1-', 4}]} + | _]] = lists:filter(fun ([Pt | _]) when element(1, Pt) == Proc2 -> true; + (_) -> false + end, Procs), + 3 = length(Procs), + R1 = lists:reverse(R2), %% - ?line check_own_and_acc(TraceFile,AnalysisFile), + check_own_and_acc(TraceFile,AnalysisFile), %% - ?line ets:delete(T), - ?line file:delete(TraceFile), - ?line file:delete(AnalysisFile), - ?line ?t:timetrap_cancel(Timetrap), - ?line Acc1 = ts_sub(TS1, TS0), - ?line Acc2 = ts_sub(TS2, TS1), - ?line io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc2, Acc1]), - {comment, io_lib:format("~p times slower", [Acc2/Acc1])}. + ets:delete(T), + file:delete(TraceFile), + file:delete(AnalysisFile), + Acc1 = TS1 - TS0, + Acc2 = TS2 - TS1, + io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc2, Acc1]), + {comment, io_lib:format("~p times slower", [divide(Acc2,Acc1)])}. spawn_simple_test(Start, Stop, Succ) -> Parent = self(), - Seq = - spawn_link( - fun () -> - Parent ! {self(), seq(Start, Stop, Succ)} - end), - SeqR = - spawn_link( - fun () -> - Parent ! {self(), seq_r(Start, Stop, Succ)} - end), - receive {Seq, SeqResult} -> - receive {SeqR, SeqRResult} -> - {{Seq, SeqResult}, {SeqR, SeqRResult}} - end + Seq = spawn_link(fun() -> + Parent ! {self(), seq(Start, Stop, Succ)} + end), + + SeqR = spawn_link(fun() -> + Parent ! {self(), seq_r(Start, Stop, Succ)} + end), + receive + {Seq, SeqResult} -> + receive + {SeqR, SeqRResult} -> + {{Seq, SeqResult}, {SeqR, SeqRResult}} + end end. %%%--------------------------------------------------------------------- -imm_tail_seq(doc) -> - ["Tests a tail recursive variant of lists:seq/3 ", - "with immediate trace to profile"]; -imm_tail_seq(suite) -> - []; +%% Tests a tail recursive variant of lists:seq/3 +%% with immediate trace to profile imm_tail_seq(Config) when is_list(Config) -> - ?line Timetrap = ?t:timetrap(?t:seconds(10)), - ?line PrivDir = ?config(priv_dir, Config), - ?line AnalysisFile = - filename:join(PrivDir, ?MODULE_STRING"_imm_tail_seq.analysis"), - ?line Start = 1, - ?line Stop = 1000, - ?line Succ = fun (X) -> X + 1 end, - ?line ok = fprof:stop(kill), - ?line catch eprof:stop(), + PrivDir = proplists:get_value(priv_dir, Config), + AnalysisFile = filename:join(PrivDir, + ?MODULE_STRING"_imm_tail_seq.analysis"), + Start = 1, + Stop = 1000, + Succ = fun (X) -> X + 1 end, + ok = fprof:stop(kill), + catch eprof:stop(), %% - ?line TS0 = erlang:now(), - ?line R0 = seq_r(Start, Stop, Succ), - ?line TS1 = erlang:now(), + TS0 = erlang:monotonic_time(), + R0 = seq_r(Start, Stop, Succ), + TS1 = erlang:monotonic_time(), %% - ?line profiling = eprof:start_profiling([self()]), - ?line TS2 = erlang:now(), - ?line R2 = seq_r(Start, Stop, Succ), - ?line TS3 = erlang:now(), - ?line profiling_stopped = eprof:stop_profiling(), - ?line R2 = R0, + profiling = eprof:start_profiling([self()]), + TS2 = erlang:monotonic_time(), + R2 = seq_r(Start, Stop, Succ), + TS3 = erlang:monotonic_time(), + profiling_stopped = eprof:stop_profiling(), + R2 = R0, %% - ?line eprof:analyze(), - ?line stopped = eprof:stop(), + eprof:analyze(), + stopped = eprof:stop(), %% - ?line {ok, Tracer} = fprof:profile(start), - ?line ok = fprof:trace([start, {tracer, Tracer}]), - ?line TS4 = erlang:now(), - ?line R4 = seq_r(Start, Stop, Succ), - ?line TS5 = erlang:now(), - ?line ok = fprof:trace(stop), - ?line ok = fprof:analyse(), - ?line ok = fprof:analyse(dest, AnalysisFile), - ?line ok = fprof:stop(), - ?line R4 = R0, + {ok, Tracer} = fprof:profile(start), + ok = fprof:trace([start, {tracer, Tracer}]), + TS4 = erlang:monotonic_time(), + R4 = seq_r(Start, Stop, Succ), + TS5 = erlang:monotonic_time(), + ok = fprof:trace(stop), + ok = fprof:analyse(), + ok = fprof:analyse(dest, AnalysisFile), + ok = fprof:stop(), + R4 = R0, %% - ?line {ok, [T, P]} = parse(AnalysisFile), - ?line io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), - ?line ok = verify(T, P), - ?line Proc = pid_to_list(self()), - ?line case P of - [{analysis_options, _}, - [{totals, _, Acc, _}], - [{Proc, _, undefined, _} | _]] -> - ok - end, + {ok, [T, P]} = parse(AnalysisFile), + io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), + ok = verify(T, P), + Proc = pid_to_list(self()), + case P of + [{analysis_options, _}, + [{totals, _, Acc, _}], + [{Proc, _, undefined, _} | _]] -> ok + end, %% - ?line ets:delete(T), - ?line file:delete(AnalysisFile), - ?line ?t:timetrap_cancel(Timetrap), - ?line Acc1 = ts_sub(TS1, TS0), - ?line Acc3 = ts_sub(TS3, TS2), - ?line Acc5 = ts_sub(TS5, TS4), - ?line io:format("~p (plain), ~p (eprof), ~p (fprof), ~p (cpu)~n", - [Acc1/1000, Acc3/1000, Acc5/1000, Acc/1000]), + ets:delete(T), + file:delete(AnalysisFile), + Acc1 = TS1 - TS0, + Acc3 = TS3 - TS2, + Acc5 = TS5 - TS4, + io:format("~p (plain), ~p (eprof), ~p (fprof), ~p (cpu)~n", + [Acc1/1000, Acc3/1000, Acc5/1000, Acc/1000]), {comment, io_lib:format("~p/~p (fprof/eprof) times slower", - [Acc5/Acc1, Acc3/Acc1])}. + [divide(Acc5,Acc1), divide(Acc3,Acc1)])}. %%%--------------------------------------------------------------------- -imm_create_file_slow(doc) -> - ["Tests a tail recursive variant of lists:seq/3 ", - "with immediate trace to profile"]; -imm_create_file_slow(suite) -> - []; +%% Tests a tail recursive variant of lists:seq/3 +%% with immediate trace to profile imm_create_file_slow(Config) when is_list(Config) -> - ?line Timetrap = ?t:timetrap(?t:seconds(60)), - ?line PrivDir = ?config(priv_dir, Config), - ?line DataFile = - filename:join(PrivDir, ?MODULE_STRING"_imm_create_file_slow.data"), - ?line AnalysisFile = - filename:join(PrivDir, ?MODULE_STRING"_imm_create_file_slow.analysis"), - ?line ok = fprof:stop(kill), + PrivDir = proplists:get_value(priv_dir, Config), + DataFile = filename:join(PrivDir, + ?MODULE_STRING"_imm_create_file_slow.data"), + AnalysisFile = filename:join(PrivDir, + ?MODULE_STRING"_imm_create_file_slow.analysis"), + ok = fprof:stop(kill), %% - ?line TS0 = erlang:now(), - ?line ok = create_file_slow(DataFile, 1024), - ?line TS1 = erlang:now(), - ?line ok = file:delete(DataFile), + TS0 = erlang:monotonic_time(), + ok = create_file_slow(DataFile, 1024), + TS1 = erlang:monotonic_time(), + ok = file:delete(DataFile), %% - ?line {ok, Tracer} = fprof:profile(start), - ?line TS2 = erlang:now(), - ?line ok = fprof:apply(?MODULE, create_file_slow, [DataFile, 1024], - [{tracer, Tracer}, continue]), - ?line TS3 = erlang:now(), - ?line ok = fprof:profile(stop), - ?line ok = fprof:analyse(), - ?line ok = fprof:analyse(dest, AnalysisFile), - ?line ok = fprof:stop(), + {ok, Tracer} = fprof:profile(start), + TS2 = erlang:monotonic_time(), + ok = fprof:apply(?MODULE, create_file_slow, [DataFile, 1024], + [{tracer, Tracer}, continue]), + TS3 = erlang:monotonic_time(), + ok = fprof:profile(stop), + ok = fprof:analyse(), + ok = fprof:analyse(dest, AnalysisFile), + ok = fprof:stop(), %% - ?line {ok, [T, P]} = parse(AnalysisFile), - ?line io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), - ?line ok = verify(T, P), - ?line Proc = pid_to_list(self()), - ?line case P of - [{analysis_options, _}, - [{totals, _, Acc, _}], - [{Proc, _, undefined, _} | _]] -> - ok - end, + {ok, [T, P]} = parse(AnalysisFile), + io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), + ok = verify(T, P), + Proc = pid_to_list(self()), + case P of + [{analysis_options, _}, + [{totals, _, Acc, _}], + [{Proc, _, undefined, _} | _]] -> + ok + end, %% - ?line ets:delete(T), - ?line file:delete(DataFile), - ?line file:delete(AnalysisFile), - ?line ?t:timetrap_cancel(Timetrap), - ?line Acc1 = ts_sub(TS1, TS0), - ?line Acc3 = ts_sub(TS3, TS2), - ?line io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc3, Acc1]), - {comment, io_lib:format("~p times slower", [Acc3/Acc1])}. + ets:delete(T), + file:delete(DataFile), + file:delete(AnalysisFile), + Acc1 = TS1 - TS0, + Acc3 = TS3 - TS2, + io:format("ts:~w, fprof:~w, bare:~w.~n", [Acc, Acc3, Acc1]), + {comment, io_lib:format("~p times slower", [divide(Acc3,Acc1)])}. %%%--------------------------------------------------------------------- -imm_compile(doc) -> - ["Tests to compile a small source file ", - "with immediate trace to profile"]; -imm_compile(suite) -> - []; +%% Tests to compile a small source file with immediate trace to profile imm_compile(Config) when is_list(Config) -> - ?line Timetrap = ?t:timetrap(?t:minutes(20)), - ?line DataDir = ?config(data_dir, Config), - ?line SourceFile = filename:join(DataDir, "foo.erl"), - ?line PrivDir = ?config(priv_dir, Config), - ?line AnalysisFile = - filename:join(PrivDir, ?MODULE_STRING"_imm_compile.analysis"), - ?line ok = fprof:stop(kill), - ?line catch eprof:stop(), + ct:timetrap({minutes, 20}), + DataDir = proplists:get_value(data_dir, Config), + SourceFile = filename:join(DataDir, "foo.erl"), + PrivDir = proplists:get_value(priv_dir, Config), + AnalysisFile = filename:join(PrivDir, + ?MODULE_STRING"_imm_compile.analysis"), + ok = fprof:stop(kill), + catch eprof:stop(), %% - ?line {ok, foo, _} = compile:file(SourceFile, [binary]), - ?line TS0 = erlang:now(), - ?line {ok, foo, _} = compile:file(SourceFile, [binary]), - ?line TS1 = erlang:now(), + {ok, foo, _} = compile:file(SourceFile, [binary]), + TS0 = erlang:monotonic_time(), + {ok, foo, _} = compile:file(SourceFile, [binary]), + TS1 = erlang:monotonic_time(), %% - ?line profiling = eprof:start_profiling([self()]), - ?line TS2 = erlang:now(), - ?line {ok, foo, _} = compile:file(SourceFile, [binary]), - ?line TS3 = erlang:now(), - ?line profiling_stopped = eprof:stop_profiling(), + profiling = eprof:start_profiling([self()]), + TS2 = erlang:monotonic_time(), + {ok, foo, _} = compile:file(SourceFile, [binary]), + TS3 = erlang:monotonic_time(), + profiling_stopped = eprof:stop_profiling(), %% - ?line eprof:analyze(), - ?line stopped = eprof:stop(), + eprof:analyze(), + stopped = eprof:stop(), %% - ?line {ok, Tracer} = fprof:profile(start), - ?line ok = fprof:trace([start, {tracer, Tracer}]), - ?line TS4 = erlang:now(), - ?line {ok, foo, _} = compile:file(SourceFile, [binary]), - ?line TS5 = erlang:now(), - ?line ok = fprof:trace(stop), + {ok, Tracer} = fprof:profile(start), + ok = fprof:trace([start, {tracer, Tracer}]), + TS4 = erlang:monotonic_time(), + {ok, foo, _} = compile:file(SourceFile, [binary]), + TS5 = erlang:monotonic_time(), + ok = fprof:trace(stop), %% - ?line io:format("Analysing...~n"), - ?line ok = fprof:analyse(dest, AnalysisFile), - ?line ok = fprof:stop(), + io:format("Analysing...~n"), + ok = fprof:analyse(dest, AnalysisFile), + ok = fprof:stop(), %% - ?line {ok, [T, P]} = parse(AnalysisFile), - ?line io:format("~p~n", [P]), - ?line Acc1 = ts_sub(TS1, TS0), - ?line Acc3 = ts_sub(TS3, TS2), - ?line Acc5 = ts_sub(TS5, TS4), - ?line io:format("Verifying...~n"), - ?line ok = verify(T, P), - ?line case P of - [{analysis_options, _}, - [{totals, _, Acc, _}] | _] -> - ok - end, + {ok, [T, P]} = parse(AnalysisFile), + io:format("~p~n", [P]), + Acc1 = TS1 - TS0, + Acc3 = TS3 - TS2, + Acc5 = TS5 - TS4, + io:format("Verifying...~n"), + ok = verify(T, P), + case P of + [{analysis_options, _}, + [{totals, _, Acc, _}] | _] -> + ok + end, %% - ?line ets:delete(T), - ?line file:delete(AnalysisFile), - ?line ?t:timetrap_cancel(Timetrap), - ?line io:format("~p (plain), ~p (eprof), ~p (fprof), ~p(cpu)~n", - [Acc1/1000, Acc3/1000, Acc5/1000, Acc/1000]), + ets:delete(T), + file:delete(AnalysisFile), + io:format("~p (plain), ~p (eprof), ~p (fprof), ~p(cpu)~n", + [Acc1/1000, Acc3/1000, Acc5/1000, Acc/1000]), {comment, io_lib:format("~p/~p (fprof/eprof) times slower", - [Acc5/Acc1, Acc3/Acc1])}. + [divide(Acc5,Acc1), divide(Acc3,Acc1)])}. %%%--------------------------------------------------------------------- -cpu_create_file_slow(doc) -> - ["Tests the create_file_slow benchmark using cpu_time"]; -cpu_create_file_slow(suite) -> - []; +%% Tests the create_file_slow benchmark using cpu_time cpu_create_file_slow(Config) when is_list(Config) -> - ?line Timetrap = ?t:timetrap(?t:seconds(40)), - ?line PrivDir = ?config(priv_dir, Config), - ?line TraceFile = - filename:join(PrivDir, ?MODULE_STRING"_cpu_create_file_slow.trace"), - ?line AnalysisFile = - filename:join(PrivDir, ?MODULE_STRING"_cpu_create_file_slow.analysis"), - ?line DataFile = - filename:join(PrivDir, ?MODULE_STRING"_cpu_create_file_slow.data"), - ?line ok = fprof:stop(kill), + PrivDir = proplists:get_value(priv_dir, Config), + TraceFile = + filename:join(PrivDir, ?MODULE_STRING"_cpu_create_file_slow.trace"), + AnalysisFile = + filename:join(PrivDir, ?MODULE_STRING"_cpu_create_file_slow.analysis"), + DataFile = + filename:join(PrivDir, ?MODULE_STRING"_cpu_create_file_slow.data"), + ok = fprof:stop(kill), %% - ?line TS0 = erlang:now(), - ?line Result = (catch fprof:apply(?MODULE, create_file_slow, - [DataFile, 1024], - [{file, TraceFile}, cpu_time])), - ?line TS1 = erlang:now(), - ?line TestResult = - case Result of - ok -> - ?line ok = fprof:profile(file, TraceFile), - ?line ok = fprof:analyse(), - ?line ok = fprof:analyse(dest, AnalysisFile), - ?line ok = fprof:stop(), - %% - ?line {ok, [T, P]} = parse(AnalysisFile), - ?line io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), - ?line ok = verify(T, P), - ?line Proc = pid_to_list(self()), - ?line case P of - [{analysis_options, _}, - [{totals, _, Acc, _}], - [{Proc, _, undefined, _} | _]] -> - ok - end, - %% - ?line check_own_and_acc(TraceFile,AnalysisFile), - %% - ?line ets:delete(T), - ?line file:delete(DataFile), - ?line file:delete(TraceFile), - ?line file:delete(AnalysisFile), - ?line Acc1 = ts_sub(TS1, TS0), - ?line io:format("cpu_ts:~w, fprof:~w~n", [Acc, Acc1]), - {comment, io_lib:format("~p% cpu utilization", - [100*Acc/Acc1])}; - {'EXIT', not_supported} -> - case {os:type(), os:version()} of - {{unix, sunos}, {Major, Minor, _}} - when Major >= 5, Minor >= 7 -> - test_server:fail(Result); - _ -> - {skipped, "not_supported"} - end; - _ -> - test_server:fail(Result) - end, - ?line ?t:timetrap_cancel(Timetrap), + TS0 = erlang:monotonic_time(), + Result = (catch fprof:apply(?MODULE, create_file_slow, + [DataFile, 1024], + [{file, TraceFile}, cpu_time])), + TS1 = erlang:monotonic_time(), + TestResult = + case Result of + ok -> + ok = fprof:profile(file, TraceFile), + ok = fprof:analyse(), + ok = fprof:analyse(dest, AnalysisFile), + ok = fprof:stop(), + %% + {ok, [T, P]} = parse(AnalysisFile), + io:format("~p~n~n~p~n", [P, ets:tab2list(T)]), + ok = verify(T, P), + Proc = pid_to_list(self()), + case P of + [{analysis_options, _}, + [{totals, _, Acc, _}], + [{Proc, _, undefined, _} | _]] -> + ok + end, + %% + check_own_and_acc(TraceFile,AnalysisFile), + %% + ets:delete(T), + file:delete(DataFile), + file:delete(TraceFile), + file:delete(AnalysisFile), + Acc1 = TS1 - TS0, + io:format("cpu_ts:~w, fprof:~w~n", [Acc, Acc1]), + {comment, io_lib:format("~p% cpu utilization", [100*divide(Acc,Acc1)])}; + {'EXIT', not_supported} -> + case {os:type(), os:version()} of + {{unix, sunos}, {Major, Minor, _}} + when Major >= 5, Minor >= 7 -> + ct:fail(Result); + _ -> + {skipped, "not_supported"} + end; + _ -> + ct:fail(Result) + end, TestResult. - %%%--------------------------------------------------------------------- %%% Functions to test %%%--------------------------------------------------------------------- @@ -623,14 +560,14 @@ seq_r(Start, Stop, Succ, R) -> create_file_slow(Name, N) when is_integer(N), N >= 0 -> {ok, FD} = - file:open(Name, [raw, write, delayed_write, binary]), + file:open(Name, [raw, write, delayed_write, binary]), if N > 256 -> - ok = file:write(FD, - lists:map(fun (X) -> <<X:32/unsigned>> end, - lists:seq(0, 255))), - ok = create_file_slow(FD, 256, N); + ok = file:write(FD, + lists:map(fun (X) -> <<X:32/unsigned>> end, + lists:seq(0, 255))), + ok = create_file_slow(FD, 256, N); true -> - ok = create_file_slow(FD, 0, N) + ok = create_file_slow(FD, 0, N) end, ok = file:close(FD). @@ -647,46 +584,44 @@ create_file_slow(FD, M, N) -> %%%--------------------------------------------------------------------- - verify(Tab, [{analysis_options, _}, - [{totals, Cnt, Acc, Own} | _] | Processes]) -> + [{totals, Cnt, Acc, Own} | _] | Processes]) -> Processes_1 = - lists:map( - fun ([{Proc, Cnt_P, undefined, Own_P} | _]) -> - case sum_process(Tab, Proc) of - {Proc, Cnt_P, Acc_P, Own_P} = Clocks - when Acc_P >= Own_P -> - Clocks; - Weird -> - throw({error, [?MODULE, ?LINE, Weird]}) - end - end, - Processes), + lists:map( + fun ([{Proc, Cnt_P, undefined, Own_P} | _]) -> + case sum_process(Tab, Proc) of + {Proc, Cnt_P, Acc_P, Own_P} = Clocks + when Acc_P >= Own_P -> + Clocks; + Weird -> + throw({error, [?MODULE, ?LINE, Weird]}) + end + end, + Processes), case lists:foldl( - fun ({_, Cnt_P2, Acc_P2, Own_P2}, - {totals, Cnt_T, Acc_T, Own_T}) -> - {totals, Cnt_P2+Cnt_T, Acc_P2+Acc_T, Own_P2+Own_T} - end, - {totals, 0, 0, 0}, - Processes_1) of - {totals, Cnt, Acc_T, Own} when Acc_T >= Acc -> - ok; - Weird -> - throw({error, [?MODULE, ?LINE, Weird]}) + fun ({_, Cnt_P2, Acc_P2, Own_P2}, + {totals, Cnt_T, Acc_T, Own_T}) -> + {totals, Cnt_P2+Cnt_T, Acc_P2+Acc_T, Own_P2+Own_T} + end, + {totals, 0, 0, 0}, + Processes_1) of + {totals, Cnt, Acc_T, Own} when Acc_T >= Acc -> + ok; + Weird -> + throw({error, [?MODULE, ?LINE, Weird]}) end. - sum_process(Tab, Proc) -> ets_select_fold( Tab, [{{{Proc, '_'}, '_'}, [], ['$_']}], 100, fun ({{P, MFA}, {Callers, {MFA, Cnt, Acc, Own}, Called}}, - {P, Cnt_P, Acc_P, Own_P}) when P == Proc -> - ok = verify_callers(Tab, Proc, MFA, Callers), - ok = verify_called(Tab, Proc, MFA, Called), - {P, Cnt+Cnt_P, Acc+Acc_P, Own+Own_P}; - (Weird, Clocks) -> - throw({error, [?MODULE, ?LINE, Weird, Clocks]}) + {P, Cnt_P, Acc_P, Own_P}) when P == Proc -> + ok = verify_callers(Tab, Proc, MFA, Callers), + ok = verify_called(Tab, Proc, MFA, Called), + {P, Cnt+Cnt_P, Acc+Acc_P, Own+Own_P}; + (Weird, Clocks) -> + throw({error, [?MODULE, ?LINE, Weird, Clocks]}) end, {Proc, 0, 0, 0}). @@ -695,31 +630,31 @@ verify_callers(_, _, _, []) -> verify_callers(Tab, Proc, MFA, [{Caller, Cnt, Acc, Own} | Tail]) -> Id = {Proc, Caller}, case ets:lookup(Tab, Id) of - [{Id, {_, {Caller, _, _, _}, Called}}] -> - case lists:keysearch(MFA, 1, Called) of - {value, {MFA, Cnt, Acc, Own}} -> - verify_callers(Tab, Proc, MFA, Tail); - false -> - throw({error, [?MODULE, ?LINE, MFA, Id]}) - end; - Weird -> - throw({error, [?MODULE, ?LINE, Weird]}) + [{Id, {_, {Caller, _, _, _}, Called}}] -> + case lists:keysearch(MFA, 1, Called) of + {value, {MFA, Cnt, Acc, Own}} -> + verify_callers(Tab, Proc, MFA, Tail); + false -> + throw({error, [?MODULE, ?LINE, MFA, Id]}) + end; + Weird -> + throw({error, [?MODULE, ?LINE, Weird]}) end. - + verify_called(_, _, _, []) -> ok; verify_called(Tab, Proc, MFA, [{Called, Cnt, Acc, Own} | Tail]) -> Id = {Proc, Called}, case ets:lookup(Tab, Id) of - [{Id, {Callers, {Called, _, _, _}, _}}] -> - case lists:keysearch(MFA, 1, Callers) of - {value, {MFA, Cnt, Acc, Own}} -> - verify_called(Tab, Proc, MFA, Tail); - false -> - throw({error, [?MODULE, ?LINE, MFA, Id]}) - end; - Weird -> - throw({error, [?MODULE, ?LINE, Weird]}) + [{Id, {Callers, {Called, _, _, _}, _}}] -> + case lists:keysearch(MFA, 1, Callers) of + {value, {MFA, Cnt, Acc, Own}} -> + verify_called(Tab, Proc, MFA, Tail); + false -> + throw({error, [?MODULE, ?LINE, MFA, Id]}) + end; + Weird -> + throw({error, [?MODULE, ?LINE, Weird]}) end. @@ -729,12 +664,12 @@ verify_called(Tab, Proc, MFA, [{Called, Cnt, Acc, Own} | Tail]) -> %% entries when they are read. parse(Filename) -> case file:open(Filename, [read]) of - {ok, FD} -> - Result = parse_stream(FD), - file:close(FD), - Result; - Error -> - Error + {ok, FD} -> + Result = parse_stream(FD), + file:close(FD), + Result; + Error -> + Error end. parse_stream(FD) -> @@ -743,31 +678,31 @@ parse_stream(FD) -> parse_stream(FD, Tab, R, Proc) -> case catch io:read(FD, '') of - {'EXIT', _} -> - {error, [?MODULE, ?LINE]}; - {ok, Term} -> - case parse_term(Term) of - {ok, {analysis_options, _} = Term_1} - when Proc == void -> - parse_stream(FD, Tab, [Term_1 | R], analysis_options); - {ok, [{totals, _, _, _} | _] = Term_1} - when Proc == analysis_options -> - parse_stream(FD, Tab, [Term_1 | R], totals); - {ok, [{P, _, _, _} | _] = Term_1} -> - parse_stream(FD, Tab, [Term_1 | R], P); - {ok, {_Callers, {MFA, _, _, _}, _Called} = Term_1} - when Proc == totals; is_list(Proc) -> - ets:insert(Tab, {{Proc, MFA}, Term_1}), - parse_stream(FD, Tab, R, Proc); - {ok, Term_1} -> - {error, [?MODULE, ?LINE, Term_1]}; - E -> - E - end; - eof -> - {ok, [Tab, lists:reverse(R)]}; - Error -> - Error + {'EXIT', _} -> + {error, [?MODULE, ?LINE]}; + {ok, Term} -> + case parse_term(Term) of + {ok, {analysis_options, _} = Term_1} + when Proc == void -> + parse_stream(FD, Tab, [Term_1 | R], analysis_options); + {ok, [{totals, _, _, _} | _] = Term_1} + when Proc == analysis_options -> + parse_stream(FD, Tab, [Term_1 | R], totals); + {ok, [{P, _, _, _} | _] = Term_1} -> + parse_stream(FD, Tab, [Term_1 | R], P); + {ok, {_Callers, {MFA, _, _, _}, _Called} = Term_1} + when Proc == totals; is_list(Proc) -> + ets:insert(Tab, {{Proc, MFA}, Term_1}), + parse_stream(FD, Tab, R, Proc); + {ok, Term_1} -> + {error, [?MODULE, ?LINE, Term_1]}; + E -> + E + end; + eof -> + {ok, [Tab, lists:reverse(R)]}; + Error -> + Error end. parse_term({Callers, Func, Called}) @@ -777,10 +712,10 @@ parse_term({Callers, Func, Called}) Called_1 = lists:map(fun parse_clocks/1, Called), Result = {Callers_1, Func_1, Called_1}, case chk_invariant(Result) of - ok -> - {ok, Result}; - Error -> - Error + ok -> + {ok, Result}; + Error -> + Error end; parse_term([{_, _, _, _} = Clocks | Tail]) -> {ok, [parse_clocks(Clocks) | Tail]}; @@ -798,41 +733,41 @@ parse_clocks(Clocks) -> chk_invariant({Callers, {MFA, Cnt, Acc, Own}, Called} = Term) -> {_, Callers_Cnt, Callers_Acc, Callers_Own} = Callers_Sum = sum(Callers), -% {_, Called_Cnt, Called_Acc, Called_Own} = Called_Sum = sum(Called), + % {_, Called_Cnt, Called_Acc, Called_Own} = Called_Sum = sum(Called), case {MFA, - lists:keymember(suspend, 1, Callers), - lists:keymember(garbage_collect, 1, Callers), - Called} of - {suspend, false, _, []} -> - ok; - {suspend, _, _, _} = Weird -> - {error, [?MODULE, ?LINE, Weird, Term]}; - {garbage_collect, false, false, []} -> - ok; - {garbage_collect, false, false, [{suspend, _, _, _}]} -> - ok; - {garbage_collect, _, _, _} = Weird -> - {error, [?MODULE, ?LINE, Weird, Term]}; - {undefined, false, false, _} - when Callers == [], Cnt == 0, Acc == 0, Own == 0 -> - ok; - {undefined, _, _, _} = Weird -> - {error, [?MODULE, ?LINE, Weird, Term]}; - {_, _, _, _} -> - case chk_self_call(Term) of - true when Callers_Cnt /= Cnt; Callers_Acc /= Acc; - Callers_Own /= Own -> - {error, [?MODULE, ?LINE, Callers_Sum, Term]}; -% true when Called_Acc + Own /= Acc -> -% io:format("WARNING: ~p:~p, ~p, ~p.~n", -% [?MODULE, ?LINE, Term, Called_Sum]), -% {error, [?MODULE, ?LINE, Term, Called_Sum]}; -% ok; - true -> - ok; - false -> - {error, [?MODULE, ?LINE, Term]} - end + lists:keymember(suspend, 1, Callers), + lists:keymember(garbage_collect, 1, Callers), + Called} of + {suspend, false, _, []} -> + ok; + {suspend, _, _, _} = Weird -> + {error, [?MODULE, ?LINE, Weird, Term]}; + {garbage_collect, false, false, []} -> + ok; + {garbage_collect, false, false, [{suspend, _, _, _}]} -> + ok; + {garbage_collect, _, _, _} = Weird -> + {error, [?MODULE, ?LINE, Weird, Term]}; + {undefined, false, false, _} + when Callers == [], Cnt == 0, Acc == 0, Own == 0 -> + ok; + {undefined, _, _, _} = Weird -> + {error, [?MODULE, ?LINE, Weird, Term]}; + {_, _, _, _} -> + case chk_self_call(Term) of + true when Callers_Cnt /= Cnt; Callers_Acc /= Acc; + Callers_Own /= Own -> + {error, [?MODULE, ?LINE, Callers_Sum, Term]}; + % true when Called_Acc + Own /= Acc -> + % io:format("WARNING: ~p:~p, ~p, ~p.~n", + % [?MODULE, ?LINE, Term, Called_Sum]), + % {error, [?MODULE, ?LINE, Term, Called_Sum]}; + % ok; + true -> + ok; + false -> + {error, [?MODULE, ?LINE, Term]} + end end. ts_sub({A, B, C}, {A0, B0, C0}) -> @@ -840,28 +775,28 @@ ts_sub({A, B, C}, {A0, B0, C0}) -> sum(Funcs) -> {sum, _Cnt, _Acc, _Own} = - lists:foldl( - fun ({_, C1, A1, O1}, {sum, C2, A2, O2}) -> - {sum, C1+C2, A1+A2, O1+O2} - end, - {sum, 0, 0, 0}, - Funcs). + lists:foldl( + fun ({_, C1, A1, O1}, {sum, C2, A2, O2}) -> + {sum, C1+C2, A1+A2, O1+O2} + end, + {sum, 0, 0, 0}, + Funcs). chk_self_call({Callers, {MFA, _Cnt, _Acc, _Own}, Called}) -> case lists:keysearch(MFA, 1, Callers) of - false -> - true; - {value, {MFA, C, 0, O}} -> - case lists:keysearch(MFA, 1, Called) of - false -> - false; - {value, {MFA, C, 0, O}} -> - true; - {value, _} -> - false - end; - {value, _} -> - false + false -> + true; + {value, {MFA, C, 0, O}} -> + case lists:keysearch(MFA, 1, Called) of + false -> + false; + {value, {MFA, C, 0, O}} -> + true; + {value, _} -> + false + end; + {value, _} -> + false end. @@ -879,9 +814,8 @@ ets_select_fold_1('$end_of_table', _, Acc) -> Acc; ets_select_fold_1({Matches, Continuation}, Fun, Acc) -> ets_select_fold_1(ets:select(Continuation), - Fun, - lists:foldl(Fun, Acc, Matches)). - + Fun, + lists:foldl(Fun, Acc, Matches)). % ets_select_foreach(Table, MatchSpec, Limit, Fun) -> @@ -910,7 +844,7 @@ check_own_and_acc(TraceFile, AnalysisFile) -> check_own_and_acc(TraceFile, AnalysisFile, HandlerFun) -> dbg:trace_client(file,TraceFile,{HandlerFun,{init,self()}}), receive {result,Result} -> - compare(Result,get_own_and_acc_from_analysis(AnalysisFile)) + compare(Result,get_own_and_acc_from_analysis(AnalysisFile)) end. %% handle_trace_traced(Trace, Msg) -> @@ -924,21 +858,21 @@ handle_trace(Trace,{init,Parent}) -> handle_trace({trace_ts,Pid,in,MFA,TS},P) -> ?dbg("~p",[{{in,Pid,MFA},get(Pid)}]), case get(Pid) of - [suspend|[suspend|_]=NewStack] -> - T = ts_sub(TS,get({Pid,last_ts})), - update_acc(Pid,NewStack,T), - put(Pid,NewStack); - [suspend|NewStack] = Stack -> - T = ts_sub(TS,get({Pid,last_ts})), - update_acc(Pid,Stack,T), - put(Pid,NewStack); - [] -> - put(Pid,[MFA]), - insert(Pid,MFA); - undefined -> - put(first_ts,TS), - put(Pid,[MFA]), - insert(Pid,MFA) + [suspend|[suspend|_]=NewStack] -> + T = ts_sub(TS,get({Pid,last_ts})), + update_acc(Pid,NewStack,T), + put(Pid,NewStack); + [suspend|NewStack] = Stack -> + T = ts_sub(TS,get({Pid,last_ts})), + update_acc(Pid,Stack,T), + put(Pid,NewStack); + [] -> + put(Pid,[MFA]), + insert(Pid,MFA); + undefined -> + put(first_ts,TS), + put(Pid,[MFA]), + insert(Pid,MFA) end, put({Pid,last_ts},TS), P; @@ -946,17 +880,17 @@ handle_trace({trace_ts,Pid,out,_MfaOrZero,TS},P) -> ?dbg("~p",[{{out,Pid,_MfaOrZero},get(Pid)}]), T = ts_sub(TS,get({Pid,last_ts})), case get(Pid) of - [suspend|S] = Stack -> - update_acc(Pid,S,T), - put(Pid,[suspend|Stack]); - [MFA|_] = Stack -> - insert(Pid,suspend), - update_own(Pid,MFA,T), - update_acc(Pid,Stack,T), - put(Pid,[suspend|Stack]); - [] -> - insert(Pid,suspend), - put(Pid,[suspend]) + [suspend|S] = Stack -> + update_acc(Pid,S,T), + put(Pid,[suspend|Stack]); + [MFA|_] = Stack -> + insert(Pid,suspend), + update_own(Pid,MFA,T), + update_acc(Pid,Stack,T), + put(Pid,[suspend|Stack]); + [] -> + insert(Pid,suspend), + put(Pid,[suspend]) end, put({Pid,last_ts},TS), P; @@ -964,26 +898,26 @@ handle_trace({trace_ts,Pid,call,MFA,{cp,Caller},TS},P) -> ?dbg("~p",[{{call,Pid,MFA},get(Pid)}]), T = ts_sub(TS,get({Pid,last_ts})), case get(Pid) of - [MFA|_] = Stack -> - %% recursive - update_own(Pid,MFA,T), - update_acc(Pid,Stack,T); - [CallingMFA|_] = Stack when Caller==undefined -> - insert(Pid,MFA), - update_own(Pid,CallingMFA,T), - update_acc(Pid,Stack,T), - put(Pid,[MFA|Stack]); - [] when Caller==undefined -> - insert(Pid,MFA), - insert(Pid,MFA), - put(Pid,[MFA]); - Stack0 -> - Stack = [CallingMFA|_] = insert_caller(Caller,Stack0,[]), - insert(Pid,MFA), - insert(Pid,Caller), - update_own(Pid,CallingMFA,T), - update_acc(Pid,Stack,T), - put(Pid,[MFA|Stack]) + [MFA|_] = Stack -> + %% recursive + update_own(Pid,MFA,T), + update_acc(Pid,Stack,T); + [CallingMFA|_] = Stack when Caller==undefined -> + insert(Pid,MFA), + update_own(Pid,CallingMFA,T), + update_acc(Pid,Stack,T), + put(Pid,[MFA|Stack]); + [] when Caller==undefined -> + insert(Pid,MFA), + insert(Pid,MFA), + put(Pid,[MFA]); + Stack0 -> + Stack = [CallingMFA|_] = insert_caller(Caller,Stack0,[]), + insert(Pid,MFA), + insert(Pid,Caller), + update_own(Pid,CallingMFA,T), + update_acc(Pid,Stack,T), + put(Pid,[MFA|Stack]) end, put({Pid,last_ts},TS), P; @@ -991,59 +925,91 @@ handle_trace({trace_ts,Pid,return_to,MFA,TS},P) -> ?dbg("~p",[{{return_to,Pid,MFA},get(Pid)}]), T = ts_sub(TS,get({Pid,last_ts})), case get(Pid) of - [MFA|_] = Stack -> - %% recursive - update_own(Pid,MFA,T), - update_acc(Pid,Stack,T), - put(Pid,Stack); - [ReturnFromMFA,MFA|RestOfStack] = Stack -> - update_own(Pid,ReturnFromMFA,T), - update_acc(Pid,Stack,T), - put(Pid,[MFA|RestOfStack]); - [ReturnFromMFA|RestOfStack] = Stack -> - update_own(Pid,ReturnFromMFA,T), - update_acc(Pid,Stack,T), - case find_return_to(MFA,RestOfStack) of - [] when MFA==undefined -> - put(Pid,[]); - [] -> - insert(Pid,MFA), - put(Pid,[MFA]); - NewStack -> - put(Pid,NewStack) - end + [MFA|_] = Stack -> + %% recursive + update_own(Pid,MFA,T), + update_acc(Pid,Stack,T), + put(Pid,Stack); + [ReturnFromMFA,MFA|RestOfStack] = Stack -> + update_own(Pid,ReturnFromMFA,T), + update_acc(Pid,Stack,T), + put(Pid,[MFA|RestOfStack]); + [ReturnFromMFA|RestOfStack] = Stack -> + update_own(Pid,ReturnFromMFA,T), + update_acc(Pid,Stack,T), + case find_return_to(MFA,RestOfStack) of + [] when MFA==undefined -> + put(Pid,[]); + [] -> + insert(Pid,MFA), + put(Pid,[MFA]); + NewStack -> + put(Pid,NewStack) + end end, put({Pid,last_ts},TS), P; -handle_trace({trace_ts,Pid,gc_start,_,TS},P) -> - ?dbg("~p",[{{gc_start,Pid},get(Pid)}]), +handle_trace({trace_ts,Pid,gc_minor_start,_,TS},P) -> + ?dbg("~p",[{{gc_minor_start,Pid},get(Pid)}]), case get(Pid) of - [suspend|_] = Stack -> - T = ts_sub(TS,get({Pid,last_ts})), - insert(Pid,garbage_collect), - update_acc(Pid,Stack,T), - put(Pid,[garbage_collect|Stack]); - [CallingMFA|_] = Stack -> - T = ts_sub(TS,get({Pid,last_ts})), - insert(Pid,garbage_collect), - update_own(Pid,CallingMFA,T), - update_acc(Pid,Stack,T), - put(Pid,[garbage_collect|Stack]); - undefined -> - put(first_ts,TS), - put(Pid,[garbage_collect]), - insert(Pid,garbage_collect) + [suspend|_] = Stack -> + T = ts_sub(TS,get({Pid,last_ts})), + insert(Pid,garbage_collect), + update_acc(Pid,Stack,T), + put(Pid,[garbage_collect|Stack]); + [CallingMFA|_] = Stack -> + T = ts_sub(TS,get({Pid,last_ts})), + insert(Pid,garbage_collect), + update_own(Pid,CallingMFA,T), + update_acc(Pid,Stack,T), + put(Pid,[garbage_collect|Stack]); + undefined -> + put(first_ts,TS), + put(Pid,[garbage_collect]), + insert(Pid,garbage_collect) end, put({Pid,last_ts},TS), P; -handle_trace({trace_ts,Pid,gc_end,_,TS},P) -> - ?dbg("~p",[{{gc_end,Pid},get(Pid)}]), +handle_trace({trace_ts,Pid,gc_major_start,_,TS},P) -> + ?dbg("~p",[{{gc_minor_start,Pid},get(Pid)}]), + case get(Pid) of + [suspend|_] = Stack -> + T = ts_sub(TS,get({Pid,last_ts})), + insert(Pid,garbage_collect), + update_acc(Pid,Stack,T), + put(Pid,[garbage_collect|Stack]); + [CallingMFA|_] = Stack -> + T = ts_sub(TS,get({Pid,last_ts})), + insert(Pid,garbage_collect), + update_own(Pid,CallingMFA,T), + update_acc(Pid,Stack,T), + put(Pid,[garbage_collect|Stack]); + undefined -> + put(first_ts,TS), + put(Pid,[garbage_collect]), + insert(Pid,garbage_collect) + end, + put({Pid,last_ts},TS), + P; +handle_trace({trace_ts,Pid,gc_minor_end,_,TS},P) -> + ?dbg("~p",[{{gc_minor_end,Pid},get(Pid)}]), T = ts_sub(TS,get({Pid,last_ts})), case get(Pid) of - [garbage_collect|RestOfStack] = Stack -> - update_own(Pid,garbage_collect,T), - update_acc(Pid,Stack,T), - put(Pid,RestOfStack) + [garbage_collect|RestOfStack] = Stack -> + update_own(Pid,garbage_collect,T), + update_acc(Pid,Stack,T), + put(Pid,RestOfStack) + end, + put({Pid,last_ts},TS), + P; +handle_trace({trace_ts,Pid,gc_major_end,_,TS},P) -> + ?dbg("~p",[{{gc_major_end,Pid},get(Pid)}]), + T = ts_sub(TS,get({Pid,last_ts})), + case get(Pid) of + [garbage_collect|RestOfStack] = Stack -> + update_own(Pid,garbage_collect,T), + update_acc(Pid,Stack,T), + put(Pid,RestOfStack) end, put({Pid,last_ts},TS), P; @@ -1051,27 +1017,45 @@ handle_trace({trace_ts,Pid,spawn,NewPid,{M,F,Args},TS},P) -> MFA = {M,F,length(Args)}, ?dbg("~p",[{{spawn,Pid,NewPid,MFA},get(Pid)}]), T = ts_sub(TS,get({Pid,last_ts})), - put({NewPid,last_ts},TS), - put(NewPid,[suspend,MFA]), - insert(NewPid,suspend), - insert(NewPid,MFA), + case get(NewPid) of + undefined -> + put({NewPid,last_ts},TS), + put(NewPid,[suspend,MFA]), + insert(NewPid,suspend), + insert(NewPid,MFA); + _Else -> + ok + end, case get(Pid) of - [SpawningMFA|_] = Stack -> - update_own(Pid,SpawningMFA,T), - update_acc(Pid,Stack,T) + [SpawningMFA|_] = Stack -> + update_own(Pid,SpawningMFA,T), + update_acc(Pid,Stack,T) end, put({Pid,last_ts},TS), P; +handle_trace({trace_ts,NewPid,spawned,Pid,{M,F,Args},TS},P) -> + MFA = {M,F,length(Args)}, + ?dbg("~p",[{{spawned,NewPid,Pid,MFA},get(NewPid)}]), + case get(NewPid) of + undefined -> + put({NewPid,last_ts},TS), + put(NewPid,[suspend,MFA]), + insert(NewPid,suspend), + insert(NewPid,MFA); + _Else -> + ok + end, + P; handle_trace({trace_ts,Pid,exit,_Reason,TS},P) -> ?dbg("~p",[{{exit,Pid,_Reason},get(Pid)}]), T = ts_sub(TS,get({Pid,last_ts})), case get(Pid) of - [DyingMFA|_] = Stack -> - update_own(Pid,DyingMFA,T), - update_acc(Pid,Stack,T), - put(Pid,[]); - [] -> - ok + [DyingMFA|_] = Stack -> + update_own(Pid,DyingMFA,T), + update_acc(Pid,Stack,T), + put(Pid,[]); + [] -> + ok end, put({Pid,last_ts},TS), P; @@ -1089,6 +1073,7 @@ handle_trace(end_of_trace,P) -> P ! {result,[{totals,TotAcc,TotOwn}|ProcOwns]++Result}, P; handle_trace(Other,_P) -> + ct:log("Got unexpected trace message: ~p",[Other]), exit({unexpected,Other}). find_return_to(MFA,[MFA|_]=Stack) -> @@ -1107,10 +1092,10 @@ insert_caller(MFA,[],Result) -> insert(Pid,MFA) -> case ets:member(fprof_verify_tab,{Pid,MFA}) of - false -> - ets:insert(fprof_verify_tab,{{Pid,MFA},0,0}); - true -> - ok + false -> + ets:insert(fprof_verify_tab,{{Pid,MFA},0,0}); + true -> + ok end. update_own(Pid,MFA,T) -> @@ -1118,11 +1103,11 @@ update_own(Pid,MFA,T) -> update_acc(Pid,[MFA|Rest],T) -> case lists:member(MFA,Rest) of - true -> - %% Only charge one time for recursive functions - ok; - false -> - ets:update_counter(fprof_verify_tab,{Pid,MFA},{2,T}) + true -> + %% Only charge one time for recursive functions + ok; + false -> + ets:update_counter(fprof_verify_tab,{Pid,MFA},{2,T}) end, update_acc(Pid,Rest,T); update_acc(_Pid,[],_T) -> @@ -1140,63 +1125,63 @@ get_last_ts([],Last) -> get_proc_owns([{{Pid,_MFA},_Acc,Own}|Rest],Result,Sum) -> NewResult = - case lists:keysearch(Pid,1,Result) of - {value,{Pid,undefined,PidOwn}} -> - lists:keyreplace(Pid,1,Result,{Pid,undefined,PidOwn+Own}); - false -> - [{Pid,undefined,Own}|Result] + case lists:keysearch(Pid,1,Result) of + {value,{Pid,undefined,PidOwn}} -> + lists:keyreplace(Pid,1,Result,{Pid,undefined,PidOwn+Own}); + false -> + [{Pid,undefined,Own}|Result] end, get_proc_owns(Rest,NewResult,Sum+Own); get_proc_owns([],Result,Sum) -> {Sum,Result}. - + compare([X|Rest],FprofResult) -> FprofResult1 = - case lists:member(X,FprofResult) of - true -> - ?dbg("~p",[X]), - lists:delete(X,FprofResult); - false -> - case lists:keysearch(element(1,X),1,FprofResult) of - {value,Fprof} -> - put(compare_error,true), - io:format("Error: Different values\n" - "Fprof: ~p\n" - "Simulator: ~p",[Fprof,X]), - lists:delete(Fprof,FprofResult); - false -> - put(compare_error,true), - io:format("Error: Missing in fprof: ~p",[X]), - FprofResult - end - end, + case lists:member(X,FprofResult) of + true -> + ?dbg("~p",[X]), + lists:delete(X,FprofResult); + false -> + case lists:keysearch(element(1,X),1,FprofResult) of + {value,Fprof} -> + put(compare_error,true), + io:format("Error: Different values\n" + "Fprof: ~p\n" + "Simulator: ~p",[Fprof,X]), + lists:delete(Fprof,FprofResult); + false -> + put(compare_error,true), + io:format("Error: Missing in fprof: ~p",[X]), + FprofResult + end + end, compare(Rest,FprofResult1); compare([],Rest) -> case {remove_undefined(Rest,[]),get(compare_error)} of - {[],undefined} -> ok; - {Error,_} -> - case Error of - [] -> ok; - _ -> io:format("\nMissing in simulator results:\n~p\n",[Error]) - end, - ?t:fail({error,mismatch_between_simulator_and_fprof}) + {[],undefined} -> ok; + {Error,_} -> + case Error of + [] -> ok; + _ -> io:format("\nMissing in simulator results:\n~p\n",[Error]) + end, + ct:fail({error,mismatch_between_simulator_and_fprof}) end. - + remove_undefined([{{_Pid,undefined},_,_}|Rest],Result) -> remove_undefined(Rest,Result); remove_undefined([X|Rest],Result) -> remove_undefined(Rest,[X|Result]); remove_undefined([],Result) -> Result. - + get_own_and_acc_from_analysis(Log) -> case file:consult(Log) of - {ok,[_Options,[{totals,_,TotAcc,TotOwn}]|Rest]} -> - get_own_and_acc(undefined,Rest, - [{totals,m1000(TotAcc),m1000(TotOwn)}]); - Error -> - exit({error,{cant_open,Log,Error}}) + {ok,[_Options,[{totals,_,TotAcc,TotOwn}]|Rest]} -> + get_own_and_acc(undefined,Rest, + [{totals,m1000(TotAcc),m1000(TotOwn)}]); + Error -> + exit({error,{cant_open,Log,Error}}) end. get_own_and_acc(_,[[{PidStr,_,Acc,Own}|_]|Rest],Result) -> @@ -1212,3 +1197,5 @@ m1000(undefined) -> m1000(X) -> round(X*1000). +divide(_,0) -> inf; +divide(A,B) -> A / B. |