Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix #17046, deprecate tic and toc #23773

Merged
merged 2 commits into from
Sep 20, 2017
Merged
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Next Next commit
fix #17046, deprecate tic and toc
JeffBezanson committed Sep 19, 2017

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature. The key has expired.
commit ec50a5c939a2a36c331b7956716d64f729ea135b
3 changes: 3 additions & 0 deletions NEWS.md
Original file line number Diff line number Diff line change
@@ -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
---------------------------

31 changes: 31 additions & 0 deletions base/deprecated.jl
Original file line number Diff line number Diff line change
@@ -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
3 changes: 0 additions & 3 deletions base/exports.jl
Original file line number Diff line number Diff line change
@@ -897,11 +897,8 @@ export

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

# dates
Date,
73 changes: 0 additions & 73 deletions base/util.jl
Original file line number Diff line number Diff line change
@@ -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"]
3 changes: 1 addition & 2 deletions doc/src/manual/noteworthy-differences.md
Original file line number Diff line number Diff line change
@@ -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.
3 changes: 1 addition & 2 deletions doc/src/manual/performance-tips.md
Original file line number Diff line number Diff line change
@@ -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
3 changes: 0 additions & 3 deletions doc/src/stdlib/base.md
Original file line number Diff line number Diff line change
@@ -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
5 changes: 2 additions & 3 deletions test/channels.jl
Original file line number Diff line number Diff line change
@@ -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)
10 changes: 5 additions & 5 deletions test/file.jl
Original file line number Diff line number Diff line change
@@ -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
3 changes: 1 addition & 2 deletions test/perf/kernel/gk.jl
Original file line number Diff line number Diff line change
@@ -65,7 +65,6 @@ function gk(n, myeps)

csum = zeros(n)

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

end

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

x = X/t
4 changes: 2 additions & 2 deletions test/perf/spell/perf.jl
Original file line number Diff line number Diff line change
@@ -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
@@ -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"=>
39 changes: 18 additions & 21 deletions test/perf/threads/lbm3d/lbm3d.jl
Original file line number Diff line number Diff line change
@@ -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
32 changes: 16 additions & 16 deletions test/pollfd.jl
Original file line number Diff line number Diff line change
@@ -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
@@ -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