diff --git a/Project.toml b/Project.toml index 75a700a..7461473 100644 --- a/Project.toml +++ b/Project.toml @@ -1,14 +1,16 @@ name = "TimerOutputs" uuid = "a759f4b9-e2f1-59dc-863e-4aeb61b1ea8f" -version = "0.5.23" +version = "0.6.0" [deps] ExprTools = "e2ba6199-217a-4e67-a87a-7c52f15ade04" Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7" +ScopedValues = "7e506255-f358-4e82-b7e4-beb19740aa63" [compat] ExprTools = "0.1.0" -julia = "1" +ScopedValues = "1.0.0" +julia = "1.8" [extras] Test = "8dfed614-e22c-5e08-85e1-65c5234f0b40" diff --git a/src/TimerOutput.jl b/src/TimerOutput.jl index 06379a6..b59debb 100644 --- a/src/TimerOutput.jl +++ b/src/TimerOutput.jl @@ -1,174 +1,112 @@ ############ # TimeData # ############ -mutable struct TimeData - ncalls::Int +struct TimeData + ncalls::Int64 time::Int64 allocs::Int64 - firstexec::Int64 end -TimeData(ncalls, time, allocs) = TimeData(ncalls, time, allocs, time) -Base.copy(td::TimeData) = TimeData(td.ncalls, td.time, td.allocs) -TimeData() = TimeData(0, 0, 0, time_ns()) +TimeData() = TimeData(0,0,0) function Base.:+(self::TimeData, other::TimeData) - TimeData(self.ncalls + other.ncalls, + TimeData(self.ncalls + self.ncalls, self.time + other.time, - self.allocs + other.allocs, - min(self.firstexec, other.firstexec)) + self.allocs + other.allocs) end -############### -# TimerOutput # -############### -mutable struct TimerOutput - start_data::TimeData - accumulated_data::TimeData - inner_timers::Dict{String,TimerOutput} - timer_stack::Vector{TimerOutput} - name::String - flattened::Bool - enabled::Bool - totmeasured::Tuple{Int64,Int64} - prev_timer_label::String - prev_timer::Union{TimerOutput,Nothing} - - function TimerOutput(label::String = "root") - start_data = TimeData(0, time_ns(), gc_bytes()) - accumulated_data = TimeData() - inner_timers = Dict{String,TimerOutput}() - timer_stack = TimerOutput[] - return new(start_data, accumulated_data, inner_timers, timer_stack, label, false, true, (0, 0), "", nothing) - end - - # Jeez... - TimerOutput(start_data, accumulated_data, inner_timers, timer_stack, name, flattened, enabled, totmeasured, prev_timer_label, - prev_timer) = new(start_data, accumulated_data, inner_timers, timer_stack, name, flattened, enabled, totmeasured, prev_timer_label, - prev_timer) - +mutable struct LList{T} + const next::LList{T} + const val::T + LList{T}() where T = new{T}() + LList(next::LList{T}, val::T) where T = new{T}(next, val) end -Base.copy(to::TimerOutput) = TimerOutput(copy(to.start_data), copy(to.accumulated_data), copy(to.inner_timers), - copy(to.timer_stack), to.name, to.flattened, to.enabled, to.totmeasured, "", nothing) - -const DEFAULT_TIMER = TimerOutput() -const _timers = Dict{String, TimerOutput}("Default" => DEFAULT_TIMER) -const _timers_lock = ReentrantLock() # needed for adding new timers on different threads -""" - get_timer(name::String) - -Returns the `TimerOutput` associated with `name`. -If no timers are associated with `name`, a new `TimerOutput` will be created. -""" -function get_timer(name::String) - lock(_timers_lock) do - if !haskey(_timers, name) - _timers[name] = TimerOutput(name) - end - return _timers[name] +function Base.show(io::IO, list::LList) + print(io, LList, "(") + first = true + while isdefined(list, :next) + first || print(io, ", ") + first = false + show(io, list.val) + list = list.next end + print(io, ")") end -# push! and pop! -function Base.push!(to::TimerOutput, label::String) - if length(to.timer_stack) == 0 # Root section - current_timer = to - else # Not a root section - current_timer = to.timer_stack[end] +function Base.iterate(list::LList{T}, state::Union{Nothing, LList{T}}=nothing) where T + if state === nothing + state = list end - # Fast path - if current_timer.prev_timer_label == label - timer = current_timer.prev_timer - else - maybe_timer = get(current_timer.inner_timers, label, nothing) - # this could be implemented more elegant using - # get!(() -> TimerOutput(label), current_timer.inner_timers, label) - # however that causes lots of allocations in - # julia v1.3 - if maybe_timer === nothing - timer = TimerOutput(label) - current_timer.inner_timers[label] = timer - else - timer = maybe_timer - end + if !isdefined(state, :next) + return nothing end - timer = timer::TimerOutput - current_timer.prev_timer_label = label - current_timer.prev_timer = timer + return (state.val, state.next) +end - push!(to.timer_stack, timer) - return timer.accumulated_data +Base.eltype(::LList{T}) where T = T +Base.IteratorSize(::Type{<:LList}) = Base.SizeUnknown() + + +############### +# TimerOutput # +############### +mutable struct TimerOutput + const name::String + const parent::Union{Nothing, TimerOutput} + @atomic data::Union{Nothing, TimeData} + @atomic children::LList{TimerOutput} + +end +function TimerOutput(name::String = "", parent=nothing) + return TimerOutput(name, parent, nothing, LList{TimerOutput}()) end +const TIMER = ScopedValue(TimerOutput()) -Base.pop!(to::TimerOutput) = pop!(to.timer_stack) +isroot(to::TimerOutput) = to.parent === nothing -# Only sum the highest parents -function totmeasured(to::TimerOutput) - t, b = Int64(0), Int64(0) - for section in values(to.inner_timers) - timedata = section.accumulated_data - t += timedata.time - b += timedata.allocs +function register!(to::TimerOutput) + # Note: Don't call register twice + parent = to.parent + if parent === nothing + return false + end + success = false + old = @atomic :acquire parent.children + while !success + new = LList(old, to) + old, success = @atomicreplace :acquire_release :acquire parent.children old => new end - return t, b + return true +end + +function finish!(to::TimerOutput, t₀, b₀) + data = TimeData(1, time_ns() - t₀, gc_bytes() - b₀) + @atomic to.data = data + register!(to) end function longest_name(to::TimerOutput, indent = 0) m = textwidth(to.name) + indent - for inner_timer in values(to.inner_timers) - m = max(m, longest_name(inner_timer, indent + 2)) + for child in to.children + m = max(m, longest_name(child, indent + 2)) end return m end - -# merging timer outputs -const merge_lock = ReentrantLock() # needed for merges of objects on different threads - -Base.merge(others::TimerOutput...) = merge!(TimerOutput(), others...) -function Base.merge!(self::TimerOutput, others::TimerOutput...; tree_point = String[]) - lock(merge_lock) do - for other in others - self.accumulated_data += other.accumulated_data - its = self.inner_timers - for point in tree_point - its = its[point].inner_timers - end - _merge(its, other.inner_timers) - end - return self - end -end -function _merge(self::Dict{String,TimerOutput}, other::Dict{String,TimerOutput}) - for key in keys(other) - if haskey(self, key) - self[key].accumulated_data += other[key].accumulated_data - _merge(self[key].inner_timers, other[key].inner_timers) - else - self[key] = deepcopy(other[key]) - end - end -end - ####### # API # ####### # Accessors -ncalls(to::TimerOutput) = to.accumulated_data.ncalls -allocated(to::TimerOutput) = to.accumulated_data.allocs -time(to::TimerOutput) = to.accumulated_data.time -totallocated(to::TimerOutput) = totmeasured(to)[2] -tottime(to::TimerOutput) = totmeasured(to)[1] +ncalls(to::TimerOutput) = to.data.ncalls +allocated(to::TimerOutput) = to.data.allocs +time(to::TimerOutput) = to._data.time -time() = time(DEFAULT_TIMER) -ncalls() = ncalls(DEFAULT_TIMER) -allocated() = allocated(DEFAULT_TIMER) -totallocated() = totmeasured(DEFAULT_TIMER)[2] -tottime() = totmeasured(DEFAULT_TIMER)[1] +time() = time(TIMER[]) +ncalls() = ncalls(TIMER[]) +allocated() = allocated(TIMER[]) -get_defaulttimer() = DEFAULT_TIMER -Base.@deprecate get_defaultimer get_defaulttimer +current_timer() = TIMER[] # Macro macro timeit(args...) @@ -194,7 +132,7 @@ function disable_debug_timings(m::Module) end end -timer_expr(args...) = throw(ArgumentError("invalid macro usage for @timeit, use as @timeit [to] label codeblock")) +timer_expr(args...) = throw(ArgumentError("invalid macro usage for @timeit, use as @timeit label codeblock")) function is_func_def(f) if isa(f, Expr) && (f.head === :function || Base.is_short_function_def(f)) @@ -205,44 +143,31 @@ function is_func_def(f) 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), ex)) + is_func_def(ex) && return timer_expr_func(m, is_debug, ex, nothing) + error("invalid macro usage for @timeit") 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, ex)) +function timer_expr(m::Module, is_debug::Bool, label, ex::Expr) + timer_expr(m, is_debug, string(label), ex) 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, ex)) -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, ex)) + is_func_def(ex) && return timer_expr_func(m, is_debug, ex, label) + return esc(_timer_expr(m, is_debug, label, ex)) end -function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOutput}, label, ex::Expr) - @gensym local_to enabled accumulated_data b₀ t₀ val +function _timer_expr(m::Module, is_debug::Bool, label, ex::Expr) + @gensym b₀ t₀ val timeit_block = quote - $local_to = $to - $enabled = $local_to.enabled - if $enabled - $accumulated_data = $(push!)($local_to, $label) + $scoped($(TIMER) => $(TimerOutput)($label, $(TIMER)[])) do # TODO can we have a macro form of this? + $b₀ = $(gc_bytes)() + $t₀ = $(time_ns)() + $(Expr(:tryfinally, + :($val = $ex), + :($(finish!)($(TIMER)[], $t₀, $b₀)) + )) + $val 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 if is_debug @@ -258,7 +183,7 @@ function _timer_expr(m::Module, is_debug::Bool, to::Union{Symbol, Expr, TimerOut end end -function timer_expr_func(m::Module, is_debug::Bool, to, expr::Expr, label=nothing) +function timer_expr_func(m::Module, is_debug::Bool, expr::Expr, label=nothing) expr = macroexpand(m, expr) def = splitdef(expr) @@ -269,132 +194,51 @@ 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(m, is_debug, label, :(inner()))) end else - _timer_expr(m, is_debug, to, label, def[:body]) + _timer_expr(m, is_debug, label, def[:body]) end return esc(combinedef(def)) end -function do_accumulate!(accumulated_data, t₀, b₀) - accumulated_data.time += time_ns() - t₀ - accumulated_data.allocs += gc_bytes() - b₀ - accumulated_data.ncalls += 1 -end - - -reset_timer!() = reset_timer!(DEFAULT_TIMER) +reset_timer!() = reset_timer!(TIMER[]) function reset_timer!(to::TimerOutput) - to.inner_timers = Dict{String,TimerOutput}() - to.start_data = TimeData(0, time_ns(), gc_bytes()) - to.accumulated_data = TimeData() - to.prev_timer_label = "" - to.prev_timer = nothing - resize!(to.timer_stack, 0) + @atomic to.data = nothing + @atomic to.children = LList{TimerOutput}() return to end -# We can remove this now that the @timeit macro is exception safe. -# Doesn't hurt to keep it for a while though -timeit(f::Function, label::String) = timeit(f, DEFAULT_TIMER, label) -function timeit(f::Function, to::TimerOutput, label::String) - accumulated_data = push!(to, label) - b₀ = gc_bytes() - t₀ = time_ns() - local val - try - val = f() - finally - accumulated_data.time += time_ns() - t₀ - accumulated_data.allocs += gc_bytes() - b₀ - accumulated_data.ncalls += 1 - pop!(to) - end - return val -end - -Base.haskey(to::TimerOutput, name::String) = haskey(to.inner_timers, name) -Base.getindex(to::TimerOutput, name::String) = to.inner_timers[name] - -function flatten(to::TimerOutput) - t, b = totmeasured(to) - inner_timers = Dict{String,TimerOutput}() - for inner_timer in values(to.inner_timers) - _flatten!(inner_timer, inner_timers) - end - toc = copy(to) - return TimerOutput(toc.start_data, toc.accumulated_data, inner_timers, TimerOutput[], "Flattened", true, true, (t, b), "", to) -end +function merge(self::TimerOutput, other::Union{TimerOutput, Nothing}=nothing) + if other !== nothing + @assert self.name == other.name - -function _flatten!(to::TimerOutput, inner_timers::Dict{String,TimerOutput}) - for inner_timer in values(to.inner_timers) - _flatten!(inner_timer, inner_timers) - end - - if haskey(inner_timers, to.name) - timer = inner_timers[to.name] - timer.accumulated_data += to.accumulated_data + data = self.data + other.data else - toc = copy(to) - toc.inner_timers = Dict{String,TimerOutput}() - inner_timers[toc.name] = toc + data = self.data end -end - -enable_timer!(to::TimerOutput=DEFAULT_TIMER) = to.enabled = true -disable_timer!(to::TimerOutput=DEFAULT_TIMER) = to.enabled = false - -# Macro to selectively disable timer for expression -macro notimeit(args...) - notimeit_expr(args...) -end - -# Default function throws an error for the benefit of the user -notimeit_expr(args...) = throw(ArgumentError("invalid macro usage for @notimeit, use as @notimeit [to] codeblock")) - -complement!() = complement!(DEFAULT_TIMER) -function complement!(to::TimerOutput) - if length(to.inner_timers) == 0 - return nothing - end - tot_time = to.accumulated_data.time - tot_allocs = to.accumulated_data.allocs - for timer in values(to.inner_timers) - tot_time -= timer.accumulated_data.time - tot_allocs -= timer.accumulated_data.allocs - complement!(timer) + accum = Dict{String, TimerOutput}() + for child in self.children + if !haskey(accum, child.name) + accum[child.name] = merge(child) + continue + end + accum[child.name] = merge(accum[child.name], child) end - tot_time = max(tot_time, 0) - tot_allocs = max(tot_allocs, 0) - if !(to.name in ["root", "Flattened"]) - name = string("~", to.name, "~") - timer = TimerOutput(to.start_data, TimeData(max(1,to.accumulated_data.ncalls), tot_time, tot_allocs), Dict{String,TimerOutput}(), TimerOutput[], name, false, true, (tot_time, tot_allocs), to.name, to) - to.inner_timers[name] = timer + if other !== nothing + for child in other.children + if !haskey(accum, child.name) + accum[child.name] = merge(child) + continue + end + accum[child.name] = merge(accum[child.name], child) + end end - return to -end - -# If @notimeit was called without a TimerOutput instance, use default timer -notimeit_expr(ex::Expr) = notimeit_expr(:($(TimerOutputs.DEFAULT_TIMER)), ex) - -# Disable timer, evaluate expression, restore timer to previous value, and return expression result -function notimeit_expr(to, ex::Expr) - return quote - local to = $(esc(to)) - local enabled = to.enabled - $(disable_timer!)(to) - local val - $(Expr(:tryfinally, - :(val = $(esc(ex))), - quote - if enabled - $(enable_timer!)(to) - end - end)) - val + list = LList{TimerOutput}() + for child in values(accum) + list = LList(list, child) end + return TimerOutput(self.name, self.parent, data, list) end diff --git a/src/TimerOutputs.jl b/src/TimerOutputs.jl index 1145e00..0859d1a 100644 --- a/src/TimerOutputs.jl +++ b/src/TimerOutputs.jl @@ -1,6 +1,7 @@ module TimerOutputs using ExprTools +using ScopedValues import Base: show, time_ns export TimerOutput, @timeit, @timeit_debug, reset_timer!, print_timer, timeit, diff --git a/src/compile.jl b/src/compile.jl index 9d1a5b7..f23ad1c 100644 --- a/src/compile.jl +++ b/src/compile.jl @@ -1,18 +1,14 @@ # To make it less likely that users measure TimerOutputs compilation time. let - to = TimerOutput() - @timeit to "1" string(1) + @timeit "1" string(1) end function _precompile_() ccall(:jl_generating_output, Cint, ()) == 1 || return nothing @assert Base.precompile(Tuple{typeof(print_timer), typeof(stdout), TimerOutput}) @assert Base.precompile(Tuple{typeof(print_timer), TimerOutput}) - @assert Base.precompile(Tuple{typeof(push!), TimerOutput, String}) + @assert Base.precompile(Tuple{typeof(finish!), TimerOutput, Int, Int}) @assert Base.precompile(Tuple{typeof(reset_timer!), TimerOutput}) - @assert Base.precompile(Tuple{typeof(disable_timer!), TimerOutput}) - @assert Base.precompile(Tuple{typeof(enable_timer!), TimerOutput}) - @assert Base.precompile(Tuple{typeof(complement!), TimerOutput}) - @assert Base.precompile(Tuple{typeof(do_accumulate!), TimeData, UInt64, Int64}) - @assert Base.precompile(Tuple{Type{TimerOutput}, String}) + @assert Base.precompile(Tuple{typeof(register!), TimerOutput}) + @assert Base.precompile(Tuple{Type{TimerOutput}, String, TimerOutput}) end diff --git a/src/show.jl b/src/show.jl index c9d2b47..5aa0f5d 100644 --- a/src/show.jl +++ b/src/show.jl @@ -4,14 +4,20 @@ print_timer(io::IO; kwargs...) = print_timer(io, DEFAULT_TIMER; kwargs...) print_timer(io::IO, to::TimerOutput; kwargs...) = (show(io, to; kwargs...); println(io)) Base.show(to::TimerOutput; 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, :firstexec) || throw(ArgumentError("sortby should be :time, :allocations, :ncalls, :name, or :firstexec, got $sortby")) +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, :name, got $sortby")) linechars in (:unicode, :ascii) || throw(ArgumentError("linechars should be :unicode or :ascii, got $linechars")) - t₀, b₀ = to.start_data.time, to.start_data.allocs - t₁, b₁ = time_ns(), gc_bytes() - Δt, Δb = t₁ - t₀, b₁ - b₀ - ∑t, ∑b = to.flattened ? to.totmeasured : totmeasured(to) + to = merge(to) + if !isroot(to) + data = to.data + else + data = sum(child->child.data, to.children, init=TimeData()) + end + ∑t, ∑b = data.time, data.allocs max_name = longest_name(to) available_width = displaysize(io)[2] @@ -34,21 +40,20 @@ function Base.show(io::IO, to::TimerOutput; allocations::Bool = true, sortby::Sy #requested_width = 34 + (allocations ? 27 : 0) + max_name name_length = max(9, max_name - max(0, requested_width - available_width)) - print_header(io, Δt, Δb, ∑t, ∑b, name_length, true, allocations, linechars, compact, title) - rev = !in(sortby, [:name, :firstexec]) + print_header(io, ∑t, ∑b, name_length, true, allocations, linechars, compact, title) + rev = !in(sortby, (:name,)) by(x) = sortf(x, sortby) - for timer in sort!(collect(values(to.inner_timers)); rev = rev, by = by) + for timer in sort!(collect(to.children); rev = rev, by = by) _print_timer(io, timer, ∑t, ∑b, 0, name_length, allocations, sortby, compact) end - print_header(io, Δt, Δb, ∑t, ∑b, name_length, false, allocations, linechars, compact, title) + print_header(io, ∑t, ∑b, name_length, false, allocations, linechars, compact, title) end function sortf(x, sortby) - sortby == :time && return x.accumulated_data.time - sortby == :ncalls && return x.accumulated_data.ncalls - sortby == :allocations && return x.accumulated_data.allocs + sortby == :time && return x.data.time + sortby == :ncalls && return x.data.ncalls + sortby == :allocations && return x.data.allocs sortby == :name && return x.name - sortby == :firstexec && return x.accumulated_data.firstexec error("internal error") end @@ -64,7 +69,7 @@ function truncdots(str, n) return String(take!(io)) end -function print_header(io, Δt, Δb, ∑t, ∑b, name_length, header, allocations, linechars, compact, title) +function print_header(io, ∑t, ∑b, name_length, header, allocations, linechars, compact, title) global BOX_MODE, ALLOCATIONS_ENABLED midrule = linechars == :unicode ? "─" : "-" @@ -102,15 +107,10 @@ function print_header(io, Δt, Δb, ∑t, ∑b, name_length, header, allocations end alloc_underline = midrule^textwidth(allocation_header) - #tot_meas_str = string(" ", rpad("Tot / % measured:", textwidth(sec_ncalls) - 1, " ")) - if compact - tot_meas_str = center("Total measured:", textwidth(sec_ncalls)) - else - tot_meas_str = center("Tot / % measured:", textwidth(sec_ncalls)) - end + tot_meas_str = center("Total measured:", textwidth(sec_ncalls)) - str_time = center(string(prettytime(Δt), compact ? "" : string(" / ", prettypercent(∑t, Δt))), textwidth(time_header)) - str_alloc = center(string(prettymemory(Δb), compact ? "" : string(" / ", prettypercent(∑b, Δb))), textwidth(allocation_header)) + str_time = center(prettytime(∑t), textwidth(time_header)) + str_alloc = center(prettymemory(∑b), textwidth(allocation_header)) header_str = string(" time %tot %timed") tot_midstr = string(sec_ncalls, " ", header_str) @@ -137,13 +137,13 @@ function print_header(io, Δt, Δb, ∑t, ∑b, name_length, header, allocations end function _print_timer(io::IO, to::TimerOutput, ∑t::Integer, ∑b::Integer, indent::Integer, name_length, allocations, sortby, compact) - accum_data = to.accumulated_data - t = accum_data.time - b = accum_data.allocs + data = to.data + t = data.time + b = data.allocs + nc = data.ncalls name = truncdots(to.name, name_length - indent) print(io, " ") - nc = accum_data.ncalls print(io, " "^indent, rpad(name, name_length + 2 - indent)) print(io, lpad(prettycount(nc), 5, " ")) @@ -158,9 +158,9 @@ function _print_timer(io::IO, to::TimerOutput, ∑t::Integer, ∑b::Integer, ind end print(io, "\n") - rev = !in(sortby, [:name, :firstexec]) + rev = !in(sortby, (:name,)) by(x) = sortf(x, sortby) - for timer in sort!(collect(values(to.inner_timers)); rev = rev, by = by) + for timer in sort!(collect(to.children); rev = rev, by = by) _print_timer(io, timer, ∑t, ∑b, indent + 2, name_length, allocations, sortby, compact) end end diff --git a/src/utilities.jl b/src/utilities.jl index 9c7a703..e890fa5 100644 --- a/src/utilities.jl +++ b/src/utilities.jl @@ -120,12 +120,11 @@ Converts a `TimerOutput` into a nested set of dictionaries, with keys and value """ function todict(to::TimerOutput) return Dict{String,Any}( - "n_calls" => ncalls(to), "time_ns" => time(to), "allocated_bytes" => allocated(to), "total_allocated_bytes" => totallocated(to), "total_time_ns" => tottime(to), - "inner_timers" => Dict{String, Any}(k => todict(v) for (k,v) in to.inner_timers) + # "inner_timers" => Dict{String, Any}(k => todict(v) for (k,v) in to.inner_timers) ) end @@ -138,7 +137,6 @@ end # you that `f` is involved). struct InstrumentedFunction{F} <: Function func::F - t::TimerOutput name::String end @@ -150,17 +148,8 @@ function funcname(f::F) where {F} end end -InstrumentedFunction(f, t) = InstrumentedFunction(f, t, funcname(f)) +InstrumentedFunction(f) = InstrumentedFunction(f, funcname(f)) -function (inst::InstrumentedFunction)(args...; kwargs...) - @timeit inst.t inst.name inst.func(args...; kwargs...) -end - -""" - (t::TimerOutput)(f, name=string(repr(f))) -> InstrumentedFunction - -Instruments `f` by the [`TimerOutput`](@ref) `t` returning an `InstrumentedFunction`. -This function can be used just like `f`, but whenever it is called it stores timing -results in `t`. -""" -(t::TimerOutput)(f, name=funcname(f)) = InstrumentedFunction(f, t, name) +# function (inst::InstrumentedFunction)(args...; kwargs...) +# @timeit inst.name inst.func(args...; kwargs...) +# end