RFC: Use logging-based progress bars (#104)

* Use logging-based progress bars

* Bump to 0.2.8

Author: tkf

Manifest.toml

@@ -1,30 +1,33 @@
 name = "PkgBenchmark"
 uuid = "32113eaa-f34f-5b0d-bd6c-c81e245fc73d"
-version = "0.2.7"
+version = "0.2.8"
 
 [deps]
 BenchmarkTools = "6e4b80f9-dd63-53aa-95a3-0cdb28fa8baf"
 Dates = "ade2ca70-3891-5945-98fb-dc099432e06a"
 InteractiveUtils = "b77e0a4c-d291-57a0-90e8-8db25a27a240"
 JSON = "682c06a0-de6a-54ab-a142-c8b1cf79cde6"
 LibGit2 = "76f85450-5226-5b5a-8eaa-529ad045b433"
+Logging = "56ddb016-857b-54e1-b83d-db4d58db5568"
 Pkg = "44cfe95a-1eb2-52ea-b672-e2afdf69b78f"
 Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7"
-ProgressMeter = "92933f4c-e287-5a05-a399-4b506db050ca"
+TerminalLoggers = "5d786b92-1e48-4d6f-9151-6b4477ca9bed"
+UUIDs = "cf7118a7-6976-5b1a-9a39-7adc72f591a4"
 
 [compat]
 BenchmarkTools = "^0.4.3, 0.5"
 JSON = "0.21"
-ProgressMeter = "1"
+TerminalLoggers = "0.1"
 julia = "1"
 
 [extras]
 Dates = "ade2ca70-3891-5945-98fb-dc099432e06a"
+Documenter = "e30172f5-a6a5-5a46-863b-614d45cd2de4"
 LibGit2 = "76f85450-5226-5b5a-8eaa-529ad045b433"
 Pkg = "44cfe95a-1eb2-52ea-b672-e2afdf69b78f"
 Random = "9a3f8284-a2c9-5f02-9a11-845980a1fd5c"
 Statistics = "10745b16-79ce-11e8-11f9-7d13ad32a3b2"
 Test = "8dfed614-e22c-5e08-85e1-65c5234f0b40"
 
 [targets]
-test = ["Dates", "Pkg", "LibGit2", "Statistics", "Test", "Random"]
+test = ["Dates", "Documenter", "Pkg", "LibGit2", "Statistics", "Test", "Random"]

Project.toml

@@ -4,12 +4,14 @@ module PkgBenchmark
 
 using BenchmarkTools
 using JSON
-using ProgressMeter
 using Pkg
 using LibGit2
 using Dates
 using InteractiveUtils
 using Printf
+using Logging: with_logger
+using TerminalLoggers: TerminalLogger
+using UUIDs: UUID
 
 export benchmarkpkg, judge, writeresults, readresults, export_markdown, memory
 export BenchmarkConfig, BenchmarkResults, BenchmarkJudgement

src/PkgBenchmark.jl

@@ -13,8 +13,11 @@ The argument `pkg` can be a name of a package or a path to a directory to a pack
 * `postprocess` - A function to post-process results. Will be passed the `BenchmarkGroup`, which it can modify, or return a new one.
 * `resultfile` - If set, saves the output to `resultfile`
 * `retune` - Force a re-tune, saving the new tuning to the tune file.
-* `progressoptions` - Options (a `NamedTuple`) to be passed as keyword arguments to
-  `ProgressMeter.Progress`.
+* `verbose::Bool = true` - Print currently running benchmark.
+* `logger_factory` - Specify the logger used during benchmark.  It is a callable object
+  (typically a type) with no argument that creates a logger.  It must exist as a constant
+  in some package (e.g., an anonymous function does not work).
+* `progressoptions` - Deprecated.
 
 The result can be used by functions such as [`judge`](@ref). If you choose to, you can save the results manually using
 [`writeresults`](@ref) where `results` is the return value of this function. It can be read back with [`readresults`](@ref).
@@ -42,9 +45,18 @@ function benchmarkpkg(
         postprocess=nothing,
         resultfile=nothing,
         retune=false,
-        progressoptions=NamedTuple(),
+        verbose::Bool=true,
+        logger_factory=nothing,
+        progressoptions=nothing,
         custom_loadpath="" #= used in tests =#
     )
+    if progressoptions !== nothing
+        Base.depwarn(
+            "Keyword argument `progressoptions` is ignored. Please use `logger_factory`.",
+            :benchmarkpkg,
+        )
+    end
+
     target = BenchmarkConfig(target)
 
     pkgid = Base.identify_package(pkg)
@@ -96,7 +108,8 @@ function benchmarkpkg(
             _runbenchmark(script, f, target, tunefile;
                           retune = retune,
                           custom_loadpath = custom_loadpath,
-                          progressoptions = progressoptions)
+                          runoptions = (verbose = verbose,),
+                          logger_factory = logger_factory)
         end
         io = IOBuffer(results_local["results"])
         seek(io, 0)
@@ -138,8 +151,61 @@ function benchmarkpkg(
     return results
 end
 
+"""
+    objectpath(x) -> (pkg_uuid::Union{String,Nothing}, pkg_name::String, name::Symbol...)
+
+Get the "fullname" of object, prefixed by package ID.
+
+# Examples
+```jldoctest
+julia> using PkgBenchmark: objectpath
+
+julia> using Logging
+
+julia> objectpath(ConsoleLogger)
+("56ddb016-857b-54e1-b83d-db4d58db5568", "Logging", :ConsoleLogger)
+```
+"""
+function objectpath(x)
+    m = parentmodule(x)
+    if x === m
+        pkg = Base.PkgId(x)
+        uuid = pkg.uuid === nothing ? nothing : string(pkg.uuid)
+        return (uuid, pkg.name)
+    else
+        n = nameof(x)
+        if !isdefined(m, n)
+            error("Object `$x` is not accessible as `$m.$n`.")
+        end
+        return (objectpath(m)..., n)
+    end
+end
+
+"""
+    loadobject((pkg_uuid, pkg_name, name...))
+
+Inverse of `objectpath`.
+
+# Examples
+```jldoctest
+julia> using PkgBenchmark: loadobject
+
+julia> using Logging
+
+julia> loadobject(("56ddb016-857b-54e1-b83d-db4d58db5568", "Logging", :ConsoleLogger)) ===
+           ConsoleLogger
+true
+```
+"""
+loadobject(path) = _loadobject(path...)
+function _loadobject(pkg_uuid, pkg_name, fullname...)
+    pkgid = Base.PkgId(pkg_uuid === nothing ? pkg_uuid : UUID(pkg_uuid), pkg_name)
+    return foldl(getproperty, fullname, init = Base.require(pkgid))
+end
+
 function _runbenchmark(file::String, output::String, benchmarkconfig::BenchmarkConfig, tunefile::String;
-                      retune = false, custom_loadpath = nothing, progressoptions = NamedTuple())
+                       retune = false, custom_loadpath = nothing, runoptions = NamedTuple(),
+                       logger_factory = nothing)
     color = Base.have_color ? "--color=yes" : "--color=no"
     compilecache = "--compiled-modules=" * (Bool(Base.JLOptions().use_compiled_modules) ? "yes" : "no")
     _file, _output, _tunefile, _custom_loadpath = map(escape_string, (file, output, tunefile, custom_loadpath))
@@ -151,11 +217,26 @@ function _runbenchmark(file::String, output::String, benchmarkconfig::BenchmarkC
     else
         "all"
     end
+    logger_factory_path = if logger_factory === nothing
+        # Default to `TerminalLoggers.TerminalLogger`; load via
+        # `PkgBenchmark` namespace so that users don't have to add it
+        # separately.
+        (objectpath(@__MODULE__)..., :TerminalLogger)
+    else
+        objectpath(logger_factory)
+    end
     exec_str = isempty(_custom_loadpath) ? "" : "push!(LOAD_PATH, \"$(_custom_loadpath)\")\n"
     exec_str *=
         """
         using PkgBenchmark
-        PkgBenchmark._runbenchmark_local($(repr(_file)), $(repr(_output)), $(repr(_tunefile)), $(repr(retune)), $(repr(progressoptions)))
+        PkgBenchmark._runbenchmark_local(
+            $(repr(_file)),
+            $(repr(_output)),
+            $(repr(_tunefile)),
+            $(repr(retune)),
+            $(repr(runoptions)),
+            $(repr(logger_factory_path)),
+        )
         """
 
     target_env = [k => v for (k, v) in benchmarkconfig.env]
@@ -166,8 +247,13 @@ function _runbenchmark(file::String, output::String, benchmarkconfig::BenchmarkC
     return JSON.parsefile(output)
 end
 
+function _runbenchmark_local(file, output, tunefile, retune, runoptions, logger_factory_path)
+    with_logger(loadobject(logger_factory_path)()) do
+        __runbenchmark_local(file, output, tunefile, retune, runoptions)
+    end
+end
 
-function _runbenchmark_local(file, output, tunefile, retune, progressoptions)
+function __runbenchmark_local(file, output, tunefile, retune, runoptions)
     # Loading
     Base.include(Main, file)
     if !isdefined(Main, :SUITE)
@@ -182,12 +268,12 @@ function _runbenchmark_local(file, output, tunefile, retune, progressoptions)
     else
         _benchinfo("creating benchmark tuning file $(abspath(tunefile))...")
         mkpath(dirname(tunefile))
-        _tune!(suite, progressoptions = progressoptions)
+        BenchmarkTools.tune!(suite; runoptions...)
         BenchmarkTools.save(tunefile, params(suite));
     end
 
     # Running
-    results = _run(suite, progressoptions = progressoptions)
+    results = run(suite; runoptions...)
 
     # Output
     vinfo = first(split(sprint((io) -> versioninfo(io; verbose=true)), "Environment"))
@@ -202,52 +288,3 @@ function _runbenchmark_local(file, output, tunefile, retune, progressoptions)
     end
     return nothing
 end
-
-
-function _tune!(group::BenchmarkTools.BenchmarkGroup; verbose::Bool = false, root = true,
-                progressoptions = NamedTuple(),
-                prog = Progress(length(BenchmarkTools.leaves(group)); desc = "Tuning: ", progressoptions...),
-                hierarchy = [], kwargs...)
-    BenchmarkTools.gcscrub() # run GC before running group, even if individual benchmarks don't manually GC
-    i = 1
-    for id in keys(group)
-        _tune!(group[id]; verbose = verbose, prog = prog, hierarchy = push!(copy(hierarchy), (repr(id), i, length(keys(group)))), kwargs...)
-        i += 1
-    end
-    return group
-end
-
-function _tune!(b::BenchmarkTools.Benchmark, p::BenchmarkTools.Parameters = b.params;
-               prog = nothing, verbose::Bool = false, pad = "", hierarchy = [], kwargs...)
-    BenchmarkTools.warmup(b, verbose=false)
-    estimate = ceil(Int, minimum(BenchmarkTools.lineartrial(b, p; kwargs...)))
-    b.params.evals = BenchmarkTools.guessevals(estimate)
-    if prog != nothing
-        indent = 0
-        ProgressMeter.next!(prog; showvalues = [map(id -> ("  "^(indent += 1) * "[$(id[2])/$(id[3])]", id[1]), hierarchy)...])
-    end
-    return b
-end
-
-function _run(group::BenchmarkTools.BenchmarkGroup, args...;
-              progressoptions = NamedTuple(),
-              prog = Progress(length(BenchmarkTools.leaves(group)); desc = "Benchmarking: ", progressoptions...), hierarchy = [], kwargs...)
-    result = similar(group)
-    BenchmarkTools.gcscrub() # run GC before running group, even if individual benchmarks don't manually GC
-    i = 1
-    for id in keys(group)
-        result[id] = _run(group[id], args...; prog = prog, hierarchy = push!(copy(hierarchy), (repr(id), i, length(keys(group)))), kwargs...)
-        i += 1
-    end
-    return result
-end
-
-function _run(b::BenchmarkTools.Benchmark, p::BenchmarkTools.Parameters = b.params;
-                   prog = nothing, verbose::Bool = false, pad = "", hierarchy = [], kwargs...)
-    res = BenchmarkTools.run_result(b, p; kwargs...)[1]
-    if prog != nothing
-        indent = 0
-        ProgressMeter.next!(prog; showvalues = [map(id -> ("  "^(indent += 1) * "[$(id[2])/$(id[3])]", id[1]), hierarchy)...])
-    end
-    return res
-end