From b937b42d2f98c4e0024418dbbd55ff545bcf65d6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Sat, 10 Apr 2010 17:27:24 +0200 Subject: Call time breakpoint tracing framework Initial commit with a new breakpoint instruction and PSD areas for temporary time storage during tracing. --- erts/emulator/beam/erl_bif_trace.c | 70 ++++++++++++++++++++++++++++++++------ 1 file changed, 59 insertions(+), 11 deletions(-) (limited to 'erts/emulator/beam/erl_bif_trace.c') diff --git a/erts/emulator/beam/erl_bif_trace.c b/erts/emulator/beam/erl_bif_trace.c index 7fe4410e0d..20a58e5ed9 100644 --- a/erts/emulator/beam/erl_bif_trace.c +++ b/erts/emulator/beam/erl_bif_trace.c @@ -186,6 +186,14 @@ trace_pattern_3(Process* p, Eterm MFA, Eterm Pattern, Eterm flaglist) flags.breakpoint = 1; flags.call_count = 1; break; + case am_call_time: + if (is_global) { + goto error; + } + flags.breakpoint = 1; + flags.call_time = 1; + break; + default: goto error; } @@ -235,6 +243,8 @@ trace_pattern_3(Process* p, Eterm MFA, Eterm Pattern, Eterm flaglist) |= flags.meta; erts_default_trace_pattern_flags.call_count |= (on == 1) ? flags.call_count : 0; + erts_default_trace_pattern_flags.call_time + |= (on == 1) ? flags.call_time : 0; } else { erts_default_trace_pattern_flags.local &= ~flags.local; @@ -242,10 +252,13 @@ trace_pattern_3(Process* p, Eterm MFA, Eterm Pattern, Eterm flaglist) &= ~flags.meta; erts_default_trace_pattern_flags.call_count &= ~flags.call_count; + erts_default_trace_pattern_flags.call_time + &= ~flags.call_time; if (! (erts_default_trace_pattern_flags.breakpoint = erts_default_trace_pattern_flags.local | erts_default_trace_pattern_flags.meta | - erts_default_trace_pattern_flags.call_count)) { + erts_default_trace_pattern_flags.call_count | + erts_default_trace_pattern_flags.call_time)) { erts_default_trace_pattern_is_on = !!on; /* i.e off */ } } @@ -267,8 +280,9 @@ trace_pattern_3(Process* p, Eterm MFA, Eterm Pattern, Eterm flaglist) if (on) { if (on != 1) { flags.call_count = 0; + flags.call_time = 0; } - flags.breakpoint = flags.local | flags.meta | flags.call_count; + flags.breakpoint = flags.local | flags.meta | flags.call_count | flags.call_time; erts_default_trace_pattern_flags = flags; /* Struct copy */ erts_default_trace_pattern_is_on = !!flags.breakpoint; } @@ -352,7 +366,6 @@ erts_get_default_trace_pattern(int *trace_pattern_is_on, - Uint erts_trace_flag2bit(Eterm flag) { @@ -380,7 +393,7 @@ erts_trace_flag2bit(Eterm flag) default: return 0; } } - + /* Scan the argument list and sort out the trace flags. ** ** Returns !0 on success, 0 on failure. @@ -931,6 +944,7 @@ trace_info_pid(Process* p, Eterm pid_spec, Eterm key) #define FUNC_TRACE_LOCAL_TRACE (1<<2) #define FUNC_TRACE_META_TRACE (1<<3) #define FUNC_TRACE_COUNT_TRACE (1<<4) +#define FUNC_TRACE_TIME_TRACE (1<<5) /* * Returns either FUNC_TRACE_NOEXIST, FUNC_TRACE_UNTRACED, * FUNC_TRACE_GLOBAL_TRACE, or, @@ -946,10 +960,12 @@ trace_info_pid(Process* p, Eterm pid_spec, Eterm key) * If the return value contains FUNC_TRACE_COUNT_TRACE, *count is set. */ static int function_is_traced(Eterm mfa[3], - Binary **ms, /* out */ - Binary **ms_meta, /* out */ + Binary **ms, /* out */ + Binary **ms_meta, /* out */ Eterm *tracer_pid_meta, /* out */ - Sint *count) /* out */ + Sint *count, /* out */ + Uint *s_time, /* out */ + Uint *us_time) /* out */ { Export e; Export* ep; @@ -1001,7 +1017,9 @@ static int function_is_traced(Eterm mfa[3], | (erts_is_mtrace_break(code, ms_meta, tracer_pid_meta) ? FUNC_TRACE_META_TRACE : 0) | (erts_is_count_break(code, count) - ? FUNC_TRACE_COUNT_TRACE : 0); + ? FUNC_TRACE_COUNT_TRACE : 0) + | (erts_is_time_break(code, count, s_time, us_time) + ? FUNC_TRACE_TIME_TRACE : 0); return r ? r : FUNC_TRACE_UNTRACED; } @@ -1016,6 +1034,7 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) DeclareTmpHeap(mfa,3,p); /* Not really heap here, but might be when setting pattern */ Binary *ms = NULL, *ms_meta = NULL; Sint count = 0; + Uint s_time = 0, us_time = 0; Eterm traced = am_false; Eterm match_spec = am_false; Eterm retval = am_false; @@ -1039,7 +1058,7 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) mfa[1] = tp[2]; mfa[2] = signed_val(tp[3]); - r = function_is_traced(mfa, &ms, &ms_meta, &meta, &count); + r = function_is_traced(mfa, &ms, &ms_meta, &meta, &count, &s_time, &us_time); switch (r) { case FUNC_TRACE_NOEXIST: UnUseTmpHeap(3,p); @@ -1092,8 +1111,17 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) erts_make_integer(count, p); } break; + case am_call_time: + if (r & FUNC_TRACE_TIME_TRACE) { + hp = HAlloc(p, 4); + retval = TUPLE3(hp, + erts_make_integer(count, p), + erts_make_integer(s_time, p), + erts_make_integer(us_time,p)); hp += 4; + } + break; case am_all: { - Eterm match_spec_meta = am_false, c = am_false, t; + Eterm match_spec_meta = am_false, c = am_false, t, ct; if (ms) { match_spec = MatchSetGetSource(ms); @@ -1111,10 +1139,16 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) erts_make_integer(-count-1, p) : erts_make_integer(count, p); } - hp = HAlloc(p, (3+2)*5); + if (r & FUNC_TRACE_TIME_TRACE) { + hp = HAlloc(p, 4); + ct = TUPLE3(hp, erts_make_integer(count, p), erts_make_integer(s_time, p), erts_make_integer(us_time,p)); hp += 4; + } + hp = HAlloc(p, (3+2)*6); retval = NIL; t = TUPLE2(hp, am_call_count, c); hp += 3; retval = CONS(hp, t, retval); hp += 2; + t = TUPLE2(hp, am_call_time, ct); hp += 3; + retval = CONS(hp, t, retval); hp += 2; t = TUPLE2(hp, am_meta_match_spec, match_spec_meta); hp += 3; retval = CONS(hp, t, retval); hp += 2; t = TUPLE2(hp, am_meta, meta); hp += 3; @@ -1210,6 +1244,13 @@ trace_info_on_load(Process* p, Eterm key) } else { return TUPLE2(hp, key, am_false); } + case am_call_time: + hp = HAlloc(p, 3); + if (erts_default_trace_pattern_flags.call_time) { + return TUPLE2(hp, key, am_true); + } else { + return TUPLE2(hp, key, am_false); + } case am_all: { Eterm match_spec = am_false, meta_match_spec = am_false, r = NIL, t; @@ -1284,6 +1325,7 @@ erts_set_trace_pattern(Eterm* mfa, int specified, for (j = 0; j < specified && mfa[j] == ep->code[j]; j++) { /* Empty loop body */ } + if (j == specified) { if (on) { if (! flags.breakpoint) @@ -1405,6 +1447,9 @@ erts_set_trace_pattern(Eterm* mfa, int specified, if (flags.call_count) { m = erts_set_count_break(mfa, specified, on); } + if (flags.call_time) { + m = erts_set_time_break(mfa, specified, on); + } /* All assignments to 'm' above should give the same value, * so just use the last */ matches += m; @@ -1420,6 +1465,9 @@ erts_set_trace_pattern(Eterm* mfa, int specified, if (flags.call_count) { m = erts_clear_count_break(mfa, specified); } + if (flags.call_count) { + m = erts_clear_time_break(mfa, specified); + } /* All assignments to 'm' above should give the same value, * so just use the last */ matches += m; -- cgit v1.2.3 From 78d5145d68783dca4aa43bfd38fb9afecc59c416 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Wed, 21 Apr 2010 15:29:31 +0200 Subject: Add processes hashes for call time breakpoints Call time breakpoint tracing traces per call trace per process. - Add hashes to support the extra dimension. - Teach trace_info/2 to handle the extra information dimension. --- erts/emulator/beam/erl_bif_trace.c | 23 +++++++++-------------- 1 file changed, 9 insertions(+), 14 deletions(-) (limited to 'erts/emulator/beam/erl_bif_trace.c') diff --git a/erts/emulator/beam/erl_bif_trace.c b/erts/emulator/beam/erl_bif_trace.c index 20a58e5ed9..26390d397c 100644 --- a/erts/emulator/beam/erl_bif_trace.c +++ b/erts/emulator/beam/erl_bif_trace.c @@ -959,13 +959,13 @@ trace_info_pid(Process* p, Eterm pid_spec, Eterm key) * * If the return value contains FUNC_TRACE_COUNT_TRACE, *count is set. */ -static int function_is_traced(Eterm mfa[3], +static int function_is_traced(Process *p, + Eterm mfa[3], Binary **ms, /* out */ Binary **ms_meta, /* out */ Eterm *tracer_pid_meta, /* out */ Sint *count, /* out */ - Uint *s_time, /* out */ - Uint *us_time) /* out */ + Eterm *call_time) /* out */ { Export e; Export* ep; @@ -1018,7 +1018,7 @@ static int function_is_traced(Eterm mfa[3], ? FUNC_TRACE_META_TRACE : 0) | (erts_is_count_break(code, count) ? FUNC_TRACE_COUNT_TRACE : 0) - | (erts_is_time_break(code, count, s_time, us_time) + | (erts_is_time_break(p, code, call_time) ? FUNC_TRACE_TIME_TRACE : 0); return r ? r : FUNC_TRACE_UNTRACED; @@ -1034,11 +1034,11 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) DeclareTmpHeap(mfa,3,p); /* Not really heap here, but might be when setting pattern */ Binary *ms = NULL, *ms_meta = NULL; Sint count = 0; - Uint s_time = 0, us_time = 0; Eterm traced = am_false; Eterm match_spec = am_false; Eterm retval = am_false; Eterm meta = am_false; + Eterm call_time; int r; @@ -1058,7 +1058,7 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) mfa[1] = tp[2]; mfa[2] = signed_val(tp[3]); - r = function_is_traced(mfa, &ms, &ms_meta, &meta, &count, &s_time, &us_time); + r = function_is_traced(p, mfa, &ms, &ms_meta, &meta, &count, &call_time); switch (r) { case FUNC_TRACE_NOEXIST: UnUseTmpHeap(3,p); @@ -1113,15 +1113,11 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) break; case am_call_time: if (r & FUNC_TRACE_TIME_TRACE) { - hp = HAlloc(p, 4); - retval = TUPLE3(hp, - erts_make_integer(count, p), - erts_make_integer(s_time, p), - erts_make_integer(us_time,p)); hp += 4; + retval = call_time; } break; case am_all: { - Eterm match_spec_meta = am_false, c = am_false, t, ct; + Eterm match_spec_meta = am_false, c = am_false, t, ct = am_false; if (ms) { match_spec = MatchSetGetSource(ms); @@ -1140,8 +1136,7 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) erts_make_integer(count, p); } if (r & FUNC_TRACE_TIME_TRACE) { - hp = HAlloc(p, 4); - ct = TUPLE3(hp, erts_make_integer(count, p), erts_make_integer(s_time, p), erts_make_integer(us_time,p)); hp += 4; + ct = call_time; } hp = HAlloc(p, (3+2)*6); retval = NIL; -- cgit v1.2.3 From 891682094bf1db038cdf9addffe0b107f40ab6ec Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Thu, 29 Apr 2010 14:52:18 +0200 Subject: Add return_time trace and PSD deletions --- erts/emulator/beam/erl_bif_trace.c | 22 +++++++++++++++++++--- 1 file changed, 19 insertions(+), 3 deletions(-) (limited to 'erts/emulator/beam/erl_bif_trace.c') diff --git a/erts/emulator/beam/erl_bif_trace.c b/erts/emulator/beam/erl_bif_trace.c index 26390d397c..1e626533a4 100644 --- a/erts/emulator/beam/erl_bif_trace.c +++ b/erts/emulator/beam/erl_bif_trace.c @@ -41,11 +41,11 @@ #define DECL_AM(S) Eterm AM_ ## S = am_atom_put(#S, sizeof(#S) - 1) static erts_smp_mtx_t trace_pattern_mutex; -const struct trace_pattern_flags erts_trace_pattern_flags_off = {0, 0, 0, 0}; +const struct trace_pattern_flags erts_trace_pattern_flags_off = {0, 0, 0, 0, 0}; static int erts_default_trace_pattern_is_on; static Binary *erts_default_match_spec; static Binary *erts_default_meta_match_spec; -static struct trace_pattern_flags erts_default_trace_pattern_flags; +struct trace_pattern_flags erts_default_trace_pattern_flags; static Eterm erts_default_meta_tracer_pid; static void new_seq_trace_token(Process* p); /* help func for seq_trace_2*/ @@ -1058,7 +1058,22 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) mfa[1] = tp[2]; mfa[2] = signed_val(tp[3]); +#ifdef ERTS_SMP + if ( (key == am_call_time) || (key == am_all)) { + erts_smp_proc_unlock(p, ERTS_PROC_LOCK_MAIN); + erts_smp_block_system(0); + } +#endif + r = function_is_traced(p, mfa, &ms, &ms_meta, &meta, &count, &call_time); + +#ifdef ERTS_SMP + if ( (key == am_call_time) || (key == am_all)) { + erts_smp_release_system(); + erts_smp_proc_lock(p, ERTS_PROC_LOCK_MAIN); + } +#endif + switch (r) { case FUNC_TRACE_NOEXIST: UnUseTmpHeap(3,p); @@ -1429,6 +1444,7 @@ erts_set_trace_pattern(Eterm* mfa, int specified, erts_clear_trace_break(mfa, specified); erts_clear_mtrace_break(mfa, specified); erts_clear_count_break(mfa, specified); + erts_clear_time_break(mfa, specified); } else { int m = 0; if (flags.local) { @@ -1460,7 +1476,7 @@ erts_set_trace_pattern(Eterm* mfa, int specified, if (flags.call_count) { m = erts_clear_count_break(mfa, specified); } - if (flags.call_count) { + if (flags.call_time) { m = erts_clear_time_break(mfa, specified); } /* All assignments to 'm' above should give the same value, -- cgit v1.2.3 From 5bd5aa849475b505a5b0798295511a6a0b4885a4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Fri, 30 Apr 2010 15:03:56 +0200 Subject: Teach call_time trace to use intruction pointers call_time trace will use instruction pointers instead of breakpoint data pointers. More costly lookup but the bdt structure might be deallocated, we do not want that. Remove unnecessary pattern lock. --- erts/emulator/beam/erl_bif_trace.c | 14 +++++--------- 1 file changed, 5 insertions(+), 9 deletions(-) (limited to 'erts/emulator/beam/erl_bif_trace.c') diff --git a/erts/emulator/beam/erl_bif_trace.c b/erts/emulator/beam/erl_bif_trace.c index 1e626533a4..856669d2c9 100644 --- a/erts/emulator/beam/erl_bif_trace.c +++ b/erts/emulator/beam/erl_bif_trace.c @@ -40,12 +40,11 @@ #define DECL_AM(S) Eterm AM_ ## S = am_atom_put(#S, sizeof(#S) - 1) -static erts_smp_mtx_t trace_pattern_mutex; const struct trace_pattern_flags erts_trace_pattern_flags_off = {0, 0, 0, 0, 0}; static int erts_default_trace_pattern_is_on; static Binary *erts_default_match_spec; static Binary *erts_default_meta_match_spec; -struct trace_pattern_flags erts_default_trace_pattern_flags; +static struct trace_pattern_flags erts_default_trace_pattern_flags; static Eterm erts_default_meta_tracer_pid; static void new_seq_trace_token(Process* p); /* help func for seq_trace_2*/ @@ -65,7 +64,6 @@ static void clear_trace_bif(int bif_index); void erts_bif_trace_init(void) { - erts_smp_mtx_init(&trace_pattern_mutex, "trace_pattern"); erts_default_trace_pattern_is_on = 0; erts_default_match_spec = NULL; erts_default_meta_match_spec = NULL; @@ -203,8 +201,8 @@ trace_pattern_3(Process* p, Eterm MFA, Eterm Pattern, Eterm flaglist) goto error; } - if (match_prog_set && !flags.local && !flags.meta && flags.call_count) { - /* A match prog is not allowed with just call_count */ + if (match_prog_set && !flags.local && !flags.meta && (flags.call_count || flags.call_time)) { + /* A match prog is not allowed with just call_count or call_time*/ goto error; } @@ -350,7 +348,6 @@ erts_get_default_trace_pattern(int *trace_pattern_is_on, struct trace_pattern_flags *trace_pattern_flags, Eterm *meta_tracer_pid) { - erts_smp_mtx_lock(&trace_pattern_mutex); if (trace_pattern_is_on) *trace_pattern_is_on = erts_default_trace_pattern_is_on; if (match_spec) @@ -361,7 +358,6 @@ erts_get_default_trace_pattern(int *trace_pattern_is_on, *trace_pattern_flags = erts_default_trace_pattern_flags; if (meta_tracer_pid) *meta_tracer_pid = erts_default_meta_tracer_pid; - erts_smp_mtx_unlock(&trace_pattern_mutex); } @@ -964,8 +960,8 @@ static int function_is_traced(Process *p, Binary **ms, /* out */ Binary **ms_meta, /* out */ Eterm *tracer_pid_meta, /* out */ - Sint *count, /* out */ - Eterm *call_time) /* out */ + Sint *count, /* out */ + Eterm *call_time) /* out */ { Export e; Export* ep; -- cgit v1.2.3 From b2369c68b33344eb44544c0892cffb8acc658ffa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn-Egil=20Dahlberg?= Date: Tue, 25 May 2010 14:17:07 +0200 Subject: Teach call time trace patterns to include bifs --- erts/emulator/beam/erl_bif_trace.c | 20 +++++++++++++++++--- 1 file changed, 17 insertions(+), 3 deletions(-) (limited to 'erts/emulator/beam/erl_bif_trace.c') diff --git a/erts/emulator/beam/erl_bif_trace.c b/erts/emulator/beam/erl_bif_trace.c index 856669d2c9..443cac9033 100644 --- a/erts/emulator/beam/erl_bif_trace.c +++ b/erts/emulator/beam/erl_bif_trace.c @@ -992,10 +992,13 @@ static int function_is_traced(Process *p, r |= FUNC_TRACE_LOCAL_TRACE; *ms = ep->match_prog_set; } - if (erts_is_mtrace_bif(ep->code+3, ms_meta, + if (erts_is_mtrace_break(ep->code+3, ms_meta, tracer_pid_meta)) { r |= FUNC_TRACE_META_TRACE; } + if (erts_is_time_break(p, ep->code+3, call_time)) { + r |= FUNC_TRACE_TIME_TRACE; + } } return r ? r : FUNC_TRACE_UNTRACED; } @@ -1034,7 +1037,7 @@ trace_info_func(Process* p, Eterm func_spec, Eterm key) Eterm match_spec = am_false; Eterm retval = am_false; Eterm meta = am_false; - Eterm call_time; + Eterm call_time = NIL; int r; @@ -1404,6 +1407,12 @@ erts_set_trace_pattern(Eterm* mfa, int specified, erts_bif_trace_flags[i] &= ~BIF_TRACE_AS_GLOBAL; m = 1; } + if (flags.call_time) { + erts_set_time_trace_bif(bif_export[i]->code + 3, on); + /* I don't want to remove any other tracers */ + erts_bif_trace_flags[i] |= BIF_TRACE_AS_CALL_TIME; + m = 1; + } if (erts_bif_trace_flags[i]) { setup_bif_trace(i); } @@ -1423,6 +1432,11 @@ erts_set_trace_pattern(Eterm* mfa, int specified, } m = 1; } + if (flags.call_time) { + erts_clear_time_trace_bif(bif_export[i]->code + 3); + erts_bif_trace_flags[i] &= ~BIF_TRACE_AS_CALL_TIME; + m = 1; + } if (! erts_bif_trace_flags[i]) { reset_bif_trace(i); } @@ -1591,7 +1605,7 @@ static void reset_bif_trace(int bif_index) { ASSERT(ExportIsBuiltIn(ep)); ASSERT(ep->code[4]); ASSERT(! ep->match_prog_set); - ASSERT(! erts_is_mtrace_bif((BeamInstr *)ep->code+3, NULL, NULL)); + ASSERT(! erts_is_mtrace_break((BeamInstr *)ep->code+3, NULL, NULL)); ep->code[4] = (BeamInstr) bif_table[bif_index].f; } -- cgit v1.2.3