diff --git a/vlib/v/builder/rebuilding.v b/vlib/v/builder/rebuilding.v index a94d384cf69794..ff4355ef26fbaa 100644 --- a/vlib/v/builder/rebuilding.v +++ b/vlib/v/builder/rebuilding.v @@ -8,6 +8,7 @@ import strings import v.util import v.pref import v.vcache +import runtime pub fn (mut b Builder) rebuild_modules() { if !b.pref.use_cache || b.pref.build_mode == .build_module { @@ -359,7 +360,8 @@ pub fn (mut b Builder) rebuild(backend_cb FnBackend) { // vlines_per_second := int(1_000_000.0 * f64(all_v_source_lines) / f64(compilation_time_micros)) svlines_per_second := util.bold(vlines_per_second.str()) - println('compilation took: ${scompilation_time_ms} ms, compilation speed: ${svlines_per_second} vlines/s') + used_cgen_threads := if b.pref.no_parallel { 1 } else { runtime.nr_jobs() } + println('compilation took: ${scompilation_time_ms} ms, compilation speed: ${svlines_per_second} vlines/s, cgen threads: ${used_cgen_threads}') } } diff --git a/vlib/v/gen/c/cgen.v b/vlib/v/gen/c/cgen.v index dfd87bf45d8910..d3750ac58486ed 100644 --- a/vlib/v/gen/c/cgen.v +++ b/vlib/v/gen/c/cgen.v @@ -667,6 +667,11 @@ pub fn gen(files []&ast.File, mut table ast.Table, pref_ &pref.Preferences) (str fn cgen_process_one_file_cb(mut p pool.PoolProcessor, idx int, wid int) &Gen { file := p.get_item[&ast.File](idx) + timing_label_for_thread := 'C GEN thread ${wid}' + util.timing_start(timing_label_for_thread) + defer { + util.timing_measure_cumulative(timing_label_for_thread) + } mut global_g := unsafe { &Gen(p.get_shared_context()) } mut g := &Gen{ file: file diff --git a/vlib/v/util/timers.v b/vlib/v/util/timers.v index c81872aa2f4d08..fbc076f8d622bd 100644 --- a/vlib/v/util/timers.v +++ b/vlib/v/util/timers.v @@ -12,7 +12,7 @@ __global g_timers = new_timers(should_print: false, label: 'g_timers') pub struct Timers { label string pub mut: - swatches map[string]time.StopWatch + swatches shared map[string]time.StopWatch should_print bool // already_shown records for which of the swatches .show() or .show_if_exists() had been called already already_shown []string @@ -59,52 +59,43 @@ pub fn timing_set_should_print(should_print bool) { } pub fn (mut t Timers) start(name string) { - mut sw := t.swatches[name] or { time.new_stopwatch() } + mut sw := t.tsafe_get_sw(name) or { time.new_stopwatch() } sw.start() - t.swatches[name] = sw + t.tsafe_set_sw(name, sw) } pub fn (mut t Timers) measure(name string) i64 { - if name !in t.swatches { - timer_keys := t.swatches.keys() + mut sw := t.tsafe_get_sw(name) or { + timer_keys := t.tsafe_get_keys() eprintln('> Timer `${name}` was NOT started.') eprintln('> Available timers:') eprintln('> ${timer_keys}') + time.new_stopwatch() } - mut sw := t.swatches[name] ms := sw.elapsed().microseconds() sw.pause() - t.swatches[name] = sw + t.tsafe_set_sw(name, sw) return ms } pub fn (mut t Timers) measure_cumulative(name string) i64 { ms := t.measure(name) - if name !in t.swatches { - return ms - } - mut sw := t.swatches[name] + mut sw := t.tsafe_get_sw(name) or { return ms } sw.pause() - t.swatches[name] = sw + t.tsafe_set_sw(name, sw) return ms } pub fn (mut t Timers) measure_pause(name string) { - if name !in t.swatches { - return - } - mut sw := t.swatches[name] + mut sw := t.tsafe_get_sw(name) or { return } sw.pause() - t.swatches[name] = sw + t.tsafe_set_sw(name, sw) } pub fn (mut t Timers) measure_resume(name string) { - if name !in t.swatches { - return - } - mut sw := t.swatches[name] + mut sw := t.tsafe_get_sw(name) or { return } sw.start() - t.swatches[name] = sw + t.tsafe_set_sw(name, sw) } pub fn (mut t Timers) message(name string) string { @@ -128,15 +119,14 @@ pub fn (mut t Timers) show(label string) { } pub fn (mut t Timers) show_if_exists(label string) { - if label !in t.swatches { - return - } + t.tsafe_get_sw(label) or { return } t.show(label) t.already_shown << label } pub fn (mut t Timers) show_remaining() { - for k, _ in t.swatches { + keys := t.tsafe_get_keys() + for k in keys { if k in t.already_shown { continue } @@ -145,8 +135,34 @@ pub fn (mut t Timers) show_remaining() { } pub fn (mut t Timers) dump_all() { - for k, _ in t.swatches { + keys := t.tsafe_get_keys() + for k in keys { elapsed := t.message(k) println(elapsed) } } + +// + +fn (mut t Timers) tsafe_get_keys() []string { + keys := rlock t.swatches { + t.swatches.keys() + } + return keys +} + +fn (mut t Timers) tsafe_set_sw(name string, sw time.StopWatch) { + lock t.swatches { + t.swatches[name] = sw + } +} + +fn (mut t Timers) tsafe_get_sw(name string) ?time.StopWatch { + rlock t.swatches { + if name !in t.swatches { + return none + } + return t.swatches[name] + } + return none +}