Add `-show-more-timings`

4 files changed, 68 insertions, 60 deletions

diff --git a/src/build_settings.cpp b/src/build_settings.cpp
index 08442ae14..4428a8d2f 100644
--- a/src/build_settings.cpp
+++ b/src/build_settings.cpp
@@ -114,6 +114,7 @@ struct BuildContext {
 	bool   generate_docs;
 	i32    optimization_level;
 	bool   show_timings;
+	bool   show_more_timings;
 	bool   keep_temp_files;
 	bool   ignore_unknown_attributes;
 	bool   no_bounds_check;
diff --git a/src/checker.cpp b/src/checker.cpp
index a260fe48c..6b3b1b68f 100644
--- a/src/checker.cpp
+++ b/src/checker.cpp
@@ -1755,6 +1755,10 @@ Array<EntityGraphNode *> generate_entity_dependency_graph(CheckerInfo *info) {
 		}
 	}
 
+#define TIME_SECTION(str) do { if (build_context.show_more_timings) timings_start_section(&global_timings, str_lit(str)); } while (0)
+
+
+	TIME_SECTION("generate_entity_dependency_graph: Calculate edges for graph M - Part 1");
 	// Calculate edges for graph M
 	for_array(i, M.entries) {
 		Entity *   e = cast(Entity *)M.entries[i].key.ptr;
@@ -1776,6 +1780,10 @@ Array<EntityGraphNode *> generate_entity_dependency_graph(CheckerInfo *info) {
 		}
 	}
 
+	// TODO(bill): This could be multithreaded to improve performance
+	// This means that the entity graph node set will have to be thread safe
+
+	TIME_SECTION("generate_entity_dependency_graph: Calculate edges for graph M - Part 2");
 	auto G = array_make<EntityGraphNode *>(a, 0, M.entries.count);
 
 	for_array(i, M.entries) {
@@ -1812,6 +1820,7 @@ Array<EntityGraphNode *> generate_entity_dependency_graph(CheckerInfo *info) {
 		}
 	}
 
+	TIME_SECTION("generate_entity_dependency_graph: Dependency Count Checker");
 	for_array(i, G) {
 		EntityGraphNode *n = G[i];
 		n->index = i;
@@ -1821,6 +1830,8 @@ Array<EntityGraphNode *> generate_entity_dependency_graph(CheckerInfo *info) {
 	}
 
 	return G;
+
+#undef TIME_SECTION
 }
 
 
@@ -3636,21 +3647,11 @@ Array<Entity *> find_entity_path(Entity *start, Entity *end, Map<Entity *> *visi
 
 
 void calculate_global_init_order(Checker *c) {
-#if 0
-	Timings timings = {};
-	timings_init(&timings, str_lit("calculate_global_init_order"), 16);
-	defer ({
-		timings_print_all(&timings);
-		timings_destroy(&timings);
-	});
-#define TIME_SECTION(str) timings_start_section(&timings, str_lit(str))
-#else
-#define TIME_SECTION(str)
-#endif
+#define TIME_SECTION(str) do { if (build_context.show_more_timings) timings_start_section(&global_timings, str_lit(str)); } while (0)
 
 	CheckerInfo *info = &c->info;
 
-	TIME_SECTION("generate entity dependency graph");
+	TIME_SECTION("calculate_global_init_order: generate entity dependency graph");
 	Array<EntityGraphNode *> dep_graph = generate_entity_dependency_graph(info);
 	defer ({
 		for_array(i, dep_graph) {
@@ -3659,7 +3660,7 @@ void calculate_global_init_order(Checker *c) {
 		array_free(&dep_graph);
 	});
 
-	TIME_SECTION("priority queue create");
+	TIME_SECTION("calculate_global_init_order: priority queue create");
 	// NOTE(bill): Priority queue
 	auto pq = priority_queue_create(dep_graph, entity_graph_node_cmp, entity_graph_node_swap);
 
@@ -3667,7 +3668,7 @@ void calculate_global_init_order(Checker *c) {
 	ptr_set_init(&emitted, heap_allocator());
 	defer (ptr_set_destroy(&emitted));
 
-	TIME_SECTION("queue sort");
+	TIME_SECTION("calculate_global_init_order: queue sort");
 	while (pq.queue.count > 0) {
 		EntityGraphNode *n = priority_queue_pop(&pq);
 		Entity *e = n->entity;
@@ -3779,17 +3780,7 @@ GB_THREAD_PROC(check_proc_info_worker_proc) {
 
 
 void check_parsed_files(Checker *c) {
-#if 0
-	Timings timings = {};
-	timings_init(&timings, str_lit("check_parsed_files"), 16);
-	defer ({
-		timings_print_all(&timings);
-		timings_destroy(&timings);
-	});
-#define TIME_SECTION(str) timings_start_section(&timings, str_lit(str))
-#else
-#define TIME_SECTION(str)
-#endif
+#define TIME_SECTION(str) do { if (build_context.show_more_timings) timings_start_section(&global_timings, str_lit(str)); } while (0)
 
 	TIME_SECTION("map full filepaths to scope");
 	add_type_info_type(&c->init_ctx, t_invalid);
@@ -3851,6 +3842,7 @@ void check_parsed_files(Checker *c) {
 		check_proc_info(c, pi);
 	}
 
+	TIME_SECTION("check scope usage");
 	for_array(i, c->info.files.entries) {
 		AstFile *f = c->info.files.entries[i].value;
 		check_scope_usage(c, f->scope);
diff --git a/src/main.cpp b/src/main.cpp
index acb580ca2..1cee9fcfb 100644
--- a/src/main.cpp
+++ b/src/main.cpp
@@ -1,5 +1,6 @@
 // #define NO_ARRAY_BOUNDS_CHECK
 
+
 #include "common.cpp"
 #include "timings.cpp"
 #include "tokenizer.cpp"
@@ -7,6 +8,10 @@
 #include "exact_value.cpp"
 #include "build_settings.cpp"
 
+
+gb_global Timings global_timings = {0};
+
+
 #include "parser.hpp"
 #include "checker.hpp"
 
@@ -206,6 +211,7 @@ enum BuildFlagKind {
 	BuildFlag_OutFile,
 	BuildFlag_OptimizationLevel,
 	BuildFlag_ShowTimings,
+	BuildFlag_ShowMoreTimings,
 	BuildFlag_ThreadCount,
 	BuildFlag_KeepTempFiles,
 	BuildFlag_Collection,
@@ -290,20 +296,21 @@ ExactValue build_param_to_exact_value(String name, String param) {
 
 bool parse_build_flags(Array<String> args) {
 	auto build_flags = array_make<BuildFlag>(heap_allocator(), 0, BuildFlag_COUNT);
-	add_flag(&build_flags, BuildFlag_OutFile,           str_lit("out"),             BuildFlagParam_String);
-	add_flag(&build_flags, BuildFlag_OptimizationLevel, str_lit("opt"),             BuildFlagParam_Integer);
-	add_flag(&build_flags, BuildFlag_ShowTimings,       str_lit("show-timings"),    BuildFlagParam_None);
-	add_flag(&build_flags, BuildFlag_ThreadCount,       str_lit("thread-count"),    BuildFlagParam_Integer);
-	add_flag(&build_flags, BuildFlag_KeepTempFiles,     str_lit("keep-temp-files"), BuildFlagParam_None);
-	add_flag(&build_flags, BuildFlag_Collection,        str_lit("collection"),      BuildFlagParam_String);
-	add_flag(&build_flags, BuildFlag_Define,            str_lit("define"),          BuildFlagParam_String);
-	add_flag(&build_flags, BuildFlag_BuildMode,         str_lit("build-mode"),      BuildFlagParam_String);
-	add_flag(&build_flags, BuildFlag_Target,            str_lit("target"),          BuildFlagParam_String);
-	add_flag(&build_flags, BuildFlag_Debug,             str_lit("debug"),           BuildFlagParam_None);
-	add_flag(&build_flags, BuildFlag_NoBoundsCheck,     str_lit("no-bounds-check"), BuildFlagParam_None);
-	add_flag(&build_flags, BuildFlag_NoCRT,             str_lit("no-crt"),          BuildFlagParam_None);
-	add_flag(&build_flags, BuildFlag_UseLLD,            str_lit("lld"),             BuildFlagParam_None);
-	add_flag(&build_flags, BuildFlag_Vet,               str_lit("vet"),             BuildFlagParam_None);
+	add_flag(&build_flags, BuildFlag_OutFile,           str_lit("out"),               BuildFlagParam_String);
+	add_flag(&build_flags, BuildFlag_OptimizationLevel, str_lit("opt"),               BuildFlagParam_Integer);
+	add_flag(&build_flags, BuildFlag_ShowTimings,       str_lit("show-timings"),      BuildFlagParam_None);
+	add_flag(&build_flags, BuildFlag_ShowMoreTimings,   str_lit("show-more-timings"), BuildFlagParam_None);
+	add_flag(&build_flags, BuildFlag_ThreadCount,       str_lit("thread-count"),      BuildFlagParam_Integer);
+	add_flag(&build_flags, BuildFlag_KeepTempFiles,     str_lit("keep-temp-files"),   BuildFlagParam_None);
+	add_flag(&build_flags, BuildFlag_Collection,        str_lit("collection"),        BuildFlagParam_String);
+	add_flag(&build_flags, BuildFlag_Define,            str_lit("define"),            BuildFlagParam_String);
+	add_flag(&build_flags, BuildFlag_BuildMode,         str_lit("build-mode"),        BuildFlagParam_String);
+	add_flag(&build_flags, BuildFlag_Target,            str_lit("target"),            BuildFlagParam_String);
+	add_flag(&build_flags, BuildFlag_Debug,             str_lit("debug"),             BuildFlagParam_None);
+	add_flag(&build_flags, BuildFlag_NoBoundsCheck,     str_lit("no-bounds-check"),   BuildFlagParam_None);
+	add_flag(&build_flags, BuildFlag_NoCRT,             str_lit("no-crt"),            BuildFlagParam_None);
+	add_flag(&build_flags, BuildFlag_UseLLD,            str_lit("lld"),               BuildFlagParam_None);
+	add_flag(&build_flags, BuildFlag_Vet,               str_lit("vet"),               BuildFlagParam_None);
 	add_flag(&build_flags, BuildFlag_IgnoreUnknownAttributes, str_lit("ignore-unknown-attributes"), BuildFlagParam_None);
 
 	add_flag(&build_flags, BuildFlag_Compact, str_lit("compact"), BuildFlagParam_None);
@@ -374,7 +381,7 @@ bool parse_build_flags(Array<String> args) {
 							           param == "0") {
 								value = exact_value_bool(false);
 							} else {
-								gb_printf_err("Invalid flag parameter for '%.*s' = '%.*s'\n", LIT(name), LIT(param));
+								gb_printf_err("Invalid flag parameter for '%.*s' : '%.*s'\n", LIT(name), LIT(param));
 							}
 						} break;
 						case BuildFlagParam_Integer:
@@ -461,6 +468,11 @@ bool parse_build_flags(Array<String> args) {
 							GB_ASSERT(value.kind == ExactValue_Invalid);
 							build_context.show_timings = true;
 							break;
+						case BuildFlag_ShowMoreTimings:
+							GB_ASSERT(value.kind == ExactValue_Invalid);
+							build_context.show_timings = true;
+							build_context.show_more_timings = true;
+							break;
 						case BuildFlag_ThreadCount: {
 							GB_ASSERT(value.kind == ExactValue_Integer);
 							isize count = cast(isize)big_int_to_i64(&value.value_integer);
@@ -912,9 +924,10 @@ int main(int arg_count, char **arg_ptr) {
 		return 1;
 	}
 
-	Timings timings = {0};
-	timings_init(&timings, str_lit("Total Time"), 128);
-	defer (timings_destroy(&timings));
+	Timings *timings = &global_timings;
+
+	timings_init(timings, str_lit("Total Time"), 128);
+	defer (timings_destroy(timings));
 
 	init_string_buffer_memory();
 	init_global_error_collector();
@@ -1023,7 +1036,7 @@ int main(int arg_count, char **arg_ptr) {
 	init_universal();
 	// TODO(bill): prevent compiling without a linker
 
-	timings_start_section(&timings, str_lit("parse files"));
+	timings_start_section(timings, str_lit("parse files"));
 
 	Parser parser = {0};
 	if (!init_parser(&parser)) {
@@ -1039,7 +1052,7 @@ int main(int arg_count, char **arg_ptr) {
 		// generate_documentation(&parser);
 		return 0;
 	}
-	timings_start_section(&timings, str_lit("type check"));
+	timings_start_section(timings, str_lit("type check"));
 
 	Checker checker = {0};
 
@@ -1055,10 +1068,10 @@ int main(int arg_count, char **arg_ptr) {
 
 	if (build_context.no_output_files) {
 		if (build_context.query_data_set_settings.ok) {
-			generate_and_print_query_data(&checker, &timings);
+			generate_and_print_query_data(&checker, timings);
 		} else {
 			if (build_context.show_timings) {
-				show_timings(&checker, &timings);
+				show_timings(&checker, timings);
 			}
 		}
 
@@ -1080,13 +1093,13 @@ int main(int arg_count, char **arg_ptr) {
 	// defer (ir_gen_destroy(&ir_gen));
 
 
-	timings_start_section(&timings, str_lit("llvm ir gen"));
+	timings_start_section(timings, str_lit("llvm ir gen"));
 	ir_gen_tree(&ir_gen);
 
-	timings_start_section(&timings, str_lit("llvm ir opt tree"));
+	timings_start_section(timings, str_lit("llvm ir opt tree"));
 	ir_opt_tree(&ir_gen);
 
-	timings_start_section(&timings, str_lit("llvm ir print"));
+	timings_start_section(timings, str_lit("llvm ir print"));
 	print_llvm_ir(&ir_gen);
 
 
@@ -1097,13 +1110,13 @@ int main(int arg_count, char **arg_ptr) {
 
 	i32 exit_code = 0;
 
-	timings_start_section(&timings, str_lit("llvm-opt"));
+	timings_start_section(timings, str_lit("llvm-opt"));
 	exit_code = exec_llvm_opt(output_base);
 	if (exit_code != 0) {
 		return exit_code;
 	}
 
-	timings_start_section(&timings, str_lit("llvm-llc"));
+	timings_start_section(timings, str_lit("llvm-llc"));
 	exit_code = exec_llvm_llc(output_base);
 	if (exit_code != 0) {
 		return exit_code;
@@ -1121,7 +1134,7 @@ int main(int arg_count, char **arg_ptr) {
 		}
 	} else {
 	#if defined(GB_SYSTEM_WINDOWS)
-		timings_start_section(&timings, str_lit("msvc-link"));
+		timings_start_section(timings, str_lit("msvc-link"));
 
 		gbString lib_str = gb_string_make(heap_allocator(), "");
 		defer (gb_string_free(lib_str));
@@ -1212,7 +1225,7 @@ int main(int arg_count, char **arg_ptr) {
 		}
 
 		if (build_context.show_timings) {
-			show_timings(&checker, &timings);
+			show_timings(&checker, timings);
 		}
 
 		remove_temp_files(output_base);
@@ -1221,7 +1234,7 @@ int main(int arg_count, char **arg_ptr) {
 			return system_exec_command_line_app("odin run", "%.*s.exe %.*s", LIT(output_base), LIT(run_args_string));
 		}
 	#else
-		timings_start_section(&timings, str_lit("ld-link"));
+		timings_start_section(timings, str_lit("ld-link"));
 
 		// NOTE(vassvik): get cwd, for used for local shared libs linking, since those have to be relative to the exe
 		char cwd[256];
@@ -1351,7 +1364,7 @@ int main(int arg_count, char **arg_ptr) {
 
 
 		if (build_context.show_timings) {
-			show_timings(&checker, &timings);
+			show_timings(&checker, timings);
 		}
 
 		remove_temp_files(output_base);
diff --git a/src/timings.cpp b/src/timings.cpp
index 31de1ce8c..873e9493d 100644
--- a/src/timings.cpp
+++ b/src/timings.cpp
@@ -159,19 +159,21 @@ f64 time_stamp(TimeStamp const &ts, u64 freq, TimingUnit unit) {
 }
 
 void timings_print_all(Timings *t, TimingUnit unit = TimingUnit_Millisecond) {
-	char const SPACES[] = "                                                                ";
-	isize max_len;
+	isize const SPACES_LEN = 256;
+	char SPACES[SPACES_LEN+1] = {0};
+	gb_memset(SPACES, ' ', SPACES_LEN);
+
 
 	timings__stop_current_section(t);
 	t->total.finish = time_stamp_time_now();
 
-	max_len = gb_min(36, t->total.label.len);
+	isize max_len = gb_min(36, t->total.label.len);
 	for_array(i, t->sections) {
 		TimeStamp ts = t->sections[i];
 		max_len = gb_max(max_len, ts.label.len);
 	}
 
-	GB_ASSERT(max_len <= gb_size_of(SPACES)-1);
+	GB_ASSERT(max_len <= SPACES_LEN);
 
 	t->total_time_seconds = time_stamp_as_s(t->total, t->freq);