Add -show-more-timings

This commit is contained in:
gingerBill
2019-11-10 21:49:02 +00:00
parent 33d05a07de
commit 967981aacd
4 changed files with 68 additions and 60 deletions
+1
View File
@@ -114,6 +114,7 @@ struct BuildContext {
bool generate_docs; bool generate_docs;
i32 optimization_level; i32 optimization_level;
bool show_timings; bool show_timings;
bool show_more_timings;
bool keep_temp_files; bool keep_temp_files;
bool ignore_unknown_attributes; bool ignore_unknown_attributes;
bool no_bounds_check; bool no_bounds_check;
+17 -25
View File
@@ -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 // Calculate edges for graph M
for_array(i, M.entries) { for_array(i, M.entries) {
Entity * e = cast(Entity *)M.entries[i].key.ptr; 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); auto G = array_make<EntityGraphNode *>(a, 0, M.entries.count);
for_array(i, M.entries) { 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) { for_array(i, G) {
EntityGraphNode *n = G[i]; EntityGraphNode *n = G[i];
n->index = i; n->index = i;
@@ -1821,6 +1830,8 @@ Array<EntityGraphNode *> generate_entity_dependency_graph(CheckerInfo *info) {
} }
return G; 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) { void calculate_global_init_order(Checker *c) {
#if 0 #define TIME_SECTION(str) do { if (build_context.show_more_timings) timings_start_section(&global_timings, str_lit(str)); } while (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
CheckerInfo *info = &c->info; 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); Array<EntityGraphNode *> dep_graph = generate_entity_dependency_graph(info);
defer ({ defer ({
for_array(i, dep_graph) { for_array(i, dep_graph) {
@@ -3659,7 +3660,7 @@ void calculate_global_init_order(Checker *c) {
array_free(&dep_graph); array_free(&dep_graph);
}); });
TIME_SECTION("priority queue create"); TIME_SECTION("calculate_global_init_order: priority queue create");
// NOTE(bill): Priority queue // NOTE(bill): Priority queue
auto pq = priority_queue_create(dep_graph, entity_graph_node_cmp, entity_graph_node_swap); 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()); ptr_set_init(&emitted, heap_allocator());
defer (ptr_set_destroy(&emitted)); defer (ptr_set_destroy(&emitted));
TIME_SECTION("queue sort"); TIME_SECTION("calculate_global_init_order: queue sort");
while (pq.queue.count > 0) { while (pq.queue.count > 0) {
EntityGraphNode *n = priority_queue_pop(&pq); EntityGraphNode *n = priority_queue_pop(&pq);
Entity *e = n->entity; Entity *e = n->entity;
@@ -3779,17 +3780,7 @@ GB_THREAD_PROC(check_proc_info_worker_proc) {
void check_parsed_files(Checker *c) { void check_parsed_files(Checker *c) {
#if 0 #define TIME_SECTION(str) do { if (build_context.show_more_timings) timings_start_section(&global_timings, str_lit(str)); } while (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
TIME_SECTION("map full filepaths to scope"); TIME_SECTION("map full filepaths to scope");
add_type_info_type(&c->init_ctx, t_invalid); add_type_info_type(&c->init_ctx, t_invalid);
@@ -3851,6 +3842,7 @@ void check_parsed_files(Checker *c) {
check_proc_info(c, pi); check_proc_info(c, pi);
} }
TIME_SECTION("check scope usage");
for_array(i, c->info.files.entries) { for_array(i, c->info.files.entries) {
AstFile *f = c->info.files.entries[i].value; AstFile *f = c->info.files.entries[i].value;
check_scope_usage(c, f->scope); check_scope_usage(c, f->scope);
+44 -31
View File
@@ -1,5 +1,6 @@
// #define NO_ARRAY_BOUNDS_CHECK // #define NO_ARRAY_BOUNDS_CHECK
#include "common.cpp" #include "common.cpp"
#include "timings.cpp" #include "timings.cpp"
#include "tokenizer.cpp" #include "tokenizer.cpp"
@@ -7,6 +8,10 @@
#include "exact_value.cpp" #include "exact_value.cpp"
#include "build_settings.cpp" #include "build_settings.cpp"
gb_global Timings global_timings = {0};
#include "parser.hpp" #include "parser.hpp"
#include "checker.hpp" #include "checker.hpp"
@@ -206,6 +211,7 @@ enum BuildFlagKind {
BuildFlag_OutFile, BuildFlag_OutFile,
BuildFlag_OptimizationLevel, BuildFlag_OptimizationLevel,
BuildFlag_ShowTimings, BuildFlag_ShowTimings,
BuildFlag_ShowMoreTimings,
BuildFlag_ThreadCount, BuildFlag_ThreadCount,
BuildFlag_KeepTempFiles, BuildFlag_KeepTempFiles,
BuildFlag_Collection, BuildFlag_Collection,
@@ -290,20 +296,21 @@ ExactValue build_param_to_exact_value(String name, String param) {
bool parse_build_flags(Array<String> args) { bool parse_build_flags(Array<String> args) {
auto build_flags = array_make<BuildFlag>(heap_allocator(), 0, BuildFlag_COUNT); 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_OutFile, str_lit("out"), BuildFlagParam_String);
add_flag(&build_flags, BuildFlag_OptimizationLevel, str_lit("opt"), BuildFlagParam_Integer); 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_ShowTimings, str_lit("show-timings"), BuildFlagParam_None);
add_flag(&build_flags, BuildFlag_ThreadCount, str_lit("thread-count"), BuildFlagParam_Integer); add_flag(&build_flags, BuildFlag_ShowMoreTimings, str_lit("show-more-timings"), BuildFlagParam_None);
add_flag(&build_flags, BuildFlag_KeepTempFiles, str_lit("keep-temp-files"), BuildFlagParam_None); add_flag(&build_flags, BuildFlag_ThreadCount, str_lit("thread-count"), BuildFlagParam_Integer);
add_flag(&build_flags, BuildFlag_Collection, str_lit("collection"), BuildFlagParam_String); add_flag(&build_flags, BuildFlag_KeepTempFiles, str_lit("keep-temp-files"), BuildFlagParam_None);
add_flag(&build_flags, BuildFlag_Define, str_lit("define"), BuildFlagParam_String); add_flag(&build_flags, BuildFlag_Collection, str_lit("collection"), BuildFlagParam_String);
add_flag(&build_flags, BuildFlag_BuildMode, str_lit("build-mode"), BuildFlagParam_String); add_flag(&build_flags, BuildFlag_Define, str_lit("define"), BuildFlagParam_String);
add_flag(&build_flags, BuildFlag_Target, str_lit("target"), BuildFlagParam_String); add_flag(&build_flags, BuildFlag_BuildMode, str_lit("build-mode"), BuildFlagParam_String);
add_flag(&build_flags, BuildFlag_Debug, str_lit("debug"), BuildFlagParam_None); add_flag(&build_flags, BuildFlag_Target, str_lit("target"), BuildFlagParam_String);
add_flag(&build_flags, BuildFlag_NoBoundsCheck, str_lit("no-bounds-check"), BuildFlagParam_None); add_flag(&build_flags, BuildFlag_Debug, str_lit("debug"), BuildFlagParam_None);
add_flag(&build_flags, BuildFlag_NoCRT, str_lit("no-crt"), BuildFlagParam_None); add_flag(&build_flags, BuildFlag_NoBoundsCheck, str_lit("no-bounds-check"), BuildFlagParam_None);
add_flag(&build_flags, BuildFlag_UseLLD, str_lit("lld"), BuildFlagParam_None); add_flag(&build_flags, BuildFlag_NoCRT, str_lit("no-crt"), BuildFlagParam_None);
add_flag(&build_flags, BuildFlag_Vet, str_lit("vet"), 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_IgnoreUnknownAttributes, str_lit("ignore-unknown-attributes"), BuildFlagParam_None);
add_flag(&build_flags, BuildFlag_Compact, str_lit("compact"), 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") { param == "0") {
value = exact_value_bool(false); value = exact_value_bool(false);
} else { } 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; } break;
case BuildFlagParam_Integer: case BuildFlagParam_Integer:
@@ -461,6 +468,11 @@ bool parse_build_flags(Array<String> args) {
GB_ASSERT(value.kind == ExactValue_Invalid); GB_ASSERT(value.kind == ExactValue_Invalid);
build_context.show_timings = true; build_context.show_timings = true;
break; 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: { case BuildFlag_ThreadCount: {
GB_ASSERT(value.kind == ExactValue_Integer); GB_ASSERT(value.kind == ExactValue_Integer);
isize count = cast(isize)big_int_to_i64(&value.value_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; return 1;
} }
Timings timings = {0}; Timings *timings = &global_timings;
timings_init(&timings, str_lit("Total Time"), 128);
defer (timings_destroy(&timings)); timings_init(timings, str_lit("Total Time"), 128);
defer (timings_destroy(timings));
init_string_buffer_memory(); init_string_buffer_memory();
init_global_error_collector(); init_global_error_collector();
@@ -1023,7 +1036,7 @@ int main(int arg_count, char **arg_ptr) {
init_universal(); init_universal();
// TODO(bill): prevent compiling without a linker // 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}; Parser parser = {0};
if (!init_parser(&parser)) { if (!init_parser(&parser)) {
@@ -1039,7 +1052,7 @@ int main(int arg_count, char **arg_ptr) {
// generate_documentation(&parser); // generate_documentation(&parser);
return 0; return 0;
} }
timings_start_section(&timings, str_lit("type check")); timings_start_section(timings, str_lit("type check"));
Checker checker = {0}; Checker checker = {0};
@@ -1055,10 +1068,10 @@ int main(int arg_count, char **arg_ptr) {
if (build_context.no_output_files) { if (build_context.no_output_files) {
if (build_context.query_data_set_settings.ok) { if (build_context.query_data_set_settings.ok) {
generate_and_print_query_data(&checker, &timings); generate_and_print_query_data(&checker, timings);
} else { } else {
if (build_context.show_timings) { 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)); // 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); 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); 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); print_llvm_ir(&ir_gen);
@@ -1097,13 +1110,13 @@ int main(int arg_count, char **arg_ptr) {
i32 exit_code = 0; 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); exit_code = exec_llvm_opt(output_base);
if (exit_code != 0) { if (exit_code != 0) {
return exit_code; 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); exit_code = exec_llvm_llc(output_base);
if (exit_code != 0) { if (exit_code != 0) {
return exit_code; return exit_code;
@@ -1121,7 +1134,7 @@ int main(int arg_count, char **arg_ptr) {
} }
} else { } else {
#if defined(GB_SYSTEM_WINDOWS) #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(), ""); gbString lib_str = gb_string_make(heap_allocator(), "");
defer (gb_string_free(lib_str)); defer (gb_string_free(lib_str));
@@ -1212,7 +1225,7 @@ int main(int arg_count, char **arg_ptr) {
} }
if (build_context.show_timings) { if (build_context.show_timings) {
show_timings(&checker, &timings); show_timings(&checker, timings);
} }
remove_temp_files(output_base); 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)); return system_exec_command_line_app("odin run", "%.*s.exe %.*s", LIT(output_base), LIT(run_args_string));
} }
#else #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 // NOTE(vassvik): get cwd, for used for local shared libs linking, since those have to be relative to the exe
char cwd[256]; char cwd[256];
@@ -1351,7 +1364,7 @@ int main(int arg_count, char **arg_ptr) {
if (build_context.show_timings) { if (build_context.show_timings) {
show_timings(&checker, &timings); show_timings(&checker, timings);
} }
remove_temp_files(output_base); remove_temp_files(output_base);
+6 -4
View File
@@ -159,19 +159,21 @@ f64 time_stamp(TimeStamp const &ts, u64 freq, TimingUnit unit) {
} }
void timings_print_all(Timings *t, TimingUnit unit = TimingUnit_Millisecond) { void timings_print_all(Timings *t, TimingUnit unit = TimingUnit_Millisecond) {
char const SPACES[] = " "; isize const SPACES_LEN = 256;
isize max_len; char SPACES[SPACES_LEN+1] = {0};
gb_memset(SPACES, ' ', SPACES_LEN);
timings__stop_current_section(t); timings__stop_current_section(t);
t->total.finish = time_stamp_time_now(); 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) { for_array(i, t->sections) {
TimeStamp ts = t->sections[i]; TimeStamp ts = t->sections[i];
max_len = gb_max(max_len, ts.label.len); 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); t->total_time_seconds = time_stamp_as_s(t->total, t->freq);