Add @bprofile (#254)

To collect enough data, profiling benefits from long(ish) execution
times. That makes `@benchmark`/`@btime` attractive workloads
for profiling. Unfortunately, there's a lot of "junk" that appears in
the profile records, including many for type-inference.

This adds `@bprofile`, a substitute for `@profile @b...`,
that restricts profiling to the `run` phase of benchmarking.
Other than a fairly small amount of inference on the first session
use of `@bprofile` itself, this eliminates all the inference
and tuning in the trace.

Author: timholy

Project.toml

@@ -1,17 +1,18 @@
 name = "BenchmarkTools"
 uuid = "6e4b80f9-dd63-53aa-95a3-0cdb28fa8baf"
-version = "1.1.4"
+version = "1.2.0"
 
 [deps]
 JSON = "682c06a0-de6a-54ab-a142-c8b1cf79cde6"
 Logging = "56ddb016-857b-54e1-b83d-db4d58db5568"
 Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7"
+Profile = "9abbd945-dff8-562f-b5e8-e1ebf5ef1b79"
 Statistics = "10745b16-79ce-11e8-11f9-7d13ad32a3b2"
 UUIDs = "cf7118a7-6976-5b1a-9a39-7adc72f591a4"
 
 [compat]
-julia = "1"
 JSON = "0.18, 0.19, 0.20, 0.21"
+julia = "1"
 
 [extras]
 Statistics = "10745b16-79ce-11e8-11f9-7d13ad32a3b2"

src/BenchmarkTools.jl

@@ -7,6 +7,7 @@ using Logging: @logmsg, LogLevel
 using Statistics
 using UUIDs: uuid4
 using Printf
+using Profile
 
 
 const BENCHMARKTOOLS_VERSION = v"1.0.0"
@@ -68,7 +69,8 @@ export tune!,
        @benchmark,
        @benchmarkable,
        @belapsed,
-       @btime
+       @btime,
+       @bprofile
 
 #################
 # Serialization #

src/execution.jl

@@ -575,3 +575,30 @@ macro btime(args...)
         $result
     end)
 end
+
+"""
+    @bprofile expression [other parameters...]
+
+Run `@benchmark` while profiling. This is similar to
+
+    @profile @benchmark expression [other parameters...]
+
+but the profiling is applied only to the main
+execution (after compilation and tuning).
+The profile buffer is cleared prior to execution.
+
+View the profile results with `Profile.print(...)`.
+See the profiling section of the Julia manual for more
+information.
+"""
+macro bprofile(args...)
+    _, params = prunekwargs(args...)
+    tmp = gensym()
+    return esc(quote
+        local $tmp = $BenchmarkTools.@benchmarkable $(args...)
+        $BenchmarkTools.warmup($tmp)
+        $(hasevals(params) ? :() : :($BenchmarkTools.tune!($tmp)))
+        $BenchmarkTools.Profile.clear()
+        $BenchmarkTools.@profile $BenchmarkTools.run($tmp)
+    end)
+end

test/ExecutionTests.jl

@@ -1,6 +1,7 @@
 module ExecutionTests
 
 using BenchmarkTools
+using Profile
 using Test
 
 seteq(a, b) = length(a) == length(b) == length(intersect(a, b))
@@ -134,6 +135,36 @@ tune!(b)
 # test kwargs separated by `,`
 @benchmark(output=sin(x), setup=(x=1.0; output=0.0), teardown=(@test output == sin(x)))
 
+#############
+# @bprofile #
+#############
+
+function likegcd(a::T, b::T) where T<:Base.BitInteger
+    za = trailing_zeros(a)
+    zb = trailing_zeros(b)
+    k = min(za, zb)
+    u = unsigned(abs(a >> za))
+    v = unsigned(abs(b >> zb))
+    while u != v
+        if u > v
+            u, v = v, u
+        end
+        v -= u
+        v >>= trailing_zeros(v)
+    end
+    r = u << k
+    return r % T
+end
+
+b = @bprofile likegcd(x, y) setup=(x = rand(2:200); y = rand(2:200))
+@test isa(b, BenchmarkTools.Trial)
+io = IOBuffer()
+Profile.print(IOContext(io, :displaysize=>(24,200)))
+str = String(take!(io))
+@test  occursin(r"BenchmarkTools(\.jl)?/src/execution\.jl:\d+; _run", str)
+@test !occursin(r"BenchmarkTools(\.jl)?/src/execution\.jl:\d+; warmup", str)
+@test !occursin(r"BenchmarkTools(\.jl)?/src/execution\.jl:\d+; tune!", str)
+
 ########
 # misc #
 ########