diff --git a/src/TimerOutput.jl b/src/TimerOutput.jl index 6390e36..fdf9414 100644 --- a/src/TimerOutput.jl +++ b/src/TimerOutput.jl @@ -172,7 +172,7 @@ Base.@deprecate get_defaultimer get_defaulttimer # Macro macro timeit(args...) - blocks = timer_expr(__module__, false, args...) + blocks = timer_expr(__source__, __module__, false, args...) if blocks isa Expr blocks else @@ -191,7 +191,7 @@ macro timeit_debug(args...) Core.eval(__module__, :(timeit_debug_enabled() = false)) end - blocks = timer_expr(__module__, true, args...) + blocks = timer_expr(__source__, __module__, true, args...) if blocks isa Expr blocks else @@ -234,28 +234,28 @@ function _esc(ex) end end -function timer_expr(m::Module, is_debug::Bool, ex::Expr) - is_func_def(ex) && return timer_expr_func(m, is_debug, :($(TimerOutputs.DEFAULT_TIMER)), ex) - return _esc(_timer_expr(m, is_debug, :($(TimerOutputs).DEFAULT_TIMER))) +function timer_expr(source::LineNumberNode, m::Module, is_debug::Bool, ex::Expr) + is_func_def(ex) && return timer_expr_func(source, m, is_debug, :($(TimerOutputs.DEFAULT_TIMER)), ex) + return _esc(_timer_expr(source, m, is_debug, :($(TimerOutputs).DEFAULT_TIMER))) end -function timer_expr(m::Module, is_debug::Bool, label_or_to, ex::Expr) - is_func_def(ex) && return timer_expr_func(m, is_debug, label_or_to, ex) - return _esc(_timer_expr(m, is_debug, :($(TimerOutputs).DEFAULT_TIMER), label_or_to)) +function timer_expr(source::LineNumberNode, m::Module, is_debug::Bool, label_or_to, ex::Expr) + is_func_def(ex) && return timer_expr_func(source, m, is_debug, label_or_to, ex) + return _esc(_timer_expr(source, m, is_debug, :($(TimerOutputs).DEFAULT_TIMER), label_or_to)) end -function timer_expr(m::Module, is_debug::Bool, label::String, ex::Expr) - is_func_def(ex) && return timer_expr_func(m, is_debug, :($(TimerOutputs).DEFAULT_TIMER), ex, label) - return _esc(_timer_expr(m, is_debug, :($(TimerOutputs).DEFAULT_TIMER), label)) +function timer_expr(source::LineNumberNode, m::Module, is_debug::Bool, label::String, ex::Expr) + is_func_def(ex) && return timer_expr_func(source, m, is_debug, :($(TimerOutputs).DEFAULT_TIMER), ex, label) + return _esc(_timer_expr(source, m, is_debug, :($(TimerOutputs).DEFAULT_TIMER), label)) end -function timer_expr(m::Module, is_debug::Bool, to, label, ex::Expr) - is_func_def(ex) && return timer_expr_func(m, is_debug, to, ex, label) - return _esc(_timer_expr(m, is_debug, to, label)) +function timer_expr(source::LineNumberNode, m::Module, is_debug::Bool, to, label, ex::Expr) + is_func_def(ex) && return timer_expr_func(source, m, is_debug, to, ex, label) + return _esc(_timer_expr(source, m, is_debug, to, label)) end # no ex given, so just return before and after for construction in the macro -function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOutput}, label) +function _timer_expr(source::LineNumberNode, m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOutput}, label) @gensym local_to enabled accumulated_data b₀ t₀ val timeit_block = quote $local_to = $to @@ -289,7 +289,7 @@ function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOut end # ex given, so return the whole thing -function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOutput}, label, ex::Expr) +function _timer_expr(source::LineNumberNode, m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOutput}, label, ex::Expr) @gensym local_to enabled accumulated_data b₀ t₀ val timeit_block = quote $local_to = $to @@ -310,20 +310,26 @@ function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOut $val end - if is_debug - return Base.remove_linenums!(quote + result_expr = if is_debug + quote if $m.timeit_debug_enabled() $timeit_block else $ex end - end) + end else - return Base.remove_linenums!(timeit_block) + timeit_block end + + # remove existing line numbers (#77) but add in the source for code coverage (#194) + result_expr = Base.remove_linenums!(result_expr) + pushfirst!(result_expr.args, source) + + return result_expr end -function timer_expr_func(m::Module, is_debug::Bool, to, expr::Expr, label=nothing) +function timer_expr_func(source::LineNumberNode, m::Module, is_debug::Bool, to, expr::Expr, label=nothing) expr = macroexpand(m, expr) def = splitdef(expr) @@ -334,10 +340,10 @@ function timer_expr_func(m::Module, is_debug::Bool, to, expr::Expr, label=nothin @inline function inner() $(def[:body]) end - $(_timer_expr(m, is_debug, to, label, :(inner()))) + $(_timer_expr(source, m, is_debug, to, label, :(inner()))) end else - _timer_expr(m, is_debug, to, label, def[:body]) + _timer_expr(source, m, is_debug, to, label, def[:body]) end return esc(combinedef(def)) diff --git a/test/TestPkg/Project.toml b/test/TestPkg/Project.toml new file mode 100644 index 0000000..4aade3b --- /dev/null +++ b/test/TestPkg/Project.toml @@ -0,0 +1,6 @@ +name = "TestPkg" +uuid = "a1172fb3-f03b-46d1-aab3-7b5cb3128a7b" +version = "0.1.0" + +[deps] +TimerOutputs = "a759f4b9-e2f1-59dc-863e-4aeb61b1ea8f" diff --git a/test/TestPkg/src/TestPkg.jl b/test/TestPkg/src/TestPkg.jl new file mode 100644 index 0000000..be6ec15 --- /dev/null +++ b/test/TestPkg/src/TestPkg.jl @@ -0,0 +1,11 @@ +module TestPkg + +using TimerOutputs + +const TIMER = TimerOutput() + +@timeit TIMER function abc() + 1 + 1 +end + +end # module TestPkg diff --git a/test/coverage_script.jl b/test/coverage_script.jl new file mode 100644 index 0000000..c8120ba --- /dev/null +++ b/test/coverage_script.jl @@ -0,0 +1,11 @@ +# entrypoint to TestPkg to invoke `abc` +using TimerOutputs + +push!(LOAD_PATH, joinpath(pkgdir(TimerOutputs), "test", "TestPkg")) +try + using TestPkg + + TestPkg.abc() +finally + pop!(LOAD_PATH) +end diff --git a/test/runtests.jl b/test/runtests.jl index 50c60e7..4710be7 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -759,3 +759,20 @@ end flamegraph(to) flamegraph(to, crop_root=true) end + +function foo_77(::Float64) end + +@testset "Stacktraces (#77)" begin + err = try + @timeit "foo_77" foo_77(1) + catch e + sprint(Base.display_error, e, catch_backtrace()) + end + + @test err isa AbstractString + + # this err shouldn't have any stacktrace pointing into TimerOutputs.jl + @test !contains(err, "src/TimerOutput.jl:") +end + +include("test_coverage.jl") diff --git a/test/test_coverage.jl b/test/test_coverage.jl new file mode 100644 index 0000000..410bb3b --- /dev/null +++ b/test/test_coverage.jl @@ -0,0 +1,16 @@ +function find_cov_files() + pkg = joinpath(pkgdir(TimerOutputs), "test", "TestPkg") + return filter(endswith(".cov"), readdir(joinpath(pkg, "src"); join=true)) +end + +# remove existing coverage +foreach(rm, find_cov_files()) + +@testset "functions defined with `@timeit` macro generate code coverage" begin + @test isempty(find_cov_files()) + + script = joinpath(pkgdir(TimerOutputs), "test", "coverage_script.jl") + run(`julia --startup-file=no --project=$(pkgdir(TimerOutputs)) --check-bounds=yes --code-coverage $script`) + + @test !isempty(find_cov_files()) +end