docstring + tests

Author: mcabbott

src/execution.jl

@@ -554,10 +554,26 @@ this executes an expression, printing the time
 it took to execute and the memory allocated before
 returning the value of the expression.
 
-Unlike `@time`, it uses the `@benchmark`
-macro, and accepts all of the same additional
-parameters as `@benchmark`.  The printed time
-is the *minimum* elapsed time measured during the benchmark.
+However, it uses the [`@benchmark`](@ref) to evaluate
+`expression` many times, and accepts all of the same
+additional parameters as `@benchmark`. It prints both
+the minimum and the mean elapsed time, plus information
+about allocations (if any) and time spent on
+memory garbage collection (GC).
+
+# Examples
+```
+julia> @btime log(x[]) setup=(x=Ref(2.0))
+  min 3.666 ns, mean 3.772 ns (0 allocations)
+0.6931471805599453
+
+julia> @btime sum(log, \$(fill(2.0, 1000)))
+  min 3.391 μs, mean 3.441 μs (0 allocations)
+693.1471805599322
+
+julia> @btime rand(1000);
+  min 724.432 ns, mean 1.462 μs (1 allocation, 7.94 KiB. GC mean 352 ns, 24.11%)
+```
 """
 macro btime(args...)
     _, params = prunekwargs(args...)

src/trials.jl

@@ -264,7 +264,7 @@ function prettytime(t; short=false)
         value, units = t / 1e9, "s"
     end
     if short
-        string(@sprintf("%.0f", value), " ", units)
+        string(@sprintf("%.0f", value), " ", units)  # "%.3g" also OK, always 3 numbers
     else
         string(@sprintf("%.3f", value), " ", units)
     end

test/ExecutionTests.jl

@@ -227,6 +227,7 @@ str = String(take!(io))
 
 let fname = tempname()
     try
+        # simple function, zero allocations
         ret = open(fname, "w") do f
             redirect_stdout(f) do
                 x = 1
@@ -238,7 +239,21 @@ let fname = tempname()
         end
         s = read(fname, String)
         try
-            @test occursin(r"[0-9.]+ \w*s \([0-9]* allocations?: [0-9]+ bytes\)", s)
+            @test occursin(r"min [0-9.]+ \w*s, mean [0-9.]+ \w*s \(0 allocations\)", s)
+        catch
+            println(stderr, "@btime output didn't match ", repr(s))
+            rethrow()
+        end
+        # function which allocates
+        ret2 = open(fname, "w") do f
+            redirect_stdout(f) do
+                y = @btime(sum(log, ones(100)))
+                @test y ≈ 0
+            end
+        end
+        s2 = read(fname, String)
+        try
+            @test occursin(r", mean [0-9.]+ \w*s \([0-9]* allocations?, [0-9]+ bytes. GC mean [0-9.]+ \w*s,", s2)
         catch
             println(stderr, "@btime output didn't match ", repr(s))
             rethrow()