Add exec timings to -vv output #2490

releasenotes.md

@@ -11,6 +11,7 @@
 - `env::PROJECT_VERSION` now returns the version in project.json.
 - Comparing slices and arrays of user-defined types that implement == operator now works #2486.
 - Add 'loop-vectorize', 'slp-vectorize', 'unroll-loops' and 'merge-functions' optimization flags #2491. 
+- Add exec timings to -vv output #2490.
 
 ### Fixes
 - Compiler assert with var x @noinit = 0 #2452

src/compiler/compiler.c

@@ -26,6 +26,7 @@ Vmem type_info_arena;
 static double compiler_init_time;
 static double compiler_parsing_time;
 static double compiler_sema_time;
+static double compiler_exec_time;
 static double compiler_ir_gen_time;
 static double compiler_codegen_time;
 static double compiler_link_time;
@@ -319,11 +320,23 @@ static void compiler_print_bench(void)
 		double link_time = compiler_link_time - compiler_codegen_time;
 		if (compiler_link_time >= 0) last = compiler_link_time;
 		printf("Frontend -------------------- Time --- %% total\n");
-		if (compiler_init_time >= 0) printf("Initialization took: %10.3f ms  %8.1f %%\n", compiler_init_time * 1000, compiler_init_time * 100 / last);
+		if (compiler_init_time >= 0)
+		{
+			compiler_init_time -= compiler.script_time;
+			printf("Initialization took: %10.3f ms  %8.1f %%\n", compiler_init_time * 1000, compiler_init_time * 100 / last);
+			if (compiler.script_time > 0)
+			{
+				printf("Scripts took:        %10.3f ms  %8.1f %%\n", compiler.script_time * 1000, compiler.script_time * 100 / last);
+			}
+		}
 		if (compiler_parsing_time >= 0) printf("Parsing took:        %10.3f ms  %8.1f %%\n", parse_time * 1000, parse_time * 100 / last);
 		if (compiler_sema_time >= 0)
 		{
 			printf("Analysis took:       %10.3f ms  %8.1f %%\n", sema_time * 1000, sema_time * 100 / last);
+			if (compiler.exec_time > 0)
+			{
+				printf(" - Scripts took:     %10.3f ms  %8.1f %%\n", compiler.exec_time * 1000, compiler.exec_time * 100 / last);
+			}
 			printf("TOTAL:               %10.3f ms  %8.1f %%\n", compiler_sema_time * 1000, compiler_sema_time * 100 / last);
 			puts("");
 		}
@@ -456,6 +469,7 @@ void compiler_compile(void)
 		exit_compiler(COMPILER_SUCCESS_EXIT);
 	}
 	compiler_sema_time = bench_mark();
+	compiler_exec_time = compiler.exec_time;
 	Module **modules = compiler.context.module_list;
 	unsigned module_count = vec_size(modules);
 	if (module_count > MAX_MODULES)
@@ -1234,6 +1248,7 @@ void execute_scripts(void)
 			error_exit("Failed to open script dir '%s'", compiler.build.script_dir);
 		}
 	}
+	double start = bench_mark();
 	FOREACH(const char *, exec, compiler.build.exec)
 	{
 		StringSlice execs = slice_from_string(exec);
@@ -1259,6 +1274,7 @@ PRINT_SCRIPT:;
 		}
 	}
 	dir_change(old_path);
+	compiler.script_time += bench_mark() - start;
 }
 
 static void check_address_sanitizer_options(BuildTarget *target)

src/compiler/compiler_internal.h

@@ -1961,6 +1961,8 @@ typedef struct
 	GlobalContext context;
 	const char *obj_output;
 	int generic_depth;
+	double exec_time;
+	double script_time;
 } CompilerState;
 
 extern CompilerState compiler;

src/compiler/sema_expr.c

@@ -5,6 +5,8 @@
 #include "sema_internal.h"
 #include <math.h>
 
+#include "compiler_tests/benchmark.h"
+
 #define RETURN_SEMA_FUNC_ERROR(_decl, _node, ...) do { sema_error_at(context, (_node)->span, __VA_ARGS__); SEMA_NOTE(_decl, "The definition was here."); return false; } while (0)
 #define RETURN_NOTE_FUNC_DEFINITION do { SEMA_NOTE(callee->definition, "The definition was here."); return false; } while (0)
 #define RESOLVE(expr__, check__) \

src/compiler/sema_passes.c

@@ -3,6 +3,7 @@
 // a copy of which can be found in the LICENSE file.
 
 #include "sema_internal.h"
+#include "compiler_tests/benchmark.h"
 
 void parent_path(StringSlice *slice)
 {
@@ -259,6 +260,7 @@ static bool exec_arg_append_to_scratch(Expr *arg)
 
 static Decl **sema_run_exec(CompilationUnit *unit, Decl *decl)
 {
+	double bench = bench_mark();
 	if (compiler.build.trust_level < TRUST_FULL)
 	{
 		RETURN_PRINT_ERROR_AT(NULL, decl, "'$exec' not permitted, trust level must be set to '--trust=full' to permit it.");
@@ -338,6 +340,7 @@ static Decl **sema_run_exec(CompilationUnit *unit, Decl *decl)
 	{
 		RETURN_PRINT_ERROR_AT(NULL, decl, "This $include would cause the maximum number of includes (%d) to be exceeded.", MAX_INCLUDE_DIRECTIVES);
 	}
+	compiler.exec_time += bench_mark() - bench;
 	return parse_include_file(file, unit);
 }