diff --git a/cmd/v/help/build.txt b/cmd/v/help/build.txt index 7f884a5fea..84ce0a9c50 100644 --- a/cmd/v/help/build.txt +++ b/cmd/v/help/build.txt @@ -118,6 +118,12 @@ The build flags are shared by the build and run commands: CHECK: 62ms C GEN: 103ms C tcc: 95ms + + Related to -show-timings, is the ability to compile a special instrumented + v compiler with this command: + `v -d time_parsing -d time_checking -d time_cgening -d time_v self` + The instrumented version will print detailed timing stats while processing + each .v file. -w Hide all warnings. diff --git a/cmd/v/v.v b/cmd/v/v.v index 7d746ad0ea..16d05f8f25 100644 --- a/cmd/v/v.v +++ b/cmd/v/v.v @@ -37,6 +37,14 @@ const ( ) fn main() { + timers_should_print := $if time_v ? { true } $else { false } + mut timers := util.new_timers(timers_should_print) + timers.start('v total') + defer { + timers.show('v total') + } + timers.start('v start') + timers.show('v start') args := os.args[1..] // args = 123 if args.len == 0 || args[0] in ['-', 'repl'] { diff --git a/vlib/v/checker/checker.v b/vlib/v/checker/checker.v index 886e4d949e..ffbe8cd58d 100644 --- a/vlib/v/checker/checker.v +++ b/vlib/v/checker/checker.v @@ -66,13 +66,16 @@ mut: vweb_gen_types []table.Type // vweb route checks prevent_sum_type_unwrapping_once bool // needed for assign new values to sum type, stopping unwrapping then loop_label string // set when inside a labelled for loop + timers &util.Timers } pub fn new_checker(table &table.Table, pref &pref.Preferences) Checker { + timers_should_print := $if time_checking ? { true } $else { false } return Checker{ table: table pref: pref cur_fn: 0 + timers: util.new_timers(timers_should_print) } } @@ -130,6 +133,7 @@ pub fn (mut c Checker) check_files(ast_files []ast.File) { mut files_from_main_module := []&ast.File{} for i in 0 .. ast_files.len { file := unsafe {&ast_files[i]} + c.timers.start('checker_check $file.path') c.check(file) if file.mod.name == 'main' { files_from_main_module << file @@ -138,6 +142,7 @@ pub fn (mut c Checker) check_files(ast_files []ast.File) { has_main_fn = true } } + c.timers.show('checker_check $file.path') } if has_main_mod_file && !has_main_fn && files_from_main_module.len > 0 { if c.pref.is_script && !c.pref.is_test { @@ -154,6 +159,7 @@ pub fn (mut c Checker) check_files(ast_files []ast.File) { has_main_fn = true } } + c.timers.start('checker_post_process_generic_fns') // post process generic functions. must be done after all files have been // checked, to eunsure all generic calls are processed as this information // is needed when the generic type is auto inferred from the call argument @@ -165,7 +171,12 @@ pub fn (mut c Checker) check_files(ast_files []ast.File) { c.post_process_generic_fns() } } + c.timers.show('checker_post_process_generic_fns') + // + c.timers.start('checker_verify_all_vweb_routes') c.verify_all_vweb_routes() + c.timers.show('checker_verify_all_vweb_routes') + // // Make sure fn main is defined in non lib builds if c.pref.build_mode == .build_module || c.pref.is_test { return diff --git a/vlib/v/gen/cgen.v b/vlib/v/gen/cgen.v index 4709e46ae5..9bd7a9bc2d 100644 --- a/vlib/v/gen/cgen.v +++ b/vlib/v/gen/cgen.v @@ -129,6 +129,7 @@ mut: aggregate_type_idx int returned_var_name string // to detect that a var doesn't need to be freed since it's being returned branch_parent_pos int // used in BranchStmt (continue/break) for autofree stop position + timers &util.Timers } const ( @@ -151,6 +152,7 @@ pub fn cgen(files []ast.File, table &table.Table, pref &pref.Preferences) string '.') } } + timers_should_print := $if time_cgening ? { true } $else { false } mut g := Gen{ out: strings.new_builder(1000) cheaders: strings.new_builder(8192) @@ -178,16 +180,19 @@ pub fn cgen(files []ast.File, table &table.Table, pref &pref.Preferences) string autofree: true indent: -1 module_built: module_built + timers: util.new_timers(timers_should_print) } for mod in g.table.modules { g.inits[mod] = strings.new_builder(100) g.cleanups[mod] = strings.new_builder(100) } + g.timers.start('cgen common') g.init() // mut tests_inited := false mut autofree_used := false for file in files { + g.timers.start('cgen_file $file.path') g.file = file if g.pref.is_vlines { g.vlines_path = util.vlines_escape_path(file.path, g.pref.ccompiler) @@ -213,6 +218,7 @@ pub fn cgen(files []ast.File, table &table.Table, pref &pref.Preferences) string tests_inited = true } g.stmts(file.stmts) + g.timers.show('cgen_file $file.path') } if autofree_used { g.autofree = true // so that void _vcleanup is generated @@ -308,6 +314,7 @@ pub fn cgen(files []ast.File, table &table.Table, pref &pref.Preferences) string b.writeln('\n// V out') b.write(g.out.str()) b.writeln('\n// THE END.') + g.timers.show('cgen common') return b.str() } diff --git a/vlib/v/util/timers.v b/vlib/v/util/timers.v index 82eb80a758..f637b799e8 100644 --- a/vlib/v/util/timers.v +++ b/vlib/v/util/timers.v @@ -31,13 +31,13 @@ pub fn (mut t Timers) measure(name string) i64 { eprintln('> Available timers:') eprintln('> $timer_keys') } - ms := t.swatches[name].elapsed().milliseconds() + ms := t.swatches[name].elapsed().microseconds() return ms } pub fn (mut t Timers) message(name string) string { - ms := t.measure(name) - value := bold('$ms') + ms := f64(t.measure(name)) / 1000.0 + value := bold('${ms:.3f}') formatted_message := '$name: $value ms' return formatted_message }