Refactor profiling code

This commit is contained in:
Abdelrahman Said 2023-07-09 00:55:22 +01:00
parent 2e9c2dc6d5
commit 0073114723
3 changed files with 162 additions and 109 deletions

View File

@ -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

View File

@ -14,137 +14,98 @@
#include <string.h>
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;
}

View File

@ -1,9 +1,29 @@
#include "profiler/timer.h"
#include "aliases.h"
#include <stdio.h>
#include <string.h>
#include <time.h>
#include <x86intrin.h>
#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,
};
}