diff --git a/vlib/v/gen/c/cgen.v b/vlib/v/gen/c/cgen.v index ed0a499c55..93e97e268a 100644 --- a/vlib/v/gen/c/cgen.v +++ b/vlib/v/gen/c/cgen.v @@ -6172,7 +6172,7 @@ fn (mut g Gen) write_init_function() { g.write_debug_calls_typeof_functions() - if g.pref.trace_calls { + if g.pref.trace_calls && g.pref.should_trace_fn_name('_vinit') { g.writeln('\tv__trace_calls__on_call(_SLIT("_vinit"));') } @@ -6267,7 +6267,7 @@ fn (mut g Gen) write_init_function() { fn_vcleanup_start_pos := g.out.len g.writeln('void _vcleanup(void) {') - if g.pref.trace_calls { + if g.pref.trace_calls && g.pref.should_trace_fn_name('_vcleanup') { g.writeln('\tv__trace_calls__on_call(_SLIT("_vcleanup"));') } if g.is_autofree { diff --git a/vlib/v/gen/c/cmain.v b/vlib/v/gen/c/cmain.v index 396a620583..321315e5eb 100644 --- a/vlib/v/gen/c/cmain.v +++ b/vlib/v/gen/c/cmain.v @@ -350,5 +350,6 @@ pub fn (mut g Gen) gen_c_main_trace_calls_hook() { if !g.pref.trace_calls { return } - g.writeln('\tu8 bottom_of_stack = 0; g_stack_base = &bottom_of_stack; v__trace_calls__on_c_main();') + should_trace_c_main := g.pref.should_trace_fn_name('C.main') + g.writeln('\tu8 bottom_of_stack = 0; g_stack_base = &bottom_of_stack; v__trace_calls__on_c_main(${should_trace_c_main});') } diff --git a/vlib/v/pref/pref.c.v b/vlib/v/pref/pref.c.v index f784de996a..5bec7231e3 100644 --- a/vlib/v/pref/pref.c.v +++ b/vlib/v/pref/pref.c.v @@ -174,8 +174,9 @@ pub mut: no_bounds_checking bool // `-no-bounds-checking` turns off *all* bounds checks for all functions at runtime, as if they all had been tagged with `[direct_array_access]` autofree bool // `v -manualfree` => false, `v -autofree` => true; false by default for now. // Disabling `free()` insertion results in better performance in some applications (e.g. compilers) - trace_calls bool // -trace-calls true = the transformer stage will generate and inject print calls for tracing function calls - compress bool // when set, use `upx` to compress the generated executable + trace_calls bool // -trace-calls true = the transformer stage will generate and inject print calls for tracing function calls + trace_fns []string // when set, tracing will be done only for functions, whose names match the listed patterns. + compress bool // when set, use `upx` to compress the generated executable // generating_vh bool no_builtin bool // Skip adding the `builtin` module implicitly. The generated C code may not compile. enable_globals bool // allow __global for low level code @@ -551,8 +552,19 @@ pub fn parse_args_and_show_errors(known_external_commands []string, args []strin res.build_options << arg } '-trace-calls' { + res.build_options << arg res.trace_calls = true } + '-trace-fns' { + value := cmdline.option(current_args, arg, '') + res.build_options << arg + res.build_options << value + trace_fns := value.split(',') + if trace_fns.len > 0 { + res.trace_fns << trace_fns + } + i++ + } '-manualfree' { res.autofree = false res.build_options << arg @@ -951,6 +963,17 @@ pub fn parse_args_and_show_errors(known_external_commands []string, args []strin } } } + if res.trace_calls { + if res.trace_fns.len == 0 { + res.trace_fns << '*' + } + for mut fpattern in res.trace_fns { + if fpattern.contains('*') { + continue + } + fpattern = '*${fpattern}*' + } + } if command == 'crun' { res.is_crun = true } @@ -1245,3 +1268,7 @@ fn (mut prefs Preferences) diagnose_deprecated_defines(define_parts []string) { pub fn supported_test_runners_list() string { return pref.supported_test_runners.map('`${it}`').join(', ') } + +pub fn (pref &Preferences) should_trace_fn_name(fname string) bool { + return pref.trace_fns.any(fname.match_glob(it)) +} diff --git a/vlib/v/tests/testdata/trace_calls/single_println.vv b/vlib/v/tests/testdata/trace_calls/single_println.vv new file mode 100644 index 0000000000..399d47d3ce --- /dev/null +++ b/vlib/v/tests/testdata/trace_calls/single_println.vv @@ -0,0 +1 @@ +println('hi') diff --git a/vlib/v/tests/testdata/trace_calls/single_println.vv.must_match b/vlib/v/tests/testdata/trace_calls/single_println.vv.must_match new file mode 100644 index 0000000000..fda1d22eab --- /dev/null +++ b/vlib/v/tests/testdata/trace_calls/single_println.vv.must_match @@ -0,0 +1 @@ +*hi* diff --git a/vlib/v/tests/trace_calls_test.v b/vlib/v/tests/trace_calls_test.v index 2134ee676b..dbe68698f0 100644 --- a/vlib/v/tests/trace_calls_test.v +++ b/vlib/v/tests/trace_calls_test.v @@ -4,6 +4,23 @@ const vexe = @VEXE const gcc_path = os.find_abs_path_of_executable('gcc') or { '' } const cdefs_h_32bit_exists = os.exists('/usr/include/i386-linux-gnu/sys/cdefs.h') +fn separator() { + eprintln('-'.repeat(30)) +} + +fn test_trace_fns() { + os.chdir(@VROOT)! + folder := os.join_path('vlib', 'v', 'tests', 'testdata', 'trace_calls') + fpath := os.join_path(folder, 'single_println.vv') + should_match_fpath := os.join_path(folder, 'single_println.vv.must_match.simple') + assert run_trace_fns(fpath, 'println') == 1 + assert run_trace_fns(fpath, '_vinit') == 1 + assert run_trace_fns(fpath, 'println,main.main') == 2 + assert run_trace_fns(fpath, 'builtin') > 3 + eprintln('> `-trace-calls -trace-fns PATTERNS` works') + separator() +} + fn test_tracing() { os.chdir(@VROOT)! folder := os.join_path('vlib', 'v', 'tests', 'testdata', 'trace_calls') @@ -21,18 +38,34 @@ fn test_tracing() { } else { eprintln('> skipping -m32 compilation since either 32bit headers are not installed, or you do not have gcc installed') } - eprintln('-'.repeat(30)) + separator() } } -fn run_single_program(fpath string, should_match_fpath string, compiler_opts string, label string) { - res := os.execute('${os.quoted_path(vexe)} ${compiler_opts} -trace-calls run ${os.quoted_path(fpath)}') +struct CmdOutput { + cmd string + output string +} + +fn run(fpath string, compiler_opts string, label string) CmdOutput { + cmd := '${os.quoted_path(vexe)} ${compiler_opts} -trace-calls run ${os.quoted_path(fpath)}' + res := os.execute(cmd) if res.exit_code != 0 { eprintln('> ${label} compilation output:\n${res.output}') assert res.exit_code == 0, 'compilation of ${fpath} failed' } + return CmdOutput{cmd, res.output} +} + +fn run_trace_fns(fpath string, patterns string) int { + // ignore the header line and the final output `hi` line: + return run(fpath, '-trace-fns ${patterns}', 'trace_fns_only_println').output.split_into_lines().len - 2 +} + +fn run_single_program(fpath string, should_match_fpath string, compiler_opts string, label string) { + c := run(fpath, compiler_opts, label) lines := os.read_lines(should_match_fpath) or { - assert false, '${fpath} should be readable' + assert false, '${should_match_fpath} should be readable' return } if lines.len == 0 { @@ -40,13 +73,15 @@ fn run_single_program(fpath string, should_match_fpath string, compiler_opts str } mut matched := false for line in lines { - if res.output.match_glob(line) { + if c.output.match_glob(line) { matched = true println('> ${label} trace output of ${fpath} matches line pattern: ${line}') continue } else { - eprintln(res.output) - assert false, '> trace output of ${fpath} DID NOT match the line pattern: ${line}' + eprintln('-----------------------------------') + eprintln(c.output) + eprintln('-----------------------------------') + assert false, '> trace output of ${fpath} DID NOT match the line pattern: `${line}`, run cmd:\n${c.cmd}' } } } diff --git a/vlib/v/trace_calls/tracing_calls.c.v b/vlib/v/trace_calls/tracing_calls.c.v index 7dd556fa95..93fda5e958 100644 --- a/vlib/v/trace_calls/tracing_calls.c.v +++ b/vlib/v/trace_calls/tracing_calls.c.v @@ -49,10 +49,12 @@ fn current_time() u64 { } @[markused] -pub fn on_c_main() { +pub fn on_c_main(should_trace_c_main bool) { g_start_time = current_time() + // > trace 2128896 714640 28148 fn C.fprintf(C.stderr, c'# tid ns ssize name\n') C.fflush(C.stderr) - on_call('C.main') - // > trace 2128896 714640 28148 fn + if should_trace_c_main { + on_call('C.main') + } } diff --git a/vlib/v/transformer/transformer.v b/vlib/v/transformer/transformer.v index 3f6565b333..3704034ea9 100644 --- a/vlib/v/transformer/transformer.v +++ b/vlib/v/transformer/transformer.v @@ -236,7 +236,9 @@ pub fn (mut t Transformer) stmt(mut node ast.Stmt) ast.Stmt { } } ast.FnDecl { - t.fn_decl(mut node) + if t.pref.trace_calls { + t.fn_decl_trace_calls(mut node) + } t.index.indent(true) for mut stmt in node.stmts { stmt = t.stmt(mut stmt) @@ -1101,43 +1103,42 @@ pub fn (mut t Transformer) sql_expr(mut node ast.SqlExpr) ast.Expr { return node } -// fn_decl mutates `node`. -// if `pref.trace_calls` is true ast Nodes for `eprintln(...)` is prepended to the `FnDecl`'s -// stmts list to let the gen backend generate the target specific code for the print. -pub fn (mut t Transformer) fn_decl(mut node ast.FnDecl) { - if t.pref.trace_calls { - if node.no_body { - // Skip `C.fn()` calls - return - } - if node.name.starts_with('v.trace_calls.') { - // do not instrument the tracing functions, to avoid infinite regress - return - } - fname := if node.is_method { - receiver_name := global_table.type_to_str(node.receiver.typ) - '${node.mod} ${receiver_name}.${node.name}/${node.params.len}' - } else { - '${node.mod} ${node.name}/${node.params.len}' - } - - expr_stmt := ast.ExprStmt{ - expr: ast.CallExpr{ - mod: node.mod - pos: node.pos - language: .v - scope: node.scope - name: 'v.trace_calls.on_call' - args: [ - ast.CallArg{ - expr: ast.StringLiteral{ - val: fname - } - typ: ast.string_type_idx - }, - ] - } - } - node.stmts.prepend(expr_stmt) +pub fn (mut t Transformer) fn_decl_trace_calls(mut node ast.FnDecl) { + // Prepend ast Nodes for `eprintln(...)` to the `FnDecl`'s stmts list, + // to let the gen backend generate the target specific code for the print. + if node.no_body { + // Skip `C.fn()` calls + return } + if node.name.starts_with('v.trace_calls.') { + // do not instrument the tracing functions, to avoid infinite regress + return + } + fname := if node.is_method { + receiver_name := global_table.type_to_str(node.receiver.typ) + '${node.mod} ${receiver_name}.${node.name}/${node.params.len}' + } else { + '${node.mod} ${node.name}/${node.params.len}' + } + if !t.pref.trace_fns.any(fname.match_glob(it)) { + return + } + expr_stmt := ast.ExprStmt{ + expr: ast.CallExpr{ + mod: node.mod + pos: node.pos + language: .v + scope: node.scope + name: 'v.trace_calls.on_call' + args: [ + ast.CallArg{ + expr: ast.StringLiteral{ + val: fname + } + typ: ast.string_type_idx + }, + ] + } + } + node.stmts.prepend(expr_stmt) }