From 007311472388608510c3cba0600932e8bb92945a Mon Sep 17 00:00:00 2001 From: Abdelrahman Said Date: Sun, 9 Jul 2023 00:55:22 +0100 Subject: [PATCH] Refactor profiling code --- haversine_02/include/profiler/timer.h | 12 ++ haversine_02/src/processor/main.cpp | 179 ++++++++++---------------- haversine_02/src/profiler/timer.c | 80 ++++++++++++ 3 files changed, 162 insertions(+), 109 deletions(-) diff --git a/haversine_02/include/profiler/timer.h b/haversine_02/include/profiler/timer.h index 93face6..0806e24 100644 --- a/haversine_02/include/profiler/timer.h +++ b/haversine_02/include/profiler/timer.h @@ -3,6 +3,13 @@ #include "aliases.h" +// TODO (Abdelrahman): Not fully satisfied with this solution +#define PROFILER_SAMPLE(ID, TITLE, CODE) \ + u64 ID##_start = read_cpu_timer(); \ + CODE; \ + u64 ID##_end = read_cpu_timer(); \ + add_sample(TITLE, ID##_end - ID##_start); + #ifdef __cplusplus extern "C" { #endif @@ -18,6 +25,11 @@ u64 read_cpu_timer(void); // CPU frequency in hz/sec u64 get_cpu_freq(u64 milliseconds); +void profile_start(); +void profile_end(); + +void add_sample(const char *title, u64 duration); + #ifdef __cplusplus } #endif diff --git a/haversine_02/src/processor/main.cpp b/haversine_02/src/processor/main.cpp index 9ae0e9c..95d2a31 100644 --- a/haversine_02/src/processor/main.cpp +++ b/haversine_02/src/processor/main.cpp @@ -14,137 +14,98 @@ #include int main(int argc, char *argv[]) { - u64 cpu_freq = get_cpu_freq(500); + profile_start(); - u64 cli_parse_start = read_cpu_timer(); + // clang-format off + PROFILER_SAMPLE(cli_parse, "CLI PARSING", + ProcessorArgs args = parse_args(argc, argv); + ); - ProcessorArgs args = parse_args(argc, argv); + PROFILER_SAMPLE(json_parse, "JSON PARSING", + jentity_t *root = load_json(args.filepath); - u64 json_parse_start = read_cpu_timer(); + assert(root->type == JENTITY_SINGLE && root->value.type == JVAL_COLLECTION); + ); - jentity_t *root = load_json(args.filepath); + PROFILER_SAMPLE(load_pairs_json, "LOAD JSON PAIRS", + jentity_t *pairs = root->value.collection->begin; - assert(root->type == JENTITY_SINGLE && root->value.type == JVAL_COLLECTION); + assert(pairs->type == JENTITY_PAIR && + pairs->pair.value.type == JVAL_COLLECTION); - u64 load_pairs_json_start = read_cpu_timer(); + u64 pair_count = pairs->pair.value.collection->size; - jentity_t *pairs = root->value.collection->begin; + PointPair *point_pairs = (PointPair *)malloc(sizeof(PointPair) * pair_count); + memset(point_pairs, 0, pair_count); - assert(pairs->type == JENTITY_PAIR && - pairs->pair.value.type == JVAL_COLLECTION); + u64 index = 0; - u64 pair_count = pairs->pair.value.collection->size; + for (jentity_t *pair = pairs->pair.value.collection->begin; pair != NULL; + pair = pair->next) { + assert(index < pair_count && pair->type == JENTITY_SINGLE && + pair->value.type == JVAL_COLLECTION && + pair->value.collection->size == 4); - PointPair *point_pairs = (PointPair *)malloc(sizeof(PointPair) * pair_count); - memset(point_pairs, 0, pair_count); + jentity_t *x0 = pair->value.collection->begin; + jentity_t *y0 = x0->next; + jentity_t *x1 = y0->next; + jentity_t *y1 = x1->next; - u64 index = 0; + PointPair p = ((PointPair){ + {x0->pair.value.num_dbl, y0->pair.value.num_dbl}, + {x1->pair.value.num_dbl, y1->pair.value.num_dbl}, + }); - for (jentity_t *pair = pairs->pair.value.collection->begin; pair != NULL; - pair = pair->next) { - assert(index < pair_count && pair->type == JENTITY_SINGLE && - pair->value.type == JVAL_COLLECTION && - pair->value.collection->size == 4); + point_pairs[index++] = p; + } + ); - jentity_t *x0 = pair->value.collection->begin; - jentity_t *y0 = x0->next; - jentity_t *x1 = y0->next; - jentity_t *y1 = x1->next; + PROFILER_SAMPLE(binary_file_read, "BINARY READ", + const char *filename = "count_and_distances"; - PointPair p = { - {x0->pair.value.num_dbl, y0->pair.value.num_dbl}, - {x1->pair.value.num_dbl, y1->pair.value.num_dbl}, - }; + FILE *fp = fopen(filename, "r"); + if (!fp) { + printf("Failed to open the %s file", filename); + } else { + // Skip the count + fseek(fp, sizeof(u64), SEEK_SET); + } + ); - point_pairs[index++] = p; - } + PROFILER_SAMPLE(haversine_sum, "HAVERSINE SUM", + f64 sum = 0.0; + f64 distance = 0.0; + f64 saved_distance = 0.0; + for (u64 i = 0; i < pair_count; ++i) { + distance = haversine_of_degrees(point_pairs[i], EARTH_RADIUS_KM); - u64 binary_file_read_start = read_cpu_timer(); + if (fp) { + fread(&saved_distance, sizeof(f64), 1, fp); - const char *filename = "count_and_distances"; + if (fabs(distance - saved_distance) > FLT_EPSILON) { + printf("%llu: %.16f does not equal %.16f\n", (unsigned long long)i, + distance, saved_distance); + } + } - FILE *fp = fopen(filename, "r"); - if (!fp) { - printf("Failed to open the %s file", filename); - } else { - // Skip the count - fseek(fp, sizeof(u64), SEEK_SET); - } + sum += distance; + } + ); - u64 haversine_sum_start = read_cpu_timer(); + PROFILER_SAMPLE(haversine_average, "HAVERSINE AVERAGE", + printf("\nAVERAGE DISTANCE: %f\n", sum / pair_count); + ); - f64 sum = 0.0; - f64 distance = 0.0; - f64 saved_distance = 0.0; - for (u64 i = 0; i < pair_count; ++i) { - distance = haversine_of_degrees(point_pairs[i], EARTH_RADIUS_KM); + PROFILER_SAMPLE(tear_down, "TEAR DOWN", + if (fp) { + fclose(fp); + } - if (fp) { - fread(&saved_distance, sizeof(f64), 1, fp); + free(point_pairs); + ); - if (fabs(distance - saved_distance) > FLT_EPSILON) { - printf("%llu: %.16f does not equal %.16f\n", (unsigned long long)i, - distance, saved_distance); - } - } - - sum += distance; - } - - u64 haversine_average_start = read_cpu_timer(); - - printf("\nAVERAGE DISTANCE: %f\n", sum / pair_count); - - u64 tear_down_start = read_cpu_timer(); - - if (fp) { - fclose(fp); - } - - free(point_pairs); - - u64 end = read_cpu_timer(); - - if (cpu_freq) { - u16 time_precision = 16; - u16 time_char_count = 20; - u16 percentage_precision = 8; - u16 percentage_char_count = 12; - - f64 total = (f64)end - (f64)cli_parse_start; - f64 cli_parse = (f64)json_parse_start - (f64)cli_parse_start; - f64 json_parse = (f64)load_pairs_json_start - (f64)json_parse_start; - f64 json_load = (f64)binary_file_read_start - (f64)load_pairs_json_start; - f64 binary_open = (f64)haversine_sum_start - (f64)binary_file_read_start; - f64 haversine_sum = (f64)haversine_average_start - (f64)haversine_sum_start; - f64 haversine_average = (f64)tear_down_start - (f64)haversine_average_start; - f64 tear_down = (f64)end - (f64)tear_down_start; - - printf("\n==========================PROFILING==========================\n"); - printf("Total: %*.*f seconds (CPU frequency: %llu)\n\n", time_char_count, - time_precision, total / cpu_freq, (unsigned long long)cpu_freq); - printf(" CLI PARSING: %*.*f seconds (%*.*f %%)\n", time_char_count, - time_precision, cli_parse / cpu_freq, percentage_char_count, - percentage_precision, cli_parse / total * 100.0); - printf(" JSON PARSING: %*.*f seconds (%*.*f %%)\n", time_char_count, - time_precision, json_parse / cpu_freq, percentage_char_count, - percentage_precision, json_parse / total * 100.0); - printf(" JSON LOADING: %*.*f seconds (%*.*f %%)\n", time_char_count, - time_precision, json_load / cpu_freq, percentage_char_count, - percentage_precision, json_load / total * 100.0); - printf(" BINARY OPEN: %*.*f seconds (%*.*f %%)\n", time_char_count, - time_precision, binary_open / cpu_freq, percentage_char_count, - percentage_precision, binary_open / total * 100.0); - printf("HAVERSINE SUM: %*.*f seconds (%*.*f %%)\n", time_char_count, - time_precision, haversine_sum / cpu_freq, percentage_char_count, - percentage_precision, haversine_sum / total * 100.0); - printf("HAVERSINE AVG: %*.*f seconds (%*.*f %%)\n", time_char_count, - time_precision, haversine_average / cpu_freq, percentage_char_count, - percentage_precision, haversine_average / total * 100.0); - printf(" TEARDOWN: %*.*f seconds (%*.*f %%)\n", time_char_count, - time_precision, tear_down / cpu_freq, percentage_char_count, - percentage_precision, tear_down / total * 100.0); - } + profile_end(); + // clang-format on return 0; } diff --git a/haversine_02/src/profiler/timer.c b/haversine_02/src/profiler/timer.c index f4a8880..7097c48 100644 --- a/haversine_02/src/profiler/timer.c +++ b/haversine_02/src/profiler/timer.c @@ -1,9 +1,29 @@ #include "profiler/timer.h" #include "aliases.h" +#include +#include #include #include +#define MAX_PROFILE_SAMPLES 1024 + +typedef struct { + const char *title; + u64 duration; +} profiler_sample_t; + +typedef struct { + profiler_sample_t samples[MAX_PROFILE_SAMPLES]; + u64 cpu_freq; + u64 size; + u64 start; + u64 end; + u64 max_title_length; +} profiler_t; + +INTERNAL profiler_t profiler = {0}; + typedef struct timespec timespec_t; u64 get_os_frequency() { return 1000000000; } @@ -44,3 +64,63 @@ u64 get_cpu_freq(u64 milliseconds) { return cpu_freq; } + +void profile_start() { + profiler.cpu_freq = get_cpu_freq(500); + profiler.start = read_cpu_timer(); + profiler.max_title_length = 0; +} + +void profile_end() { + if (!profiler.start || !profiler.size) { + return; + } + + profiler.end = read_cpu_timer(); + + u64 total = profiler.end - profiler.start; + + u16 time_precision = 16; + u16 time_char_count = 20; + u16 duration_char_count = 22; + u16 percentage_precision = 8; + u16 percentage_char_count = 12; + + // clang-format off + printf("\n==============================PROFILING==============================\n"); + // clang-format on + + if (profiler.cpu_freq) { + printf("Total: %*.*f seconds (CPU frequency: %llu hz/sec)\n\n", + time_char_count, time_precision, (f64)total / profiler.cpu_freq, + (unsigned long long)profiler.cpu_freq); + } + + profiler_sample_t *sample = NULL; + + for (u64 i = 0; i < profiler.size; ++i) { + sample = &(profiler.samples[i]); + + printf("%*s: %*lld (%*.*f %%)\n", (i32)profiler.max_title_length, + sample->title, duration_char_count, + (unsigned long long)sample->duration, percentage_char_count, + percentage_precision, (f64)sample->duration / total * 100.0); + } +} + +void add_sample(const char *title, u64 duration) { + if (profiler.size == MAX_PROFILE_SAMPLES) { + return; + } + + u64 length = strlen(title); + + if (length > profiler.max_title_length) { + profiler.max_title_length = length; + } + + profiler.samples[(profiler.size)++] = (profiler_sample_t){ + .title = title, + .duration = duration, + }; +}