# HG changeset patch # User Mike Pavone # Date 1286952716 14400 # Node ID 60906f8803efb40b838e272f3adeaf900283ecfa # Parent 04148770c229b0eb5be6edf6ce67ab345d5b36ff Improved profiling diff -r 04148770c229 -r 60906f8803ef cbackend.rhope --- a/cbackend.rhope Wed Oct 13 01:18:53 2010 +0000 +++ b/cbackend.rhope Wed Oct 13 02:51:56 2010 -0400 @@ -1484,8 +1484,10 @@ ]Append["\n #ifdef ENABLE_PROFILING uint64_t profile_counts[END]; +uint64_t profile_nestedcounts[END]; uint64_t profile_totals[END]; uint64_t profile_selftotals[END]; +uint64_t profile_activationlevel[END]; #endif int32_t rhope(uint32_t func, object ** params, uint16_t numparams, uint16_t callspace) @@ -1613,7 +1615,7 @@ for (idx = 0; idx < END; ++idx) { if(profile_counts[idx]) - printf(\"Func: %d\tCount: %llu\tTime: %llu\tAvg: %f\tSelf: %llu\tAvg: %f\\n\", idx, profile_counts[idx], profile_totals[idx], ((double)profile_totals[idx])/((double)profile_counts[idx]), profile_selftotals[idx], ((double)profile_selftotals[idx])/((double)profile_counts[idx])); + printf(\"Func: %d\tCount: %llu\tTime: %llu\tAvg: %f\tSelf: %llu\tAvg: %f\tNested Count: %llu\\n\", idx, profile_counts[idx], profile_totals[idx], ((double)profile_totals[idx])/((double)profile_counts[idx]), profile_selftotals[idx], ((double)profile_selftotals[idx])/((double)profile_counts[idx]), profile_nestedcounts[idx]); } #endif if (!numret) diff -r 04148770c229 -r 60906f8803ef procprofile.py --- a/procprofile.py Wed Oct 13 01:18:53 2010 +0000 +++ b/procprofile.py Wed Oct 13 02:51:56 2010 -0400 @@ -27,15 +27,16 @@ count,_,rest = rest.partition('\tTime: ') total,_,rest = rest.partition('\tAvg: ') avg,_,rest = rest.partition('\tSelf: ') - self,_,selfavg = rest.partition('\tAvg: ') - records.append((names[int(funcid)], int(count), int(total), float(avg), int(self), float(selfavg))) + self,_,rest = rest.partition('\tAvg: ') + selfavg,_,nestcount = rest.partition('\tNested Count: ') + records.append((names[int(funcid)], int(count), int(total), float(avg), int(self), float(selfavg), int(nestcount))) records.sort(key=lambda el: el[3]) print 'Func\tCount\tTotal(us)\tAvg(us)\tSelf(us)\tSelf Avg(us)' for record in records: - print '%s\t%d\t%d\t%f\t%d\t%f' % record + print '%s\t%d\t%d\t%f\t%d\t%f\t%d' % record diff -r 04148770c229 -r 60906f8803ef runtime/func.h --- a/runtime/func.h Wed Oct 13 01:18:53 2010 +0000 +++ b/runtime/func.h Wed Oct 13 02:51:56 2010 -0400 @@ -45,57 +45,42 @@ my_cdata->self_accum += ((uint64_t)time.tv_sec) * 1000000ULL + ((uint64_t)time.tv_usec) - my_cdata->self_start; #define AND_TOTAL \ + *(my_cdata->myactivationlevel)--;\ my_cdata->accum += ((uint64_t)time.tv_sec) * 1000000ULL + ((uint64_t)time.tv_usec) - my_cdata->start; #define RESUME_SELF \ gettimeofday(&time, NULL);\ my_cdata->self_start = ((uint64_t)time.tv_sec) * 1000000ULL + ((uint64_t)time.tv_usec); -#define AND_RESUME_TOTAL my_cdata->start = my_cdata->self_start; +#define AND_RESUME_TOTAL \ + *(my_cdata->myactivationlevel)++;\ + my_cdata->start = my_cdata->self_start; #define EndFunc(name) \ free_stack(ct, lv_ ## name);\ func = cdata->func;\ + profile_activationlevel[FUNC_ ## name]--;\ gettimeofday(&time, NULL);\ - profile_counts[FUNC_ ## name]++;\ - profile_totals[FUNC_ ## name] += ((uint64_t)time.tv_sec) * 1000000ULL + ((uint64_t)time.tv_usec) - cdata->start + cdata->accum;\ + if(profile_activationlevel[FUNC_ ## name])\ + {\ + profile_nestedcounts[FUNC_ ## name]++;\ + } else {\ + profile_counts[FUNC_ ## name]++;\ + profile_totals[FUNC_ ## name] += ((uint64_t)time.tv_sec) * 1000000ULL + ((uint64_t)time.tv_usec) - cdata->start + cdata->accum;\ + }\ profile_selftotals[FUNC_ ## name] += ((uint64_t)time.tv_sec) * 1000000ULL + ((uint64_t)time.tv_usec) - cdata->self_start + cdata->self_accum; - -#else - -#define START_PROFILE -#define PAUSE_SELF -#define RESUME_SELF -#define AND_TOTAL -#define AND_RESUME_TOTAL - -#define EndFunc(name) \ - free_stack(ct, lv_ ## name);\ - func = cdata->func; - - -#endif - -#define EndFuncNoLocals \ - func = cdata->func; - + #define Func(name,numparams) \ f_ ## name:\ for(idx = numparams; idx < cdata->num_params; ++idx)\ release_ref(cdata->params[idx]); cdata->num_params = numparams;\ sf_ ## name:\ + profile_activationlevel[FUNC_ ## name]++;\ + cdata->myactivationlevel = &profile_activationlevel[FUNC_ ## name];\ START_PROFILE\ lv_ ## name = alloc_stack(ct, sizeof(lt_ ## name));\ my_cdata = cdata; - -#define FuncNoLocals(name,numparams) \ -f_ ## name:\ - for(idx = numparams; idx < cdata->num_params; ++idx)\ - release_ref(cdata->params[idx]); cdata->num_params = numparams;\ -sf_ ## name:\ - my_cdata = cdata; - #define MethodImpl(name,type_name,mytype_id,numparams) \ f_ ## name ## AT_ ## type_name:\ sf_ ## name ## AT_ ## type_name:\ @@ -111,11 +96,66 @@ exit(1);\ }\ m_ ## name ## AT_ ## type_name:\ + profile_activationlevel[FUNC_ ## name ## AT_ ## type_name]++;\ + cdata->myactivationlevel = &profile_activationlevel[FUNC_ ## name ## AT_ ## type_name];\ START_PROFILE\ for(idx = numparams; idx < cdata->num_params; ++idx)\ release_ref(cdata->params[idx]); cdata->num_params = numparams;\ lv_ ## name ## AT_ ## type_name = alloc_stack(ct, sizeof(lt_ ## name ## AT_ ## type_name));\ my_cdata = cdata; + +#else + +#define START_PROFILE +#define PAUSE_SELF +#define RESUME_SELF +#define AND_TOTAL +#define AND_RESUME_TOTAL + +#define EndFunc(name) \ + free_stack(ct, lv_ ## name);\ + func = cdata->func; + +#define Func(name,numparams) \ +f_ ## name:\ + for(idx = numparams; idx < cdata->num_params; ++idx)\ + release_ref(cdata->params[idx]); cdata->num_params = numparams;\ +sf_ ## name:\ + lv_ ## name = alloc_stack(ct, sizeof(lt_ ## name));\ + my_cdata = cdata; + +#define MethodImpl(name,type_name,mytype_id,numparams) \ +f_ ## name ## AT_ ## type_name:\ +sf_ ## name ## AT_ ## type_name:\ + if (cdata->num_params < 1)\ + {\ + cdata = alloc_cdata(ct, cdata, 0);\ + cdata->func = FUNC_ ## name ## AT_ ## type_name;\ + goto _exception;\ + }\ + if(get_blueprint(cdata->params[0])->type_id != mytype_id)\ + {\ + puts("uh oh, need conversion and that's not implemented yet!");\ + exit(1);\ + }\ +m_ ## name ## AT_ ## type_name:\ + for(idx = numparams; idx < cdata->num_params; ++idx)\ + release_ref(cdata->params[idx]); cdata->num_params = numparams;\ + lv_ ## name ## AT_ ## type_name = alloc_stack(ct, sizeof(lt_ ## name ## AT_ ## type_name));\ + my_cdata = cdata; + +#endif + +#define EndFuncNoLocals \ + func = cdata->func; + + +#define FuncNoLocals(name,numparams) \ +f_ ## name:\ + for(idx = numparams; idx < cdata->num_params; ++idx)\ + release_ref(cdata->params[idx]); cdata->num_params = numparams;\ +sf_ ## name:\ + my_cdata = cdata; #define MethodImplNoLocals(name,type_name,mytype_id,numparams) \ diff -r 04148770c229 -r 60906f8803ef runtime/object.h --- a/runtime/object.h Wed Oct 13 01:18:53 2010 +0000 +++ b/runtime/object.h Wed Oct 13 02:51:56 2010 -0400 @@ -50,6 +50,7 @@ uint64_t accum; uint64_t self_start; uint64_t self_accum; + uint64_t *myactivationlevel; #endif uint32_t func; uint16_t num_params;