diff --git a/NEWS.md b/NEWS.md index 3850403a9aeee..ef8c434f10067 100644 --- a/NEWS.md +++ b/NEWS.md @@ -29,6 +29,7 @@ Command-line option changes * The option `--sysimage-native-code=no` has been deprecated. * The `JULIA_CPU_TARGET` environment variable now supports a `sysimage` keyword to match (or extend) the CPU target used to build the current system image ([#58970]). * The `--code-coverage=all` option now automatically throws away sysimage caches so that code coverage can be accurately measured on methods within the sysimage. It is thrown away after startup (and after startup.jl), before any user code is executed ([#59234]) +* New `--trace-eval` command-line option to show expressions being evaluated during top-level evaluation. Supports `--trace-eval=loc` or just `--trace-eval` (show location only), `--trace-eval=full` (show full expressions), and `--trace-eval=no` (disable tracing). Also adds `Base.TRACE_EVAL` global control that takes priority over the command-line option and can be set to `:no`, `:loc`, `:full`, or `nothing` (to use command-line setting). ([#57137]) Multi-threading changes ----------------------- diff --git a/base/loading.jl b/base/loading.jl index 2da72b7828ea0..ecbb8db4a8eb6 100644 --- a/base/loading.jl +++ b/base/loading.jl @@ -2323,6 +2323,37 @@ const toplevel_load = Ref(true) const _require_world_age = Ref{UInt}(typemax(UInt)) +""" + Base.TRACE_EVAL + +Global control for expression tracing during top-level evaluation. This setting takes priority +over the `--trace-eval` command-line option. + +Set to: +- `nothing` - use the command-line `--trace-eval` setting (default) +- `:no` - disable expression tracing +- `:loc` - show only location information during evaluation +- `:full` - show full expressions being evaluated + +# Examples +```julia +# Enable full expression tracing +Base.TRACE_EVAL = :full + +# Show only locations +Base.TRACE_EVAL = :loc + +# Disable tracing (overrides command-line setting) +Base.TRACE_EVAL = :no + +# Reset to use command-line setting +Base.TRACE_EVAL = nothing +``` + +See also: [Command-line Interface](@ref cli) for the `--trace-eval` option. +""" +TRACE_EVAL::Union{Symbol,Nothing} = nothing + """ require(into::Module, module::Symbol) @@ -2862,6 +2893,28 @@ function include_string(mapexpr::Function, mod::Module, code::AbstractString, # Wrap things to be eval'd in a :toplevel expr to carry line # information as part of the expr. line_and_ex.args[2] = ex + # Check global TRACE_EVAL first, fall back to command line option + trace_eval_setting = TRACE_EVAL + trace_eval = if trace_eval_setting !== nothing + # Convert symbol to integer value + setting = trace_eval_setting + if setting === :no + 0 + elseif setting === :loc + 1 + elseif setting === :full + 2 + else + error("Invalid TRACE_EVAL value: $(setting). Must be :no, :loc, or :full") + end + else + JLOptions().trace_eval + end + if trace_eval == 2 # show everything + println(stderr, "eval: ", line_and_ex) + elseif trace_eval == 1 # show top location only + println(stderr, "eval: ", line_and_ex.args[1]) + end result = Core.eval(mod, line_and_ex) end return result diff --git a/base/options.jl b/base/options.jl index dae4428b2209b..1380ac2b16839 100644 --- a/base/options.jl +++ b/base/options.jl @@ -64,6 +64,7 @@ struct JLOptions heap_target_increment::UInt64 trace_compile_timing::Int8 trim::Int8 + trace_eval::Int8 task_metrics::Int8 timeout_for_safepoint_straggler_s::Int16 gc_sweep_always_full::Int8 diff --git a/doc/man/julia.1 b/doc/man/julia.1 index 9646464e1e63d..a1992ccafaafc 100644 --- a/doc/man/julia.1 +++ b/doc/man/julia.1 @@ -294,6 +294,13 @@ If --trace-compile is enabled show how long each took to compile in ms --trace-dispatch={stderr|name} Print precompile statements for methods dispatched during execution or save to stderr or a path. +.TP +--trace-eval[={no*|loc|full}] +Show top-level expressions being evaluated. `loc` shows location info only, +`full` shows full expressions (omitting setting is equivalent to `loc`). +Only shows the outermost expression being evaluated, not internal function calls. +Can be controlled programmatically via Base.TRACE_EVAL. + .TP --task-metrics={yes|no*} Enable the collection of per-task metrics. diff --git a/doc/src/base/base.md b/doc/src/base/base.md index 774c277350bd6..eb40fc96c384e 100644 --- a/doc/src/base/base.md +++ b/doc/src/base/base.md @@ -379,6 +379,7 @@ Base.@elapsed Base.@allocated Base.@allocations Base.@lock_conflicts +Base.TRACE_EVAL Base.EnvDict Base.ENV Base.Sys.STDLIB diff --git a/doc/src/manual/command-line-interface.md b/doc/src/manual/command-line-interface.md index b8ae83620da50..416cba9c6a48d 100644 --- a/doc/src/manual/command-line-interface.md +++ b/doc/src/manual/command-line-interface.md @@ -219,6 +219,7 @@ The following is a complete list of command-line switches available when launchi |`--trace-compile={stderr\|name}` |Print precompile statements for methods compiled during execution or save to stderr or a path. Methods that were recompiled are printed in yellow or with a trailing comment if color is not supported| |`--trace-compile-timing` |If `--trace-compile` is enabled show how long each took to compile in ms| |`--trace-dispatch={stderr\|name}` |Print precompile statements for methods dispatched during execution or save to stderr or a path.| +|`--trace-eval[={no*\|loc\|full}]` |Show top-level expressions being evaluated. `loc` shows location info only, `full` shows full expressions (omitting setting is equivalent to `loc`). Only shows the outermost expression being evaluated, not internal function calls. See also [`Base.TRACE_EVAL`](@ref).| |`--image-codegen` |Force generate code in imaging mode| |`--permalloc-pkgimg={yes\|no*}` |Copy the data section of package images into memory| |`--trim={no*\|safe\|unsafe\|unsafe-warn}` |Build a sysimage including only code provably reachable from methods marked by calling `entrypoint`. The three non-default options differ in how they handle dynamic call sites. In safe mode, such sites result in compile-time errors. In unsafe mode, such sites are allowed but the resulting binary might be missing needed code and can throw runtime errors. With unsafe-warn, such sites will trigger warnings at compile-time and might error at runtime.| diff --git a/doc/src/manual/performance-tips.md b/doc/src/manual/performance-tips.md index 90a40337e081a..8bebbe6e37c7e 100644 --- a/doc/src/manual/performance-tips.md +++ b/doc/src/manual/performance-tips.md @@ -1544,6 +1544,36 @@ Note the `--startup-file=no` which helps isolate the test from packages you may More analysis of the reasons for recompilation can be achieved with the [`SnoopCompile`](https://github.com/timholy/SnoopCompile.jl) package. +### Tracing expression evaluation + +If you need to understand what code is being evaluated during test or script execution, +you can use the `--trace-eval` command-line option or the [`Base.TRACE_EVAL`](@ref) global control to trace the outermost expressions being evaluated (top-level statements). Note this does not individually report the contents of function calls or code blocks: + +```bash +# Show only location information during evaluation +julia --trace-eval=loc script.jl + +# Show full expressions being evaluated +julia --trace-eval=full script.jl +``` + +You can also control this programmatically: + +```julia +# Enable full expression tracing +Base.TRACE_EVAL = :full + +# Show only locations +Base.TRACE_EVAL = :loc + +# Disable tracing +Base.TRACE_EVAL = :no + +# Reset to use command-line setting +Base.TRACE_EVAL = nothing +``` + + ### Reducing precompilation time If package precompilation is taking a long time, one option is to set the following internal and then precompile. diff --git a/src/jloptions.c b/src/jloptions.c index b35a9705aba18..62de7732829dd 100644 --- a/src/jloptions.c +++ b/src/jloptions.c @@ -157,6 +157,7 @@ JL_DLLEXPORT void jl_init_options(void) 0, // heap-target-increment 0, // trace_compile_timing JL_TRIM_NO, // trim + 0, // trace-eval 0, // task_metrics -1, // timeout_for_safepoint_straggler_s 0, // gc_sweep_always_full @@ -344,6 +345,7 @@ static const char opts_hidden[] = " With unsafe-warn warnings will be printed for\n" " dynamic call sites that might lead to such errors.\n" " In safe mode compile-time errors are given instead.\n" + " --trace-eval={loc|full|no*} Show the expression being evaluated before eval.\n" " --hard-heap-limit=[] Set a hard limit on the heap size: if we ever\n" " go above this limit, we will abort. The value\n" " may be specified as a number of bytes,\n" @@ -410,6 +412,7 @@ JL_DLLEXPORT void jl_parse_opts(int *argcp, char ***argvp) opt_gc_threads, opt_permalloc_pkgimg, opt_trim, + opt_trace_eval, opt_experimental_features, opt_compress_sysimage, }; @@ -484,6 +487,7 @@ JL_DLLEXPORT void jl_parse_opts(int *argcp, char ***argvp) { "gc-sweep-always-full", no_argument, 0, opt_gc_sweep_always_full }, { "trim", optional_argument, 0, opt_trim }, { "compress-sysimage", required_argument, 0, opt_compress_sysimage }, + { "trace-eval", optional_argument, 0, opt_trace_eval }, { 0, 0, 0, 0 } }; @@ -1058,6 +1062,16 @@ JL_DLLEXPORT void jl_parse_opts(int *argcp, char ***argvp) else jl_errorf("julia: invalid argument to --trim={safe|no|unsafe|unsafe-warn} (%s)", optarg); break; + case opt_trace_eval: + if (optarg == NULL || !strcmp(optarg,"loc")) + jl_options.trace_eval = 1; + else if (!strcmp(optarg,"full")) + jl_options.trace_eval = 2; + else if (!strcmp(optarg,"no")) + jl_options.trace_eval = 0; + else + jl_errorf("julia: invalid argument to --trace-eval={yes|no} (%s)", optarg); + break; case opt_task_metrics: if (!strcmp(optarg, "no")) jl_options.task_metrics = JL_OPTIONS_TASK_METRICS_OFF; diff --git a/src/jloptions.h b/src/jloptions.h index 013e65345b022..2bf4707703f0d 100644 --- a/src/jloptions.h +++ b/src/jloptions.h @@ -68,6 +68,7 @@ typedef struct { uint64_t heap_target_increment; int8_t trace_compile_timing; int8_t trim; + int8_t trace_eval; int8_t task_metrics; int16_t timeout_for_safepoint_straggler_s; int8_t gc_sweep_always_full; diff --git a/test/cmdlineargs.jl b/test/cmdlineargs.jl index aa7e852905360..526aa833c7544 100644 --- a/test/cmdlineargs.jl +++ b/test/cmdlineargs.jl @@ -891,6 +891,64 @@ let exename = `$(Base.julia_cmd()) --startup-file=no --color=no` @test occursin("precompile(Tuple{typeof(Main.foo), Int", _stderr) end + # --trace-eval + let + # Test --trace-eval=loc (location only) + mktempdir() do dir + testfile = joinpath(dir, "test.jl") + write(testfile, "x = 1 + 1\ny = x * 2") + success, out, err = readchomperrors(`$exename --trace-eval=loc $testfile`) + @test success + @test occursin("eval: #=", err) + @test !occursin("eval: \$(Expr(:toplevel", err) # Should not show full expressions + end + end + + let + # Test --trace-eval=full (full expressions) + mktempdir() do dir + testfile = joinpath(dir, "test.jl") + write(testfile, "x = 1 + 1\ny = x * 2") + success, out, err = readchomperrors(`$exename --trace-eval=full $testfile`) + @test success + @test occursin("eval: \$(Expr(:toplevel", err) # Should show full expressions + @test occursin("x = 1 + 1", err) + end + end + + let + # Test --trace-eval=no (disabled) + mktempdir() do dir + testfile = joinpath(dir, "test.jl") + write(testfile, "x = 1 + 1\ny = x * 2") + success, out, err = readchomperrors(`$exename --trace-eval=no $testfile`) + @test success + @test !occursin("eval:", err) # Should not show any eval traces + end + end + + let + # Test Base.TRACE_EVAL global control takes priority + mktempdir() do dir + testfile = joinpath(dir, "test.jl") + write(testfile, """ + Base.TRACE_EVAL = :full + x = 1 + 1 + Base.TRACE_EVAL = :no + y = x * 2 + """) + success, out, err = readchomperrors(`$exename --trace-eval=loc $testfile`) # Command line says :loc, but code overrides + @test success + # Should show full expression for x = 1 + 1 (Base.TRACE_EVAL = :full) + @test occursin("eval: \$(Expr(:toplevel", err) + @test occursin("x = 1 + 1", err) + # Should not show trace for y = x * 2 (Base.TRACE_EVAL = :no) + lines = split(err, '\n') + y_lines = filter(line -> occursin("y = x * 2", line), lines) + @test length(y_lines) == 0 # No eval trace for y assignment + end + end + # test passing arguments mktempdir() do dir testfile, io = mktemp(dir)