diff --git a/haversine_02/include/profiler/timer.h b/haversine_02/include/profiler/timer.h index 6a4cef0..549b02b 100644 --- a/haversine_02/include/profiler/timer.h +++ b/haversine_02/include/profiler/timer.h @@ -27,9 +27,10 @@ typedef struct sample profiler_sample_t; struct sample { const char *title; + u64 first_start; u64 start; - u64 duration; - u64 children_duration; + u64 exclusive_time; + u64 children_time; u64 hit_count; profiler_sample_t *parent; }; diff --git a/haversine_02/src/profiler/timer.c b/haversine_02/src/profiler/timer.c index af26a0f..7889c9e 100644 --- a/haversine_02/src/profiler/timer.c +++ b/haversine_02/src/profiler/timer.c @@ -1,5 +1,6 @@ #include "profiler/timer.h" #include "aliases.h" +#include #include #include #include @@ -105,21 +106,17 @@ void profile_end() { continue; } - u64 duration = 0; - - if (sample->duration >= sample->children_duration) { - duration = sample->duration - sample->children_duration; - } - printf("%*s (hits: %*lld): %*lld (%*.*f %%", (i32)profiler.max_title_length, sample->title, hits_char_count, (unsigned long long)sample->hit_count, duration_char_count, - (unsigned long long)duration, percentage_char_count, - percentage_precision, (f64)duration / total * 100.0); + (unsigned long long)sample->exclusive_time, percentage_char_count, + percentage_precision, (f64)(sample->exclusive_time) / total * 100.0); - if (sample->children_duration > 0) { + if (sample->children_time > 0) { printf(", w/ children: %*.*f %%", percentage_char_count, - percentage_precision, (f64)sample->duration / total * 100.0); + percentage_precision, + (f64)(sample->exclusive_time + sample->children_time) / total * + 100.0); } printf(")\n"); @@ -135,9 +132,10 @@ void sample_start(u64 id, const char *title) { if (!(sample->title) || strcmp(title, sample->title) != 0) { sample->title = title; + sample->first_start = 0; sample->start = 0; - sample->duration = 0; - sample->children_duration = 0; + sample->exclusive_time = 0; + sample->children_time = 0; sample->hit_count = 0; sample->parent = NULL; @@ -149,9 +147,20 @@ void sample_start(u64 id, const char *title) { } sample->start = read_cpu_timer(); + + if (sample->hit_count == 0) { + sample->first_start = sample->start; + } + ++(sample->hit_count); - if (sample != profiler.active) { + if (profiler.active) { + u64 duration = sample->start - (profiler.active->start); + + profiler.active->exclusive_time += duration; + } + + if (!(profiler.active) || sample != profiler.active) { // This handles recursive functions by changing the parent only when a // function isn't calling itself sample->parent = profiler.active; @@ -169,16 +178,24 @@ void sample_end(u64 id) { u64 duration = read_cpu_timer() - sample->start; - if (!(sample->parent) || sample != sample->parent) { - // This handles recursive functions by adding to the duration only when a - // function isn't calling itself - sample->duration += duration; - } + sample->exclusive_time += duration; - if (sample->parent && sample != sample->parent) { - // This handles recursive functions by adding to the children_duration only - // when a function isn't calling itself - sample->parent->children_duration += duration; + u64 now = read_cpu_timer(); + + // Reset the start time at the end of the sample to handle recursion + sample->start = now; + + profiler_sample_t *parent = sample->parent; + + if (parent) { + sample->parent->start = now; + + // Add sample duration to all parents. This handles deep call stacks + while (parent) { + parent->children_time += duration; + + parent = parent->parent; + } } profiler.active = sample->parent;