fix #17046, deprecate tic and toc (#23773)

JeffBezanson · web-flow · commit 1b023388f49e · 2017-09-20T11:21:39.000-04:00
diff --git 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
@@ -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
+
 @noinline function getaddrinfo(callback::Function, host::AbstractString)
     depwarn("getaddrinfo with a callback function is deprecated, wrap code in @async instead for deferred execution", :getaddrinfo)
     @async begin
diff --git 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
@@ -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/manual/noteworthy-differences.md b/doc/src/manual/noteworthy-differences.md
@@ -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.
diff --git a/doc/src/manual/performance-tips.md b/doc/src/manual/performance-tips.md
@@ -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
diff --git 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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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

-Original file line number
+Diff line change
 # time
     sleep,
 -    tic,
     time,
     time_ns,
 -    toc,
 -    toq,
 # dates
     Date,