diff --git a/NEWS.md b/NEWS.md index 658cf453f64313..da055fc6d69eb1 100644 --- a/NEWS.md +++ b/NEWS.md @@ -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 --------------------------- diff --git a/base/deprecated.jl b/base/deprecated.jl index 77036b0e421c95..4125c3c4fbf1a1 100644 --- a/base/deprecated.jl +++ b/base/deprecated.jl @@ -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 diff --git a/base/exports.jl b/base/exports.jl index b15e1709383a05..d466248944a090 100644 --- a/base/exports.jl +++ b/base/exports.jl @@ -897,11 +897,8 @@ export # time sleep, - tic, time, time_ns, - toc, - toq, # dates Date, diff --git a/base/util.jl b/base/util.jl index 5011e1d1f74454..da8cc8bb048628 100644 --- a/base/util.jl +++ b/base/util.jl @@ -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"] diff --git a/doc/src/stdlib/base.md b/doc/src/stdlib/base.md index 2eaf02425e1e76..639006a819fa4d 100644 --- a/doc/src/stdlib/base.md +++ b/doc/src/stdlib/base.md @@ -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 diff --git a/test/channels.jl b/test/channels.jl index bd35c8a0269d48..d06592bb47e03d 100644 --- a/test/channels.jl +++ b/test/channels.jl @@ -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) diff --git a/test/file.jl b/test/file.jl index da52c1a9d1e284..b247ee58d25c17 100644 --- a/test/file.jl +++ b/test/file.jl @@ -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 diff --git a/test/perf/kernel/gk.jl b/test/perf/kernel/gk.jl index f54ab5c737333f..2e54e15dabe112 100644 --- a/test/perf/kernel/gk.jl +++ b/test/perf/kernel/gk.jl @@ -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 diff --git a/test/perf/spell/perf.jl b/test/perf/spell/perf.jl index 08be858fa70ea4..8fa1e8426f32b4 100644 --- a/test/perf/spell/perf.jl +++ b/test/perf/spell/perf.jl @@ -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"=> diff --git a/test/perf/threads/lbm3d/lbm3d.jl b/test/perf/threads/lbm3d/lbm3d.jl index 11fcee4c37c92e..b53142bde4dfbe 100644 --- a/test/perf/threads/lbm3d/lbm3d.jl +++ b/test/perf/threads/lbm3d/lbm3d.jl @@ -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 diff --git a/test/pollfd.jl b/test/pollfd.jl index fdc44439c1d51e..4a9eedd353efea 100644 --- a/test/pollfd.jl +++ b/test/pollfd.jl @@ -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