Skip to content

Commit

Permalink
fix #17046, deprecate tic and toc
Browse files Browse the repository at this point in the history
  • Loading branch information
JeffBezanson committed Sep 19, 2017
1 parent aa79148 commit ec50a5c
Show file tree
Hide file tree
Showing 13 changed files with 80 additions and 132 deletions.
3 changes: 3 additions & 0 deletions NEWS.md
Original file line number Diff line number Diff line change
Expand Up @@ -453,6 +453,9 @@ Deprecated or removed
`prompt_if_incorrect` argument are deprecated. Instead, prompting behavior is controlled using
the `allow_prompt` keyword in the `LibGit2.CredentialPayload` constructor ([#23690]).

* The timing functions `tic`, `toc`, and `toq` are deprecated in favor of `@time` and `@elapsed`
([#17046]).

Command-line option changes
---------------------------

Expand Down
31 changes: 31 additions & 0 deletions base/deprecated.jl
Original file line number Diff line number Diff line change
Expand Up @@ -1815,6 +1815,37 @@ end
@deprecate get_creds!(cache::CachedCredentials, credid, default) get!(cache, credid, default)
end

export tic, toq, toc
function tic()
depwarn("tic() is deprecated, use @time, @elapsed, or calls to time_ns() instead.", :tic)
t0 = time_ns()
task_local_storage(:TIMERS, (t0, get(task_local_storage(), :TIMERS, ())))
return t0
end

function _toq()
t1 = time_ns()
timers = get(task_local_storage(), :TIMERS, ())
if timers === ()
error("toc() without tic()")
end
t0 = timers[1]::UInt64
task_local_storage(:TIMERS, timers[2])
(t1-t0)/1e9
end

function toq()
depwarn("toq() is deprecated, use @elapsed or calls to time_ns() instead.", :toq)
return _toq()
end

function toc()
depwarn("toc() is deprecated, use @time, @elapsed, or calls to time_ns() instead.", :toc)
t = _toq()
println("elapsed time: ", t, " seconds")
return t
end

# END 0.7 deprecations

# BEGIN 1.0 deprecations
Expand Down
3 changes: 0 additions & 3 deletions base/exports.jl
Original file line number Diff line number Diff line change
Expand Up @@ -897,11 +897,8 @@ export

# time
sleep,
tic,
time,
time_ns,
toc,
toq,

# dates
Date,
Expand Down
73 changes: 0 additions & 73 deletions base/util.jl
Original file line number Diff line number Diff line change
Expand Up @@ -76,79 +76,6 @@ gc_time_ns() = ccall(:jl_gc_total_hrtime, UInt64, ())
# total number of bytes allocated so far
gc_bytes() = ccall(:jl_gc_total_bytes, Int64, ())

"""
tic()
Set a timer to be read by the next call to [`toc`](@ref) or [`toq`](@ref). The
macro call `@time expr` can also be used to time evaluation.
```julia-repl
julia> tic()
0x0000c45bc7abac95
julia> sleep(0.3)
julia> toc()
elapsed time: 0.302745944 seconds
0.302745944
```
"""
function tic()
t0 = time_ns()
task_local_storage(:TIMERS, (t0, get(task_local_storage(), :TIMERS, ())))
return t0
end

"""
toq()
Return, but do not print, the time elapsed since the last [`tic`](@ref). The
macro calls `@timed expr` and `@elapsed expr` also return evaluation time.
```julia-repl
julia> tic()
0x0000c46477a9675d
julia> sleep(0.3)
julia> toq()
0.302251004
```
"""
function toq()
t1 = time_ns()
timers = get(task_local_storage(), :TIMERS, ())
if timers === ()
error("toc() without tic()")
end
t0 = timers[1]::UInt64
task_local_storage(:TIMERS, timers[2])
(t1-t0)/1e9
end

"""
toc()
Print and return the time elapsed since the last [`tic`](@ref). The macro call
`@time expr` can also be used to time evaluation.
```julia-repl
julia> tic()
0x0000c45bc7abac95
julia> sleep(0.3)
julia> toc()
elapsed time: 0.302745944 seconds
0.302745944
```
"""
function toc()
t = toq()
println("elapsed time: ", t, " seconds")
return t
end

# print elapsed time, return expression value
const _mem_units = ["byte", "KiB", "MiB", "GiB", "TiB", "PiB"]
const _cnt_units = ["", " k", " M", " G", " T", " P"]
Expand Down
3 changes: 1 addition & 2 deletions doc/src/manual/noteworthy-differences.md
Original file line number Diff line number Diff line change
Expand Up @@ -52,8 +52,7 @@ may trip up Julia users accustomed to MATLAB:
* In Julia, functions such as [`sort`](@ref) that operate column-wise by default (`sort(A)` is
equivalent to `sort(A,1)`) do not have special behavior for `1xN` arrays; the argument is returned
unmodified since it still performs `sort(A,1)`. To sort a `1xN` matrix like a vector, use `sort(A,2)`.
* In Julia, parentheses must be used to call a function with zero arguments, like in [`tic()`](@ref)
and [`toc()`](@ref).
* In Julia, parentheses must be used to call a function with zero arguments, like in [`rand()`](@ref).
* Julia discourages the used of semicolons to end statements. The results of statements are not
automatically printed (except at the interactive prompt), and lines of code do not need to end
with semicolons. [`println`](@ref) or [`@printf`](@ref) can be used to print specific output.
Expand Down
3 changes: 1 addition & 2 deletions doc/src/manual/performance-tips.md
Original file line number Diff line number Diff line change
Expand Up @@ -73,8 +73,7 @@ julia> @time f(10^6)
On the first call (`@time f(1)`), `f` gets compiled. (If you've not yet used [`@time`](@ref)
in this session, it will also compile functions needed for timing.) You should not take the results
of this run seriously. For the second run, note that in addition to reporting the time, it also
indicated that a large amount of memory was allocated. This is the single biggest advantage of
[`@time`](@ref) vs. functions like [`tic`](@ref) and [`toc`](@ref), which only report time.
indicated that a large amount of memory was allocated.

Unexpected memory allocation is almost always a sign of some problem with your code, usually a
problem with type-stability. Consequently, in addition to the allocation itself, it's very likely
Expand Down
3 changes: 0 additions & 3 deletions doc/src/stdlib/base.md
Original file line number Diff line number Diff line change
Expand Up @@ -193,9 +193,6 @@ Base.getipaddr
Base.Libc.getpid
Base.Libc.time()
Base.time_ns
Base.tic
Base.toc
Base.toq
Base.@time
Base.@timev
Base.@timed
Expand Down
5 changes: 2 additions & 3 deletions test/channels.jl
Original file line number Diff line number Diff line change
Expand Up @@ -212,9 +212,8 @@ end
@async begin sleep(1.0); put!(rr2, :ok) end
@async begin sleep(2.0); put!(rr3, :ok) end

tic()
timedwait(callback, Dates.Second(1))
et=toq()
et = @elapsed timedwait(callback, Dates.Second(1))

# assuming that 0.5 seconds is a good enough buffer on a typical modern CPU
try
@assert (et >= 1.0) && (et <= 1.5)
Expand Down
10 changes: 5 additions & 5 deletions test/file.jl
Original file line number Diff line number Diff line change
Expand Up @@ -192,11 +192,11 @@ function test_file_poll(channel,interval,timeout_s)
end

function test_timeout(tval)
tic()
channel = Channel(1)
@async test_file_poll(channel, 10, tval)
tr = take!(channel)
t_elapsed = toq()
t_elapsed = @elapsed begin
channel = Channel(1)
@async test_file_poll(channel, 10, tval)
tr = take!(channel)
end
@test tr[1] === Base.Filesystem.StatStruct() && tr[2] === EOFError()
@test tval <= t_elapsed
end
Expand Down
3 changes: 1 addition & 2 deletions test/perf/kernel/gk.jl
Original file line number Diff line number Diff line change
Expand Up @@ -65,7 +65,6 @@ function gk(n, myeps)

csum = zeros(n)

# tic()
while(stop != 1)
t=t+1
iter=t
Expand Down Expand Up @@ -115,7 +114,7 @@ function gk(n, myeps)

end

times[KK] = 0#toc()
times[KK] = 0
iteration[KK] = iter

x = X/t
Expand Down
4 changes: 2 additions & 2 deletions test/perf/spell/perf.jl
Original file line number Diff line number Diff line change
Expand Up @@ -71,7 +71,7 @@ end
################ Testing code from here on ################

function spelltest(tests; bias=0, verbose=false)
n, bad, unknown, start = 0, 0, 0, tic()
n, bad, unknown, start = 0, 0, 0, time_ns()
if bias > 0
for target in keys(tests)
NWORDS[target] = get(NWORDS, target, 1) + bias
Expand All @@ -93,7 +93,7 @@ function spelltest(tests; bias=0, verbose=false)
end

return Dict("bad"=>bad, "n"=>n, "bias"=>bias, "pct"=>round(Int, 100. - 100. * bad/n),
"unknown"=>unknown, "secs"=>toc())
"unknown"=>unknown, "secs"=>(time_ns() - start)/1e9)
end

const tests1 = Dict("access"=> "acess", "accessing"=> "accesing", "accommodation"=>
Expand Down
39 changes: 18 additions & 21 deletions test/perf/threads/lbm3d/lbm3d.jl
Original file line number Diff line number Diff line change
Expand Up @@ -169,36 +169,33 @@ function lbm3d(n)
numactivenodes = sum(1-BOUND)

@time while (ts < 4000 && (1e-10 < abs((prevavu-avu)/avu))) || ts < 100
tic()
# Propagate -- nearest and next-nearest neighbors
for i = 2:19
circshift3d1!(F, i, prop_shifts[i-1])
tprop += @elapsed begin
# Propagate -- nearest and next-nearest neighbors
for i = 2:19
circshift3d1!(F, i, prop_shifts[i-1])
end
end
tprop = tprop + toq()

# Densities bouncing back at next timestep
BOUNCEDBACK = F[TO_REFLECT]

tic()

# Relax; calculate equilibrium state (FEQ) with equivalent speed and density to F
@threads for chunk=1:nchunk
relax!(F, UX, UY, UZ, nx, ny, nz, deltaU, t1D, t2D, t3D, sSQU, chunkid, nchunk)
end
for o in ON
UX[o] = UY[o] = UZ[o] = t1D[o] = t2D[o] = t3D[o] = sSQU[o] = 0.0
trelax += @elapsed begin
# Relax; calculate equilibrium state (FEQ) with equivalent speed and density to F
@threads for chunk=1:nchunk
relax!(F, UX, UY, UZ, nx, ny, nz, deltaU, t1D, t2D, t3D, sSQU, chunkid, nchunk)
end
for o in ON
UX[o] = UY[o] = UZ[o] = t1D[o] = t2D[o] = t3D[o] = sSQU[o] = 0.0
end
end

trelax = trelax + toq()
tic()

# Calculate equilibrium distribution: stationary
@threads for chunk=1:nchunk
calc_equi!(F, FEQ, t1D, t2D, t3D, U, UX, UY, UZ, sSQU, nx, ny, nz, omega)
tequi += @elapsed begin
# Calculate equilibrium distribution: stationary
@threads for chunk=1:nchunk
calc_equi!(F, FEQ, t1D, t2D, t3D, U, UX, UY, UZ, sSQU, nx, ny, nz, omega)
end
end

tequi = tequi + toq()

F[REFLECTED] = BOUNCEDBACK

prevavu = avu
Expand Down
32 changes: 16 additions & 16 deletions test/pollfd.jl
Original file line number Diff line number Diff line change
Expand Up @@ -25,12 +25,12 @@ end
function pfd_tst_reads(idx, intvl)
global ready += 1
wait(ready_c)
tic()
start_evt2 = Condition()
evt2 = @async (notify(start_evt2); poll_fd(pipe_fds[idx][1], intvl; readable=true, writable=false))
wait(start_evt2); yield() # make sure the async poll_fd is pumping events
evt = poll_fd(pipe_fds[idx][1], intvl; readable=true, writable=false)
t_elapsed = toq()
t_elapsed = @elapsed begin
start_evt2 = Condition()
evt2 = @async (notify(start_evt2); poll_fd(pipe_fds[idx][1], intvl; readable=true, writable=false))
wait(start_evt2); yield() # make sure the async poll_fd is pumping events
evt = poll_fd(pipe_fds[idx][1], intvl; readable=true, writable=false)
end
@test !evt.timedout
@test evt.readable
@test !evt.writable
Expand All @@ -53,16 +53,16 @@ end
function pfd_tst_timeout(idx, intvl)
global ready += 1
wait(ready_c)
tic()
start_evt2 = Condition()
evt2 = @async (notify(start_evt2); poll_fd(pipe_fds[idx][1], intvl; readable=true, writable=false))
wait(start_evt2); yield() # make sure the async poll_fd is pumping events
evt = poll_fd(pipe_fds[idx][1], intvl; readable=true, writable=false)
@test evt.timedout
@test !evt.readable
@test !evt.writable
@test evt === wait(evt2)
t_elapsed = toq()
t_elapsed = @elapsed begin
start_evt2 = Condition()
evt2 = @async (notify(start_evt2); poll_fd(pipe_fds[idx][1], intvl; readable=true, writable=false))
wait(start_evt2); yield() # make sure the async poll_fd is pumping events
evt = poll_fd(pipe_fds[idx][1], intvl; readable=true, writable=false)
@test evt.timedout
@test !evt.readable
@test !evt.writable
@test evt === wait(evt2)
end

# Disabled since these assertions fail randomly, notably on build VMs (issue #12824)
# @test intvl <= t_elapsed
Expand Down

0 comments on commit ec50a5c

Please sign in to comment.