From 9327904dcbf2708823c05baa7532783fb0214792 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Gustavsson?= Date: Fri, 7 Mar 2014 10:41:32 +0100 Subject: Teach the call_time trace to notice when the trace dies (non-SMP system) The call_time trace is a special kind of tracing that requires a tracer process just like ordinary call trace, but it never actually sends anything to the tracer. It merely use the existence of a trace process (and call trace flags) as an indication that call_time tracing is active for the process. If the tracer dies in a non-SMP run-time system, processes with call_time tracing would not notice that the tracer had died. Furthermore, if the set_on_spawn flag was active, the dead tracer could be propagaged to newly spawned processes. Before accumulating trace information in a non-SMP system, always validate the tracer process. (In an SMP system, a reference to a dead tracer will be cleared away each time a process is scheduled.) While we could put all of the new code beam_bp.c, we have chosen to make a function call from beam_bp.c to a function in erl_trace.c for clarity's sake and to ease further maintenance. In the future, we might want to handle tracing in more similar ways in the SMP and non-SMP system. --- erts/emulator/beam/beam_bp.c | 5 +- erts/emulator/beam/erl_trace.c | 19 ++++++ erts/emulator/beam/erl_trace.h | 1 + erts/emulator/test/trace_call_time_SUITE.erl | 96 ++++++++++++++++++++++++++-- 4 files changed, 115 insertions(+), 6 deletions(-) (limited to 'erts/emulator') diff --git a/erts/emulator/beam/beam_bp.c b/erts/emulator/beam/beam_bp.c index 49a34ab4ad..4e711c89e0 100644 --- a/erts/emulator/beam/beam_bp.c +++ b/erts/emulator/beam/beam_bp.c @@ -642,7 +642,7 @@ erts_generic_breakpoint(Process* c_p, BeamInstr* I, Eterm* reg) erts_smp_atomic_inc_nob(&bp->count->acount); } - if (bp_flags & ERTS_BPF_TIME_TRACE_ACTIVE) { + if (bp_flags & ERTS_BPF_TIME_TRACE_ACTIVE && erts_is_tracer_proc_valid(c_p)) { Eterm w; erts_trace_time_call(c_p, I, bp->time); w = (BeamInstr) *c_p->cp; @@ -730,7 +730,8 @@ erts_bif_trace(int bif_index, Process* p, Eterm* args, BeamInstr* I) } } if (bp_flags & ERTS_BPF_TIME_TRACE_ACTIVE && - IS_TRACED_FL(p, F_TRACE_CALLS)) { + IS_TRACED_FL(p, F_TRACE_CALLS) && + erts_is_tracer_proc_valid(p)) { BeamInstr *pc = (BeamInstr *)ep->code+3; erts_trace_time_call(p, pc, bp->time); } diff --git a/erts/emulator/beam/erl_trace.c b/erts/emulator/beam/erl_trace.c index 6978a5f11a..305058ceff 100644 --- a/erts/emulator/beam/erl_trace.c +++ b/erts/emulator/beam/erl_trace.c @@ -151,6 +151,11 @@ do { \ message dispatcher thread takes care of that). */ #define ERTS_GET_TRACER_REF(RES, TPID, TRACEE_FLGS) \ do { (RES) = (TPID); } while(0) +int +erts_is_tracer_proc_valid(Process* p) +{ + return 1; +} #else #define ERTS_NULL_TRACER_REF NULL #define ERTS_TRACER_REF_TYPE Process * @@ -163,6 +168,20 @@ do { \ return; \ } \ } while (0) +int +erts_is_tracer_proc_valid(Process* p) +{ + Process* tracer; + + tracer = erts_proc_lookup(ERTS_TRACER_PROC(p)); + if (tracer && ERTS_TRACE_FLAGS(tracer) & F_TRACER) { + return 1; + } else { + ERTS_TRACER_PROC(p) = NIL; + ERTS_TRACE_FLAGS(p) = ~TRACEE_FLAGS; + return 0; + } +} #endif static Uint active_sched; diff --git a/erts/emulator/beam/erl_trace.h b/erts/emulator/beam/erl_trace.h index 853c6cb0d8..4f2c70d6e7 100644 --- a/erts/emulator/beam/erl_trace.h +++ b/erts/emulator/beam/erl_trace.h @@ -39,6 +39,7 @@ void erts_change_default_tracing(int setflags, Uint *flagsp, Eterm *tracerp); void erts_get_default_tracing(Uint *flagsp, Eterm *tracerp); void erts_set_system_monitor(Eterm monitor); Eterm erts_get_system_monitor(void); +int erts_is_tracer_proc_valid(Process* p); #ifdef ERTS_SMP void erts_check_my_tracer_proc(Process *); diff --git a/erts/emulator/test/trace_call_time_SUITE.erl b/erts/emulator/test/trace_call_time_SUITE.erl index 5dfa87bbee..3036d2957b 100644 --- a/erts/emulator/test/trace_call_time_SUITE.erl +++ b/erts/emulator/test/trace_call_time_SUITE.erl @@ -33,7 +33,7 @@ %% Exported end user tests -export([seq/3, seq_r/3]). --export([loaded/1, a_function/1, a_called_function/1, dec/1, nif_dec/1]). +-export([loaded/1, a_function/1, a_called_function/1, dec/1, nif_dec/1, dead_tracer/1]). -define(US_ERROR, 10000). -define(R_ERROR, 0.8). @@ -89,7 +89,7 @@ all() -> true -> [not_run]; false -> [basic, on_and_off, info, pause_and_restart, scheduling, - combo, bif, nif, called_function] + combo, bif, nif, called_function, dead_tracer] end. groups() -> @@ -470,6 +470,92 @@ called_function(Config) when is_list(Config) -> ?line P = erlang:trace_pattern({'_','_','_'}, false, [call_time]), ok. +%% %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% + +dead_tracer(Config) when is_list(Config) -> + Self = self(), + FirstTracer = tracer(), + StartTracing = fun() -> turn_on_tracing(Self) end, + tell_tracer(FirstTracer, StartTracing), + [1,2,3,4,5,6,7,8] = seq(1, 8, fun(I) -> I + 1 end), + Ref = erlang:monitor(process, FirstTracer), + FirstTracer ! quit, + receive + {'DOWN',Ref,process,FirstTracer,normal} -> + ok + end, + erlang:yield(), + + %% Collect and check that we only get call_time info for the current process. + Info1 = collect_all_info(), + [] = other_than_self(Info1), + io:format("~p\n", [Info1]), + + %% Note that we have not turned off tracing for the current process, + %% but that the tracer has terminated. No more call_time information should be recorded. + [1,2,3] = seq(1, 3, fun(I) -> I + 1 end), + [] = collect_all_info(), + + %% When we start a second tracer process, that tracer process must + %% not inherit the tracing flags and the dead tracer (even though + %% we used set_on_spawn). + SecondTracer = tracer(), + tell_tracer(SecondTracer, StartTracing), + Seq20 = lists:seq(1, 20), + Seq20 = seq(1, 20, fun(I) -> I + 1 end), + Info2 = collect_all_info(), + io:format("~p\n", [Info2]), + [] = other_than_self(Info2), + SecondTracer ! quit, + + ok. + +other_than_self(Info) -> + [{Pid,MFA} || {MFA,[{Pid,_,_,_}]} <- Info, + Pid =/= self()]. + +tell_tracer(Tracer, Fun) -> + Tracer ! {execute,self(),Fun}, + receive + {Tracer,executed} -> + ok + end. + +tracer() -> + spawn_link(fun Loop() -> + receive + quit -> + ok; + {execute,From,Fun} -> + Fun(), + From ! {self(),executed}, + Loop() + end + end). + +turn_on_tracing(Pid) -> + _ = erlang:trace(Pid, true, [call,set_on_spawn]), + _ = erlang:trace_pattern({?MODULE,'_','_'}, true, [call_time]), + _ = now(), + ok. + +collect_all_info() -> + collect_all_info([{?MODULE,F,A} || {F,A} <- module_info(functions)] ++ + erlang:system_info(snifs)). + +collect_all_info([MFA|T]) -> + CallTime = erlang:trace_info(MFA, call_time), + erlang:trace_pattern(MFA, restart, [call_time]), + case CallTime of + {call_time,false} -> + collect_all_info(T); + {call_time,[]} -> + collect_all_info(T); + {call_time,[_|_]=List} -> + [{MFA,List}|collect_all_info(T)] + end; +collect_all_info([]) -> []. + %%% %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %%% The Tests %%% @@ -478,7 +564,6 @@ called_function(Config) when is_list(Config) -> %% %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %% Local helpers - load_nif(Config) -> ?line Path = ?config(data_dir, Config), ?line ok = erlang:load_nif(filename:join(Path,"trace_nif"), 0). @@ -602,8 +687,11 @@ collect(A, Ref) -> end. setup() -> + setup([]). + +setup(Opts) -> Pid = spawn_link(fun() -> loop() end), - ?line 1 = erlang:trace(Pid, true, [call]), + 1 = erlang:trace(Pid, true, [call|Opts]), Pid. execute(Pids, Mfa) when is_list(Pids) -> -- cgit v1.2.3