Use profiling functions to time the haversine processor

haversine_02/compile

@@ -10,6 +10,10 @@ else
 	CFLAGS+="-g"
 fi
 
+# profiler
+PROFSRC="./src/profiler/timer.c"
+PROFFLAGS="-c"
+
 # generator
 GENSRC="./src/generator/gen_argparser.cpp ./src/generator/generator.cpp ./src/haversine.cpp ./src/point_types.cpp ./src/generator/main.cpp"
 GENOUT=genhavr
@@ -22,6 +26,7 @@ JSONFLAGS="-c"
 PROCSRC="./*.o ./src/haversine.cpp ./src/point_types.cpp ./src/processor/proc_argparser.cpp ./src/processor/main.cpp"
 PROCOUT=prochavr
 
+(set -x ; $CC $CFLAGS $PROFFLAGS $PROFSRC)
 (set -x ; $CC $CFLAGS $JSONFLAGS $JSONSRC)
 (set -x ; $CXX $CFLAGS $PROCSRC -o $PROCOUT)
 

haversine_02/include/profiler/timer.h

@@ -0,0 +1,25 @@
+#ifndef TIMER_H
+#define TIMER_H
+
+#include "aliases.h"
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+u64 get_os_frequency();
+
+// Time in nanoseconds
+u64 get_os_time(void);
+
+// CPU timer using rdtsc
+u64 read_cpu_timer(void);
+
+// CPU frequency in hz/sec
+u64 get_cpu_freq(u64 milliseconds);
+
+#ifdef __cplusplus
+}
+#endif
+
+#endif // !TIMER_H

haversine_02/src/processor/main.cpp

@@ -1,6 +1,7 @@
 #include "haversine.h"
 #include "point_types.h"
 #include "processor/proc_argparser.h"
+#include "profiler/timer.h"
 #include "json/dstring.h"
 #include "json/json_entities.h"
 #include "json/parser.h"
@@ -13,12 +14,20 @@
 #include <string.h>
 
 int main(int argc, char *argv[]) {
+  u64 cpu_freq = get_cpu_freq(500);
+
+  u64 cli_parse_start = read_cpu_timer();
+
   ProcessorArgs args = parse_args(argc, argv);
 
+  u64 json_parse_start = read_cpu_timer();
+
   jentity_t *root = load_json(args.filepath);
 
   assert(root->type == JENTITY_SINGLE && root->value.type == JVAL_COLLECTION);
 
+  u64 load_pairs_json_start = read_cpu_timer();
+
   jentity_t *pairs = root->value.collection->begin;
 
   assert(pairs->type == JENTITY_PAIR &&
@@ -50,6 +59,8 @@ int main(int argc, char *argv[]) {
     point_pairs[index++] = p;
   }
 
+  u64 binary_file_read_start = read_cpu_timer();
+
   const char *filename = "count_and_distances";
 
   FILE *fp = fopen(filename, "r");
@@ -60,6 +71,8 @@ int main(int argc, char *argv[]) {
     fseek(fp, sizeof(u64), SEEK_SET);
   }
 
+  u64 haversine_sum_start = read_cpu_timer();
+
   f64 sum = 0.0;
   f64 distance = 0.0;
   f64 saved_distance = 0.0;
@@ -77,13 +90,61 @@ int main(int argc, char *argv[]) {
 
     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);
+  }
+
   return 0;
 }

haversine_02/src/profiler/timer.c

@@ -0,0 +1,46 @@
+#include "profiler/timer.h"
+#include "aliases.h"
+#include <time.h>
+
+#include <x86intrin.h>
+
+typedef struct timespec timespec_t;
+
+u64 get_os_frequency() { return 1000000000; }
+
+u64 get_os_time(void) {
+  timespec_t ts = {0};
+
+  if (clock_gettime(CLOCK_MONOTONIC_RAW, &ts) != 0) {
+    return 0;
+  }
+
+  return ts.tv_sec * get_os_frequency() + ts.tv_nsec;
+}
+
+u64 read_cpu_timer(void) { return __rdtsc(); }
+
+u64 get_cpu_freq(u64 milliseconds) {
+  u64 os_freq = get_os_frequency();
+  u64 os_start = get_os_time();
+  u64 cpu_start = read_cpu_timer();
+  u64 os_end = 0;
+  u64 os_elapsed = 0;
+  u64 os_wait_time = os_freq * milliseconds / 1000;
+
+  while (os_elapsed < os_wait_time) {
+    os_end = get_os_time();
+    os_elapsed = os_end - os_start;
+  }
+
+  u64 cpu_end = read_cpu_timer();
+  u64 cpu_elapsed = cpu_end - cpu_start;
+
+  u64 cpu_freq = 0;
+
+  if (os_elapsed) {
+    cpu_freq = cpu_elapsed * os_freq / os_elapsed;
+  }
+
+  return cpu_freq;
+}