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/beam_bp.c | 190 ++++++++++++++++++++---------------- erts/emulator/beam/beam_bp.h | 29 +----- erts/emulator/beam/beam_emu.c | 49 +++++++--- erts/emulator/beam/erl_bif_trace.c | 14 +-- erts/emulator/beam/erl_lock_check.c | 1 - erts/emulator/beam/erl_process.c | 8 +- erts/emulator/beam/global.h | 2 +- 7 files changed, 153 insertions(+), 140 deletions(-) (limited to 'erts') diff --git a/erts/emulator/beam/beam_bp.c b/erts/emulator/beam/beam_bp.c index 48e7b6675a..3e776fa951 100644 --- a/erts/emulator/beam/beam_bp.c +++ b/erts/emulator/beam/beam_bp.c @@ -549,6 +549,8 @@ static void bp_hash_rehash(bp_time_hash_t *hash, Uint n) { item[ix].pid = NIL; } + /* rehash, old hash -> new hash */ + for( ix = 0; ix < hash->n; ix++) { if (hash->item[ix].pid != NIL) { @@ -654,45 +656,51 @@ void erts_schedule_time_break(Process *p, Uint schedule) { Uint ix = 0; bp_data_time_item_t sitem, *item = NULL; bp_time_hash_t *h = NULL; + BpDataTime *pbdt = NULL; ASSERT(p); pbt = ERTS_PROC_GET_CALL_TIME(p); +#ifdef ERTS_SMP + ix = p->scheduler_data->no - 1; +#else + ix = 0; +#endif +/* ASSERT( (p->status == P_RUNNING) || (p->status == P_WAITING) || (p->status == P_RUNABLE)); - +*/ if (pbt) { get_sys_now(&ms,&s,&us); switch(schedule) { case ERTS_BP_CALL_TIME_SCHEDULE_EXITING : + break; case ERTS_BP_CALL_TIME_SCHEDULE_OUT : /* When a process is scheduled _out_, * timestamp it and add its delta to * the previous breakpoint. */ -#ifdef ERTS_SMP - ix = p->scheduler_data->no - 1; -#else - ix = 0; -#endif - bp_time_diff(&sitem, pbt, ms, s, us); - sitem.pid = p->id; - sitem.count = 1; - /*count is set to 0 if out and 1 if exiting */ + pbdt = (BpDataTime *) is_break(pbt->pc, (Uint) BeamOp(op_i_time_breakpoint)); + if (pbdt) { + bp_time_diff(&sitem, pbt, ms, s, us); + sitem.pid = p->id; + sitem.count = 0; - h = &(pbt->bdt->hash[ix]); + h = &(pbdt->hash[ix]); - ASSERT(h->item); + ASSERT(h); + ASSERT(h->item); - item = bp_hash_get(h, &sitem); - if (!item) { - item = bp_hash_put(h, &sitem); - } else { - BP_TIME_ADD(item, &sitem); + item = bp_hash_get(h, &sitem); + if (!item) { + item = bp_hash_put(h, &sitem); + } else { + BP_TIME_ADD(item, &sitem); + } } break; case ERTS_BP_CALL_TIME_SCHEDULE_IN : @@ -700,21 +708,6 @@ void erts_schedule_time_break(Process *p, Uint schedule) { * timestamp it and remove the previous * timestamp in the psd. */ - sitem.pid = p->id; - sitem.count = -1; - sitem.us_time = 0; - sitem.s_time = 0; - - h = &(pbt->bdt->hash[ix]); - - ASSERT(h->item); - - item = bp_hash_get(h, &sitem); - if (!item) { - item = bp_hash_put(h, &sitem); - } else { - BP_TIME_ADD(item, &sitem); - } pbt->ms = ms; pbt->s = s; pbt->us = us; @@ -748,15 +741,15 @@ void erts_schedule_time_break(Process *p, Uint schedule) { * - egil */ -void erts_do_time_break(Process *p, BpDataTime *bdt, Uint type) { +void erts_trace_time_break(Process *p, BeamInstr *pc, BpDataTime *bdt, Uint type) { Uint ms,s,us; process_breakpoint_time_t *pbt = NULL; int ix = 0; bp_data_time_item_t sitem, *item = NULL; bp_time_hash_t *h = NULL; + BpDataTime *pbdt = NULL; ASSERT(p); - ASSERT(bdt); ASSERT(p->status == P_RUNNING); /* get previous timestamp and breakpoint @@ -765,61 +758,81 @@ void erts_do_time_break(Process *p, BpDataTime *bdt, Uint type) { pbt = ERTS_PROC_GET_CALL_TIME(p); get_sys_now(&ms,&s,&us); +#ifdef ERTS_SMP + ix = p->scheduler_data->no - 1; +#else + ix = 0; +#endif + switch(type) { - case ERTS_BP_CALL_TIME_CALL: /* get pbt * timestamp = t0 + * lookup bdt from code * set ts0 to pbt * add call count here? */ - if (!pbt) { - pbt = Alloc(sizeof(process_breakpoint_time_t)); - (void *) ERTS_PROC_SET_CALL_TIME(p, ERTS_PROC_LOCK_MAIN, pbt); - } - - pbt->bdt = bdt; /* needed for schedule? */ - - pbt->ms = ms; - pbt->s = s; - pbt->us = us; - - - break; + case ERTS_BP_CALL_TIME_CALL: case ERTS_BP_CALL_TIME_TAIL_CALL: - ASSERT(pbt); - -#ifdef ERTS_SMP - ix = p->scheduler_data->no - 1; -#else - ix = 0; -#endif + if (pbt) { + ASSERT(pbt->pc); + /* add time to previous code */ bp_time_diff(&sitem, pbt, ms, s, us); sitem.pid = p->id; - sitem.count = 1; + sitem.count = 0; - h = &(bdt->hash[ix]); + /* previous breakpoint */ + pbdt = (BpDataTime *) is_break(pbt->pc, (Uint) BeamOp(op_i_time_breakpoint)); - ASSERT(h->item); + /* if null then the breakpoint was removed */ + if (pbdt) { + h = &(pbdt->hash[ix]); - item = bp_hash_get(h, &sitem); - if (!item) { - item = bp_hash_put(h, &sitem); - } else { - BP_TIME_ADD(item, &sitem); + ASSERT(h); + ASSERT(h->item); + + item = bp_hash_get(h, &sitem); + if (!item) { + item = bp_hash_put(h, &sitem); + } else { + BP_TIME_ADD(item, &sitem); + } } + } else { + /* first call of process to instrumented function */ + pbt = Alloc(sizeof(process_breakpoint_time_t)); + (void *) ERTS_PROC_SET_CALL_TIME(p, ERTS_PROC_LOCK_MAIN, pbt); + } + /* add count to this code */ + sitem.pid = p->id; + sitem.count = 1; + sitem.s_time = 0; + sitem.us_time = 0; - pbt->bdt = bdt; /* needed for schedule? */ + /* this breakpoint */ + ASSERT(bdt); + h = &(bdt->hash[ix]); - pbt->ms = ms; - pbt->s = s; - pbt->us = us; - break; + ASSERT(h); + ASSERT(h->item); + item = bp_hash_get(h, &sitem); + if (!item) { + item = bp_hash_put(h, &sitem); + } else { + BP_TIME_ADD(item, &sitem); + } + + pbt->pc = pc; + pbt->ms = ms; + pbt->s = s; + pbt->us = us; + break; case ERTS_BP_CALL_TIME_RETURN: /* get pbt + * lookup bdt from code * timestamp = t1 * get ts0 from pbt * get item from bdt->hash[bp_hash(p->id)] @@ -830,30 +843,34 @@ void erts_do_time_break(Process *p, BpDataTime *bdt, Uint type) { /* might have been removed due to * trace_pattern(false) */ -#ifdef ERTS_SMP - ix = p->scheduler_data->no - 1; -#else - ix = 0; -#endif + ASSERT(pbt->pc); + bp_time_diff(&sitem, pbt, ms, s, us); sitem.pid = p->id; - sitem.count = 1; + sitem.count = 0; - h = &(bdt->hash[ix]); + /* previous breakpoint */ + pbdt = (BpDataTime *) is_break(pbt->pc, (Uint) BeamOp(op_i_time_breakpoint)); - ASSERT(h->item); + if (pbdt) { - item = bp_hash_get(h, &sitem); - if (!item) { - item = bp_hash_put(h, &sitem); - } else { - BP_TIME_ADD(item, &sitem); + h = &(pbdt->hash[ix]); + + ASSERT(h); + ASSERT(h->item); + + item = bp_hash_get(h, &sitem); + if (!item) { + item = bp_hash_put(h, &sitem); + } else { + BP_TIME_ADD(item, &sitem); + } } - pbt->bdt = NULL; - pbt->ms = ms; - pbt->s = s; - pbt->us = us; + pbt->pc = pc; + pbt->ms = ms; + pbt->s = s; + pbt->us = us; } break; } @@ -976,7 +993,8 @@ static int set_function_break(Module *modp, BeamInstr *pc, BpDataTime *bdt = (BpDataTime *) bd; Uint i = 0; - /*XXX: must block system */ + ERTS_SMP_LC_ASSERT(erts_smp_is_system_blocked(0)); + if (count_op == erts_break_stop) { bdt->pause = 1; } else { diff --git a/erts/emulator/beam/beam_bp.h b/erts/emulator/beam/beam_bp.h index 515a06e220..249cb707fd 100644 --- a/erts/emulator/beam/beam_bp.h +++ b/erts/emulator/beam/beam_bp.h @@ -101,7 +101,7 @@ typedef struct { Uint ms; Uint s; Uint us; - BpDataTime *bdt; + Uint *pc; } process_breakpoint_time_t; /* used within psd */ extern erts_smp_spinlock_t erts_bp_lock; @@ -137,27 +137,6 @@ do { \ *(instr_result) = bdc->orig_instr; \ } while (0) -#define ErtsTimeBreak(pc,instr_result) \ -do { \ - BpDataTime *bdt = (BpDataTime *) (pc)[-4]; \ - Uint ms,s,u; \ - \ - ASSERT((pc)[-5] == (Uint) BeamOp(op_i_func_info_IaaI)); \ - ASSERT(bdt); \ - bdt = (BpDataTime *) bdt->next; \ - ASSERT(bdc); \ - (pc)[-4] = (Uint) bdt; \ - get_now(&ms,&s,&u); \ - ErtsSmpBPLock(bdt); \ - if (bdt->count >= 0) \ - bdt->count++; \ - bdt->s_time = 1; \ - bdt->us_time = 1; \ - ErtsSmpBPUnlock(bdt); \ - *(instr_result) = bdt->orig_instr; \ -} while (0) - - #define ErtsBreakSkip(pc,instr_result) \ do { \ BpData *bd = (BpData *) (pc)[-4]; \ @@ -198,8 +177,6 @@ int erts_set_debug_break(Eterm mfa[3], int specified); int erts_clear_debug_break(Eterm mfa[3], int specified); int erts_set_count_break(Eterm mfa[3], int specified, enum erts_break_op); int erts_clear_count_break(Eterm mfa[3], int specified); -int erts_set_time_break(Eterm mfa[3], int specified, enum erts_break_op); -int erts_clear_time_break(Eterm mfa[3], int specified); int erts_clear_break(Eterm mfa[3], int specified); @@ -221,8 +198,10 @@ int erts_is_native_break(BeamInstr *pc); int erts_is_count_break(BeamInstr *pc, Sint *count_ret); int erts_is_time_break(Process *p, BeamInstr *pc, Eterm *call_time); -void erts_do_time_break(Process *p, BpDataTime *bdt, Uint type); +void erts_trace_time_break(Process *p, BeamInstr *pc, BpDataTime *bdt, Uint type); void erts_schedule_time_break(Process *p, Uint out); +int erts_set_time_break(Eterm mfa[3], int specified, enum erts_break_op); +int erts_clear_time_break(Eterm mfa[3], int specified); BeamInstr *erts_find_local_func(Eterm mfa[3]); diff --git a/erts/emulator/beam/beam_emu.c b/erts/emulator/beam/beam_emu.c index 8661d7cbf5..8eb198fac3 100644 --- a/erts/emulator/beam/beam_emu.c +++ b/erts/emulator/beam/beam_emu.c @@ -231,7 +231,7 @@ BeamInstr* em_call_traced_function; BeamInstr beam_return_to_trace[1]; /* OpCode(i_return_to_trace) */ BeamInstr beam_return_trace[1]; /* OpCode(i_return_trace) */ BeamInstr beam_exception_trace[1]; /* UGLY also OpCode(i_return_trace) */ -BeamInstr beam_time_return_trace[1]; /* OpCode(i_time_return_trace) */ +BeamInstr beam_return_time_trace[1]; /* OpCode(i_time_return_trace) */ /* * All Beam instructions in numerical order. @@ -4409,6 +4409,10 @@ apply_bif_or_nif_epilogue: Goto(real_I); } + /* need to send mfa instead of bdt pointer + * the pointer might be deallocated. + */ + OpCase(i_time_breakpoint): { BeamInstr real_I; BpDataTime *bdt = (BpDataTime *) (I)[-4]; @@ -4423,43 +4427,48 @@ apply_bif_or_nif_epilogue: ASSERT(VALID_INSTR(real_I)); if (IS_TRACED_FL(c_p, F_TRACE_CALLS) && !(bdt->pause)) { - if (*cp_val((Eterm)c_p->cp) == (BeamInstr) OpCode(i_time_return_trace)) { + if (*cp_val((Eterm)c_p->cp) == (BeamInstr) OpCode(i_return_time_trace)) { tail_call = 1; } if (tail_call) { /* This _IS_ a tail recursive call */ SWAPOUT; - erts_do_time_break(c_p, bdt, ERTS_BP_CALL_TIME_TAIL_CALL); + erts_trace_time_break(c_p, I, bdt, ERTS_BP_CALL_TIME_TAIL_CALL); SWAPIN; } else { SWAPOUT; - erts_do_time_break(c_p, bdt, ERTS_BP_CALL_TIME_CALL); + erts_trace_time_break(c_p, I, bdt, ERTS_BP_CALL_TIME_CALL); + /* r register needs to be copied to the array + * for the garbage collector + */ ASSERT(c_p->htop <= E && E <= c_p->hend); if (E - 2 < HTOP) { + reg[0] = r(0); PROCESS_MAIN_CHK_LOCKS(c_p); FCALLS -= erts_garbage_collect(c_p, 2, reg, I[-1]); PROCESS_MAIN_CHK_LOCKS(c_p); + r(0) = reg[0]; } SWAPIN; ASSERT(c_p->htop <= E && E <= c_p->hend); E -= 2; + E[0] = make_cp(I); E[1] = make_cp(c_p->cp); /* original return address */ - E[0] = make_cp((Uint *)bdt); /* make sure bdt is allocated in low mem (for halfword) */ - c_p->cp = (Eterm *) make_cp(beam_time_return_trace); + c_p->cp = (Eterm *) make_cp(beam_return_time_trace); } } Goto(real_I); } - OpCase(i_time_return_trace): { - BpDataTime *bdt = (BpDataTime *) cp_val((E)[0]); + OpCase(i_return_time_trace): { + Uint *pc = (Uint *) E[0]; SWAPOUT; - erts_do_time_break(c_p, bdt, ERTS_BP_CALL_TIME_RETURN); + erts_trace_time_break(c_p, pc, NULL, ERTS_BP_CALL_TIME_RETURN); SWAPIN; c_p->cp = NULL; SET_I((Eterm *) E[1]); @@ -5024,7 +5033,7 @@ apply_bif_or_nif_epilogue: beam_return_to_trace[0] = (BeamInstr) OpCode(i_return_to_trace); beam_return_trace[0] = (BeamInstr) OpCode(return_trace); beam_exception_trace[0] = (BeamInstr) OpCode(return_trace); /* UGLY */ - beam_time_return_trace[0] = (BeamInstr) OpCode(i_time_return_trace); + beam_return_time_trace[0] = (BeamInstr) OpCode(i_return_time_trace); /* * Enter all BIFs into the export table. @@ -5228,14 +5237,18 @@ next_catch(Process* c_p, Eterm *reg) { int active_catches = c_p->catches > 0; int have_return_to_trace = 0; Eterm *ptr, *prev, *return_to_trace_ptr = NULL; - BeamInstr i_return_trace = beam_return_trace[0]; - BeamInstr i_return_to_trace = beam_return_to_trace[0]; + + BeamInstr i_return_trace = beam_return_trace[0]; + BeamInstr i_return_to_trace = beam_return_to_trace[0]; + BeamInstr i_return_time_trace = beam_return_time_trace[0]; + ptr = prev = c_p->stop; ASSERT(is_CP(*ptr)); ASSERT(ptr <= STACK_START(c_p)); if (ptr == STACK_START(c_p)) return NULL; if ((is_not_CP(*ptr) || (*cp_val(*ptr) != i_return_trace && - *cp_val(*ptr) != i_return_to_trace)) + *cp_val(*ptr) != i_return_to_trace && + *cp_val(*ptr) != i_return_time_trace )) && c_p->cp) { /* Can not follow cp here - code may be unloaded */ BeamInstr *cpp = c_p->cp; @@ -5247,6 +5260,9 @@ next_catch(Process* c_p, Eterm *reg) { } else if (cpp == beam_return_trace) { /* Skip return_trace parameters */ ptr += 2; + } else if (cpp == beam_return_time_trace) { + /* Skip return_trace parameters */ + ptr += 1; } else if (cpp == beam_return_to_trace) { have_return_to_trace = !0; /* Record next cp */ } @@ -5276,6 +5292,13 @@ next_catch(Process* c_p, Eterm *reg) { } have_return_to_trace = !0; /* Record next cp */ return_to_trace_ptr = NULL; + } else if (*cp_val(*prev) == i_return_time_trace) { + /* Skip stack frame variables */ + while (++ptr, ptr < STACK_START(c_p) && is_not_CP(*ptr)) { + if (is_catch(*ptr) && active_catches) goto found_catch; + } + /* Skip return_trace parameters */ + ptr += 1; } else { if (have_return_to_trace) { /* Record this cp as possible return_to trace cp */ 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; diff --git a/erts/emulator/beam/erl_lock_check.c b/erts/emulator/beam/erl_lock_check.c index 6ff5c1b9da..cee470ae37 100644 --- a/erts/emulator/beam/erl_lock_check.c +++ b/erts/emulator/beam/erl_lock_check.c @@ -105,7 +105,6 @@ static erts_lc_lock_order_t erts_lock_order[] = { { "node_table", NULL }, { "dist_table", NULL }, { "sys_tracers", NULL }, - { "trace_pattern", NULL }, { "module_tab", NULL }, { "export_tab", NULL }, { "fun_tab", NULL }, diff --git a/erts/emulator/beam/erl_process.c b/erts/emulator/beam/erl_process.c index 5293fabe87..f4c889889d 100644 --- a/erts/emulator/beam/erl_process.c +++ b/erts/emulator/beam/erl_process.c @@ -5878,9 +5878,7 @@ Process *schedule(Process *p, int calls) } if (IS_TRACED(p)) { - if (IS_TRACED_FL(p, F_TRACE_CALLS) && - erts_default_trace_pattern_flags.call_time && - p->status != P_FREE) { + if (IS_TRACED_FL(p, F_TRACE_CALLS) && p->status != P_FREE) { erts_schedule_time_break(p, ERTS_BP_CALL_TIME_SCHEDULE_OUT); } switch (p->status) { @@ -6319,7 +6317,7 @@ Process *schedule(Process *p, int calls) trace_virtual_sched(p, am_in); break; } - if (IS_TRACED_FL(p, F_TRACE_CALLS) && erts_default_trace_pattern_flags.call_time) { + if (IS_TRACED_FL(p, F_TRACE_CALLS)) { erts_schedule_time_break(p, ERTS_BP_CALL_TIME_SCHEDULE_IN); } } @@ -8067,7 +8065,7 @@ erts_do_exit_process(Process* p, Eterm reason) #endif if (IS_TRACED(p)) { - if (IS_TRACED_FL(p, F_TRACE_CALLS) && erts_default_trace_pattern_flags.call_time) + if (IS_TRACED_FL(p, F_TRACE_CALLS)) erts_schedule_time_break(p, ERTS_BP_CALL_TIME_SCHEDULE_EXITING); if (IS_TRACED_FL(p,F_TRACE_PROCS)) diff --git a/erts/emulator/beam/global.h b/erts/emulator/beam/global.h index 8d087fd7d6..b042f14a7b 100644 --- a/erts/emulator/beam/global.h +++ b/erts/emulator/beam/global.h @@ -1744,7 +1744,7 @@ struct trace_pattern_flags { unsigned int call_time : 1; /* Fast call time breakpoint */ }; extern const struct trace_pattern_flags erts_trace_pattern_flags_off; -extern struct trace_pattern_flags erts_default_trace_pattern_flags; /* used with blocksystem */ +extern int erts_call_time_breakpoint_tracing; int erts_set_trace_pattern(Eterm* mfa, int specified, Binary* match_prog_set, Binary *meta_match_prog_set, int on, struct trace_pattern_flags, -- cgit v1.2.3