fix #17046, deprecate tic and toc

Author: JeffBezanson

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
 ---------------------------
 

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

base/exports.jl

@@ -897,11 +897,8 @@ export
 
 # time
     sleep,
-    tic,
     time,
     time_ns,
-    toc,
-    toq,
 
 # dates
     Date,

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"]

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

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)

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

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

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"=>

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

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