diff options
Diffstat (limited to 'erts/preloaded/src')
-rw-r--r-- | erts/preloaded/src/erl_tracer.erl | 29 | ||||
-rw-r--r-- | erts/preloaded/src/erlang.erl | 6 | ||||
-rw-r--r-- | erts/preloaded/src/init.erl | 76 |
3 files changed, 101 insertions, 10 deletions
diff --git a/erts/preloaded/src/erl_tracer.erl b/erts/preloaded/src/erl_tracer.erl index 2177e48f60..de1e9ca01e 100644 --- a/erts/preloaded/src/erl_tracer.erl +++ b/erts/preloaded/src/erl_tracer.erl @@ -3,12 +3,29 @@ -export([enabled/3, trace/6, on_load/0]). -type tracee() :: port() | pid() | undefined. --type trace_tag() :: send | send_to_non_existing_process | 'receive' | - call | return_to | return_from | exception_from | - spawn | spawned | exit | link | unlink | getting_linked | - getting_unlinked | register | unregister | in | out | - in_exiting | out_exiting | out_exited | - open | closed | gc_start | gc_end. + +-type trace_tag_running_ports() :: in | out | in_exiting | out_exiting | out_exited. +-type trace_tag_running_procs() :: in | out | in_exiting | out_exiting | out_exited. +-type trace_tag_send() :: send | send_to_non_existing_process. +-type trace_tag_receive() :: 'receive'. +-type trace_tag_call() :: call | return_to | return_from | exception_from. +-type trace_tag_procs() :: spawn | spawned | exit | link | unlink + | getting_linked | getting_unlinked + | register | unregister. +-type trace_tag_ports() :: open | closed | link | unlink + | getting_linked | getting_unlinked. +-type trace_tag_gc() :: gc_minor_start | gc_minor_end + | gc_major_start | gc_major_end. + +-type trace_tag() :: trace_tag_send() + | trace_tag_receive() + | trace_tag_call() + | trace_tag_procs() + | trace_tag_ports() + | trace_tag_running_procs() + | trace_tag_running_ports() + | trace_tag_gc(). + -type trace_opts() :: #{ match_spec_result => true | term(), scheduler_id => undefined | non_neg_integer(), timestamp => undefined | timestamp | cpu_timestamp | diff --git a/erts/preloaded/src/erlang.erl b/erts/preloaded/src/erlang.erl index 3cc17014ff..20a64e81b4 100644 --- a/erts/preloaded/src/erlang.erl +++ b/erts/preloaded/src/erlang.erl @@ -2257,9 +2257,9 @@ spawn_opt(_Tuple) -> Input :: non_neg_integer(), Output :: non_neg_integer(); (microstate_accounting) -> [MSAcc_Thread] | undefined when - MSAcc_Thread :: #{ type => MSAcc_Thread_Type, - id => MSAcc_Thread_Id, - counters => MSAcc_Counters}, + MSAcc_Thread :: #{ type := MSAcc_Thread_Type, + id := MSAcc_Thread_Id, + counters := MSAcc_Counters}, MSAcc_Thread_Type :: scheduler | async | aux, MSAcc_Thread_Id :: non_neg_integer(), MSAcc_Counters :: #{ MSAcc_Thread_State => non_neg_integer() }, diff --git a/erts/preloaded/src/init.erl b/erts/preloaded/src/init.erl index 77684751c8..618b53f6bb 100644 --- a/erts/preloaded/src/init.erl +++ b/erts/preloaded/src/init.erl @@ -41,6 +41,7 @@ %% -s : Start own processes. %% %% Experimental flags: +%% -profile_boot : Use an 'eprof light' to profile boot sequence %% -init_debug : Activate debug printouts in init %% -loader_debug : Activate debug printouts in erl_prim_loader %% -code_path_choice : strict | relaxed @@ -184,6 +185,11 @@ boot(BootArgs) -> erl_tracer:on_load(), {Start0,Flags,Args} = parse_boot_args(BootArgs), + %% We don't get to profile parsing of BootArgs + case get_flag(profile_boot, Flags, false) of + false -> ok; + true -> debug_profile_start() + end, Start = map(fun prepare_run_args/1, Start0), boot(Start, Flags, Args). @@ -765,7 +771,14 @@ do_boot(Init,Flags,Start) -> %% print the node name into the Purify log. (catch erlang:system_info({purify, "Node: " ++ atom_to_list(node())})), - start_em(Start). + start_em(Start), + case get_flag(profile_boot,Flags,false) of + false -> ok; + true -> + debug_profile_format_mfas(debug_profile_mfas()), + debug_profile_stop() + end, + ok. get_root(Flags) -> case get_argument(root, Flags) of @@ -1339,3 +1352,64 @@ run_on_load_handlers([M|Ms], Debug) -> end end; run_on_load_handlers([], _) -> ok. + + +%% debug profile (light variant of eprof) +debug_profile_start() -> + _ = erlang:trace_pattern({'_','_','_'},true,[call_time]), + _ = erlang:trace_pattern(on_load,true,[call_time]), + _ = erlang:trace(all,true,[call]), + ok. + +debug_profile_stop() -> + _ = erlang:trace_pattern({'_','_','_'},false,[call_time]), + _ = erlang:trace_pattern(on_load,false,[call_time]), + _ = erlang:trace(all,false,[call]), + ok. + +debug_profile_mfas() -> + _ = erlang:trace_pattern({'_','_','_'},pause,[call_time]), + _ = erlang:trace_pattern(on_load,pause,[call_time]), + MFAs = collect_loaded_mfas() ++ erlang:system_info(snifs), + collect_mfas(MFAs,[]). + +%% debug_profile_format_mfas should be called at the end of the boot phase +%% so all pertinent modules should be loaded at that point. +debug_profile_format_mfas(MFAs0) -> + MFAs = lists:sort(MFAs0), + lists:foreach(fun({{Us,C},{M,F,A}}) -> + Str = io_lib:format("~w:~w/~w", [M,F,A]), + io:format(standard_error,"~55s - ~6w : ~w us~n", [Str,C,Us]) + end, MFAs), + ok. + +collect_loaded_mfas() -> + Ms = [M || M <- [element(1, Mi) || Mi <- code:all_loaded()]], + collect_loaded_mfas(Ms,[]). + +collect_loaded_mfas([],MFAs) -> MFAs; +collect_loaded_mfas([M|Ms],MFAs0) -> + MFAs = [{M,F,A} || {F,A} <- M:module_info(functions)], + collect_loaded_mfas(Ms,MFAs ++ MFAs0). + + +collect_mfas([], Info) -> Info; +collect_mfas([MFA|MFAs],Info) -> + case erlang:trace_info(MFA,call_time) of + {call_time, []} -> + collect_mfas(MFAs,Info); + {call_time, false} -> + collect_mfas(MFAs,Info); + {call_time, Data} -> + case collect_mfa(MFA,Data,0,0) of + {{0,_},_} -> + %% ignore mfas with zero time + collect_mfas(MFAs,Info); + MfaData -> + collect_mfas(MFAs,[MfaData|Info]) + end + end. + +collect_mfa(Mfa,[],Count,Time) -> {{Time,Count},Mfa}; +collect_mfa(Mfa,[{_Pid,C,S,Us}|Data],Count,Time) -> + collect_mfa(Mfa,Data,Count + C,Time + S * 1000000 + Us). |