From a6d617b31449f3c7f20d25c70937702ac3079cbb Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Thu, 18 Mar 2021 21:13:59 +0100 Subject: [PATCH 01/11] Define dummy NoTimerOutput --- src/NoTimerOutput.jl | 19 +++++++++++++++++++ src/TimerOutput.jl | 10 +++++++++- src/TimerOutputs.jl | 2 ++ src/show.jl | 6 +++--- 4 files changed, 33 insertions(+), 4 deletions(-) create mode 100644 src/NoTimerOutput.jl diff --git a/src/NoTimerOutput.jl b/src/NoTimerOutput.jl new file mode 100644 index 0000000..2f5730a --- /dev/null +++ b/src/NoTimerOutput.jl @@ -0,0 +1,19 @@ +struct NoTimerOutput <: AbstractTimerOutput + name::String + NoTimerOutput(label::String = "root") = new(label) +end + +isdummy(::NoTimerOutput) = true + +Base.copy(to::NoTimerOutput) = NoTimerOutput(to.name) + +# Add definitions for exported methods +reset_timer!(to::NoTimerOutput) = to +timeit(f::Function, ::NoTimerOutput, ::String) = f() +enable_timer!(to::NoTimerOutput) = true +disable_timer!(to::NoTimerOutput) = false + +function Base.show(io::IO, to::NoTimerOutput) + # TODO modify this? + print(io, "Timer \"", to.name, "\" is a dummy timer") +end diff --git a/src/TimerOutput.jl b/src/TimerOutput.jl index ac1187e..a9f1aff 100644 --- a/src/TimerOutput.jl +++ b/src/TimerOutput.jl @@ -19,7 +19,12 @@ end ############### # TimerOutput # ############### -mutable struct TimerOutput + +abstract type AbstractTimerOutput end + +isdummy(::AbstractTimerOutput) = false + +mutable struct TimerOutput <: AbstractTimerOutput start_data::TimeData accumulated_data::TimeData inner_timers::Dict{String,TimerOutput} @@ -201,6 +206,9 @@ function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOut @gensym local_to enabled accumulated_data b₀ t₀ val timeit_block = quote $local_to = $to + if isdummy($local_to) + return $(esc(ex)) + end $enabled = $local_to.enabled if $enabled $accumulated_data = $(push!)($local_to, $label) diff --git a/src/TimerOutputs.jl b/src/TimerOutputs.jl index 4979733..d41da4f 100644 --- a/src/TimerOutputs.jl +++ b/src/TimerOutputs.jl @@ -5,6 +5,7 @@ using ExprTools import Base: show, time_ns export TimerOutput, @timeit, @timeit_debug, reset_timer!, print_timer, timeit, enable_timer!, disable_timer!, @notimeit +export NoTimerOutput # https://github.com/JuliaLang/julia/pull/33717 if VERSION < v"1.4.0-DEV.475" @@ -21,6 +22,7 @@ using Printf include("TimerOutput.jl") +include("NoTimerOutput.jl") include("show.jl") include("utilities.jl") diff --git a/src/show.jl b/src/show.jl index f917269..687e940 100644 --- a/src/show.jl +++ b/src/show.jl @@ -1,9 +1,9 @@ print_timer(; kwargs...) = print_timer(stdout; kwargs...) -print_timer(to::TimerOutput; kwargs...) = print_timer(stdout, to; kwargs...) +print_timer(to::AbstractTimerOutput; kwargs...) = print_timer(stdout, to; kwargs...) print_timer(io::IO; kwargs...) = print_timer(io, DEFAULT_TIMER; kwargs...) -print_timer(io::IO, to::TimerOutput; kwargs...) = (show(io, to; kwargs...); println(io)) +print_timer(io::IO, to::AbstractTimerOutput; kwargs...) = (show(io, to; kwargs...); println(io)) -Base.show(to::TimerOutput; kwargs...) = show(stdout, to; kwargs...) +Base.show(to::AbstractTimerOutput; kwargs...) = show(stdout, to; kwargs...) function Base.show(io::IO, to::TimerOutput; allocations::Bool = true, sortby::Symbol = :time, linechars::Symbol = :unicode, compact::Bool = false, title::String = "") sortby in (:time, :ncalls, :allocations, :name) || throw(ArgumentError("sortby should be :time, :allocations, :ncalls or :name, got $sortby")) linechars in (:unicode, :ascii) || throw(ArgumentError("linechars should be :unicode or :ascii, got $linechars")) From 4a8a18d29094d083ebdd7e13a61964db2172b07b Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Fri, 19 Mar 2021 08:16:21 +0100 Subject: [PATCH 02/11] Export AbstractTimerOutput --- src/TimerOutputs.jl | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/TimerOutputs.jl b/src/TimerOutputs.jl index d41da4f..19ec622 100644 --- a/src/TimerOutputs.jl +++ b/src/TimerOutputs.jl @@ -5,7 +5,7 @@ using ExprTools import Base: show, time_ns export TimerOutput, @timeit, @timeit_debug, reset_timer!, print_timer, timeit, enable_timer!, disable_timer!, @notimeit -export NoTimerOutput +export AbtractTimerOutput, NoTimerOutput # https://github.com/JuliaLang/julia/pull/33717 if VERSION < v"1.4.0-DEV.475" From 075802551f397cfec195f78a7c8154913412e7d9 Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Mon, 22 Mar 2021 09:06:19 +0100 Subject: [PATCH 03/11] Adapt `@notimeit` for NoTimerOutput --- src/TimerOutput.jl | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/TimerOutput.jl b/src/TimerOutput.jl index a9f1aff..e527fb1 100644 --- a/src/TimerOutput.jl +++ b/src/TimerOutput.jl @@ -365,6 +365,9 @@ notimeit_expr(ex::Expr) = notimeit_expr(:($(TimerOutputs.DEFAULT_TIMER)), ex) function notimeit_expr(to, ex::Expr) return quote local to = $(esc(to)) + if isdummy(to) + return $(esc(ex)) + end local enabled = to.enabled $(disable_timer!)(to) local val From da12ae6e69e2967dd93535aec38a2be2e3217ead Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Mon, 22 Mar 2021 09:06:56 +0100 Subject: [PATCH 04/11] Remove comment --- src/NoTimerOutput.jl | 1 - 1 file changed, 1 deletion(-) diff --git a/src/NoTimerOutput.jl b/src/NoTimerOutput.jl index 2f5730a..5631430 100644 --- a/src/NoTimerOutput.jl +++ b/src/NoTimerOutput.jl @@ -14,6 +14,5 @@ enable_timer!(to::NoTimerOutput) = true disable_timer!(to::NoTimerOutput) = false function Base.show(io::IO, to::NoTimerOutput) - # TODO modify this? print(io, "Timer \"", to.name, "\" is a dummy timer") end From 689574656b4397f8c8f6edca77af6c130da01b72 Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Mon, 22 Mar 2021 09:07:02 +0100 Subject: [PATCH 05/11] Add some tests --- test/runtests.jl | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/test/runtests.jl b/test/runtests.jl index f969690..5946407 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -511,3 +511,21 @@ TimerOutputs.enable_debug_timings(@__MODULE__) @test ncalls(subto["baz"]) == 2 end end + +@testset "dummy timers" begin + to = TimerOutput() + nt = NoTimerOutput() + @test repr(nt) == "Timer \"root\" is a dummy timer" + + @test copy(nt) == nt + @test reset_timer!(nt) === nt + @test enable_timer!(nt) == true + @test disable_timer!(nt) == false + + foo(x) = x + x + @timeit tt foo(x, tt) = foo(x) + @test foo(4) == foo(4, to) + @test foo(4) == foo(4, nt) + + @test @notimeit(nt, foo(3)) == foo(3) +end From c5a22049ca8abca2af228d2f2ae9372470b70f4f Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Mon, 22 Mar 2021 09:22:06 +0100 Subject: [PATCH 06/11] More compatibility with TimerOutput --- src/NoTimerOutput.jl | 16 ++++++++++++++-- test/runtests.jl | 23 +++++++++++++++++++++++ 2 files changed, 37 insertions(+), 2 deletions(-) diff --git a/src/NoTimerOutput.jl b/src/NoTimerOutput.jl index 5631430..90fa0bd 100644 --- a/src/NoTimerOutput.jl +++ b/src/NoTimerOutput.jl @@ -10,8 +10,20 @@ Base.copy(to::NoTimerOutput) = NoTimerOutput(to.name) # Add definitions for exported methods reset_timer!(to::NoTimerOutput) = to timeit(f::Function, ::NoTimerOutput, ::String) = f() -enable_timer!(to::NoTimerOutput) = true -disable_timer!(to::NoTimerOutput) = false +enable_timer!(::NoTimerOutput) = true +disable_timer!(::NoTimerOutput) = false +flatten(to::NoTimerOutput) = to + +ncalls(::NoTimerOutput) = 0 +time(::NoTimerOutput) = 0 +allocated(::NoTimerOutput) = 0 +tottime(::NoTimerOutput) = 0 +totallocated(::NoTimerOutput) = 0 + +complement!(to::NoTimerOutput) = to + +Base.haskey(::NoTimerOutput, ::String) = false +Base.getindex(::NoTimerOutput, key::String) = throw(KeyError(key)) function Base.show(io::IO, to::NoTimerOutput) print(io, "Timer \"", to.name, "\" is a dummy timer") diff --git a/test/runtests.jl b/test/runtests.jl index 5946407..2fda80b 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -515,12 +515,19 @@ end @testset "dummy timers" begin to = TimerOutput() nt = NoTimerOutput() + @test repr(nt) == "Timer \"root\" is a dummy timer" + let io = IOBuffer() + print_timer(io, nt) + @test String(take!(io)) == "Timer \"root\" is a dummy timer\n" + end + @test copy(nt) == nt @test reset_timer!(nt) === nt @test enable_timer!(nt) == true @test disable_timer!(nt) == false + @test flatten(nt) === nt foo(x) = x + x @timeit tt foo(x, tt) = foo(x) @@ -528,4 +535,20 @@ end @test foo(4) == foo(4, nt) @test @notimeit(nt, foo(3)) == foo(3) + + @timeit to "sin" sin(3) + @timeit nt "sin" sin(3) + + @test haskey(to, "sin") + @test !haskey(nt, "sin") + + @test to["sin"] isa TimerOutput + @test_throws KeyError("sin") nt["sin"] + + @test ncalls(nt) == 0 + @test TimerOutputs.time(nt) == 0 + @test TimerOutputs.allocated(nt) == 0 + @test TimerOutputs.tottime(nt) == 0 + @test TimerOutputs.totallocated(nt) == 0 + @test TimerOutputs.complement!(nt) === nt end From 99915a0619cbfc2a1d10035d4cd54dfaf7f71443 Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Mon, 22 Mar 2021 09:37:45 +0100 Subject: [PATCH 07/11] Add some documentation --- README.md | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/README.md b/README.md index 723170f..55ba70b 100644 --- a/README.md +++ b/README.md @@ -397,6 +397,10 @@ By default, debug timings are disabled, and this conditional should be optimized If a user calls `TimerOutputs.enable_debug_timings()`, the `.timeit_debug_enabled()` method will be redefined, causing all dependent methods to be recompiled within that module. This may take a while, and hence is intended only for debugging usage, however all calls to `@timeit_debug` (within that Module) will thereafter be enabled. +As an alternative to `@timeit_debug`, this package also provides a `NoTimerOutput` type that allows disabling all timings with zero overhead. +This type represents a dummy timer which acts as a drop-in replacement for regular `TimerOutput`s. +From a user's perspective, it suffices to replace `to = TimerOutput()` by `to = NoTimerOutput()` at the beginning of their code to fully disable timers. + ## Author Kristoffer Carlsson - @KristofferC From 2ae94b6b10693470370c0132edd8ab3f917fd535 Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Tue, 23 Mar 2021 20:02:14 +0100 Subject: [PATCH 08/11] Rename NoTimerOutput -> NullTimer --- README.md | 4 ++-- src/NoTimerOutput.jl | 30 ------------------------------ src/NullTimer.jl | 30 ++++++++++++++++++++++++++++++ src/TimerOutputs.jl | 4 ++-- test/runtests.jl | 2 +- 5 files changed, 35 insertions(+), 35 deletions(-) delete mode 100644 src/NoTimerOutput.jl create mode 100644 src/NullTimer.jl diff --git a/README.md b/README.md index 55ba70b..f419a08 100644 --- a/README.md +++ b/README.md @@ -397,9 +397,9 @@ By default, debug timings are disabled, and this conditional should be optimized If a user calls `TimerOutputs.enable_debug_timings()`, the `.timeit_debug_enabled()` method will be redefined, causing all dependent methods to be recompiled within that module. This may take a while, and hence is intended only for debugging usage, however all calls to `@timeit_debug` (within that Module) will thereafter be enabled. -As an alternative to `@timeit_debug`, this package also provides a `NoTimerOutput` type that allows disabling all timings with zero overhead. +As an alternative to `@timeit_debug`, this package also provides a `NullTimer` type that allows disabling all timings with zero overhead. This type represents a dummy timer which acts as a drop-in replacement for regular `TimerOutput`s. -From a user's perspective, it suffices to replace `to = TimerOutput()` by `to = NoTimerOutput()` at the beginning of their code to fully disable timers. +From a user's perspective, it suffices to replace `to = TimerOutput()` by `to = NullTimer()` at the beginning of their code to fully disable timers. ## Author diff --git a/src/NoTimerOutput.jl b/src/NoTimerOutput.jl deleted file mode 100644 index 90fa0bd..0000000 --- a/src/NoTimerOutput.jl +++ /dev/null @@ -1,30 +0,0 @@ -struct NoTimerOutput <: AbstractTimerOutput - name::String - NoTimerOutput(label::String = "root") = new(label) -end - -isdummy(::NoTimerOutput) = true - -Base.copy(to::NoTimerOutput) = NoTimerOutput(to.name) - -# Add definitions for exported methods -reset_timer!(to::NoTimerOutput) = to -timeit(f::Function, ::NoTimerOutput, ::String) = f() -enable_timer!(::NoTimerOutput) = true -disable_timer!(::NoTimerOutput) = false -flatten(to::NoTimerOutput) = to - -ncalls(::NoTimerOutput) = 0 -time(::NoTimerOutput) = 0 -allocated(::NoTimerOutput) = 0 -tottime(::NoTimerOutput) = 0 -totallocated(::NoTimerOutput) = 0 - -complement!(to::NoTimerOutput) = to - -Base.haskey(::NoTimerOutput, ::String) = false -Base.getindex(::NoTimerOutput, key::String) = throw(KeyError(key)) - -function Base.show(io::IO, to::NoTimerOutput) - print(io, "Timer \"", to.name, "\" is a dummy timer") -end diff --git a/src/NullTimer.jl b/src/NullTimer.jl new file mode 100644 index 0000000..c0921fb --- /dev/null +++ b/src/NullTimer.jl @@ -0,0 +1,30 @@ +struct NullTimer <: AbstractTimerOutput + name::String + NullTimer(label::String = "root") = new(label) +end + +isdummy(::NullTimer) = true + +Base.copy(to::NullTimer) = NullTimer(to.name) + +# Add definitions for exported methods +reset_timer!(to::NullTimer) = to +timeit(f::Function, ::NullTimer, ::String) = f() +enable_timer!(::NullTimer) = true +disable_timer!(::NullTimer) = false +flatten(to::NullTimer) = to + +ncalls(::NullTimer) = 0 +time(::NullTimer) = 0 +allocated(::NullTimer) = 0 +tottime(::NullTimer) = 0 +totallocated(::NullTimer) = 0 + +complement!(to::NullTimer) = to + +Base.haskey(::NullTimer, ::String) = false +Base.getindex(::NullTimer, key::String) = throw(KeyError(key)) + +function Base.show(io::IO, to::NullTimer) + print(io, "Timer \"", to.name, "\" is a dummy timer") +end diff --git a/src/TimerOutputs.jl b/src/TimerOutputs.jl index 19ec622..30294ac 100644 --- a/src/TimerOutputs.jl +++ b/src/TimerOutputs.jl @@ -5,7 +5,7 @@ using ExprTools import Base: show, time_ns export TimerOutput, @timeit, @timeit_debug, reset_timer!, print_timer, timeit, enable_timer!, disable_timer!, @notimeit -export AbtractTimerOutput, NoTimerOutput +export AbtractTimerOutput, NullTimer # https://github.com/JuliaLang/julia/pull/33717 if VERSION < v"1.4.0-DEV.475" @@ -22,7 +22,7 @@ using Printf include("TimerOutput.jl") -include("NoTimerOutput.jl") +include("NullTimer.jl") include("show.jl") include("utilities.jl") diff --git a/test/runtests.jl b/test/runtests.jl index 2fda80b..cdb75fd 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -514,7 +514,7 @@ end @testset "dummy timers" begin to = TimerOutput() - nt = NoTimerOutput() + nt = NullTimer() @test repr(nt) == "Timer \"root\" is a dummy timer" From 01fd57f3f5bbe8088cbf4af62106ddfc7f61482f Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Fri, 21 May 2021 17:33:27 +0200 Subject: [PATCH 09/11] Fix for recent changes in TimerOutputs --- src/TimerOutput.jl | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/TimerOutput.jl b/src/TimerOutput.jl index e527fb1..24c7fe3 100644 --- a/src/TimerOutput.jl +++ b/src/TimerOutput.jl @@ -206,8 +206,8 @@ function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOut @gensym local_to enabled accumulated_data b₀ t₀ val timeit_block = quote $local_to = $to - if isdummy($local_to) - return $(esc(ex)) + if TimerOutputs.isdummy($local_to) + return $ex end $enabled = $local_to.enabled if $enabled From 677cf13c6fc98519966bd3e31e9e3ac9157b7a97 Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Fri, 21 May 2021 17:47:19 +0200 Subject: [PATCH 10/11] Fix tests using ugly hack --- src/TimerOutput.jl | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/TimerOutput.jl b/src/TimerOutput.jl index 24c7fe3..9208afa 100644 --- a/src/TimerOutput.jl +++ b/src/TimerOutput.jl @@ -206,7 +206,7 @@ function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOut @gensym local_to enabled accumulated_data b₀ t₀ val timeit_block = quote $local_to = $to - if TimerOutputs.isdummy($local_to) + if Main.hasfield(typeof($local_to), :enabled) === false return $ex end $enabled = $local_to.enabled From 7f069468be49d66ad838fdc2227a22e523ae03db Mon Sep 17 00:00:00 2001 From: Juan Ignacio Polanco Date: Sat, 22 May 2021 07:46:57 +0200 Subject: [PATCH 11/11] Fix return issue with NullTimer --- src/TimerOutput.jl | 31 ++++++++++++++++--------------- 1 file changed, 16 insertions(+), 15 deletions(-) diff --git a/src/TimerOutput.jl b/src/TimerOutput.jl index 9208afa..2d5f791 100644 --- a/src/TimerOutput.jl +++ b/src/TimerOutput.jl @@ -207,22 +207,23 @@ function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOut timeit_block = quote $local_to = $to if Main.hasfield(typeof($local_to), :enabled) === false - return $ex - end - $enabled = $local_to.enabled - if $enabled - $accumulated_data = $(push!)($local_to, $label) + $val = $ex + else + $enabled = $local_to.enabled + if $enabled + $accumulated_data = $(push!)($local_to, $label) + end + $b₀ = $(gc_bytes)() + $t₀ = $(time_ns)() + $(Expr(:tryfinally, + :($val = $ex), + quote + if $enabled + $(do_accumulate!)($accumulated_data, $t₀, $b₀) + $(pop!)($local_to) + end + end)) end - $b₀ = $(gc_bytes)() - $t₀ = $(time_ns)() - $(Expr(:tryfinally, - :($val = $ex), - quote - if $enabled - $(do_accumulate!)($accumulated_data, $t₀, $b₀) - $(pop!)($local_to) - end - end)) $val end