Improve progress bar (ETA and Unicode-based rendering) (#4)

tkf · web-flow · commit b1b661540dd0 · 2020-01-13T18:05:40.000-08:00
* Use ProgressMeter to draw progress bars

* Fix test failures in Julia 1.0

* Use infix operator to improve @-test failure output

* Fix test failures in Windows

* Vendor ProgressMeter.jl

* Fix test/TerminalLogger.jl

* More tests

* Fix Windows test
diff --git a/Project.toml b/Project.toml
@@ -5,6 +5,7 @@ version = "0.1.0"
 
 [deps]
 Logging = "56ddb016-857b-54e1-b83d-db4d58db5568"
+Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7"
 
 [compat]
 julia = "1"
diff --git a/src/ProgressMeter/LICENSE.txt b/src/ProgressMeter/LICENSE.txt
@@ -0,0 +1,8 @@
+The MIT License (MIT)
+Copyright (c) 2013 Timothy E. Holy
+
+Permission is hereby granted, free of charge, to any person obtaining a copy of this software and associated documentation files (the "Software"), to deal in the Software without restriction, including without limitation the rights to use, copy, modify, merge, publish, distribute, sublicense, and/or sell copies of the Software, and to permit persons to whom the Software is furnished to do so, subject to the following conditions:
+
+The above copyright notice and this permission notice shall be included in all copies or substantial portions of the Software.
+
+THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
diff --git a/src/ProgressMeter/ProgressMeter.jl b/src/ProgressMeter/ProgressMeter.jl
@@ -0,0 +1,114 @@
+module ProgressMeter
+
+using Printf: @printf, @sprintf
+
+"""
+Holds the five characters that will be used to generate the progress bar.
+"""
+mutable struct BarGlyphs
+    leftend::Char
+    fill::Char
+    front::Union{Vector{Char}, Char}
+    empty::Char
+    rightend::Char
+end
+
+BarGlyphs() = BarGlyphs(
+    '|',
+    '█',
+    Sys.iswindows() ? '█' : ['▏', '▎', '▍', '▌', '▋', '▊', '▉'],
+    ' ',
+    '|',
+)
+
+struct ProgressBar
+    barglyphs::BarGlyphs
+    tfirst::Float64
+end
+
+ProgressBar(barglyphs = BarGlyphs()) = ProgressBar(barglyphs, time())
+
+"""
+    printprogress(io::IO, p::ProgressBar, desc, progress::Real)
+
+Print progress bar to `io` with setting `p`.
+
+# Arguments
+- `io::IO`
+- `p::ProgressBar`
+- `desc`: description to be printed at left side of progress bar.
+- `progress::Real`: a number between 0 and 1 or a `NaN`.
+"""
+function printprogress(io::IO, p::ProgressBar, desc, progress::Real)
+    t = time()
+    percentage_complete = 100.0 * (isnan(progress) ? 0.0 : progress)
+
+    #...length of percentage and ETA string with days is 29 characters
+    barlen = max(0, displaysize(io)[2] - (length(desc) + 29))
+
+    if progress >= 1
+        bar = barstring(barlen, percentage_complete, barglyphs=p.barglyphs)
+        dur = durationstring(t - p.tfirst)
+        @printf io "%s%3u%%%s Time: %s" desc round(Int, percentage_complete) bar dur
+        return
+    end
+
+    bar = barstring(barlen, percentage_complete, barglyphs=p.barglyphs)
+    elapsed_time = t - p.tfirst
+    est_total_time = 100 * elapsed_time / percentage_complete
+    if 0 <= est_total_time <= typemax(Int)
+        eta_sec = round(Int, est_total_time - elapsed_time)
+        eta = durationstring(eta_sec)
+    else
+        eta = "N/A"
+    end
+    @printf io "%s%3u%%%s  ETA: %s" desc round(Int, percentage_complete) bar eta
+    return
+end
+
+function compute_front(barglyphs::BarGlyphs, frac_solid::AbstractFloat)
+    barglyphs.front isa Char && return barglyphs.front
+    idx = round(Int, frac_solid * (length(barglyphs.front) + 1))
+    return idx > length(barglyphs.front) ? barglyphs.fill :
+           idx == 0 ? barglyphs.empty :
+           barglyphs.front[idx]
+end
+
+function barstring(barlen, percentage_complete; barglyphs)
+    bar = ""
+    if barlen>0
+        if percentage_complete == 100 # if we're done, don't use the "front" character
+            bar = string(barglyphs.leftend, repeat(string(barglyphs.fill), barlen), barglyphs.rightend)
+        else
+            n_bars = barlen * percentage_complete / 100
+            nsolid = trunc(Int, n_bars)
+            frac_solid = n_bars - nsolid
+            nempty = barlen - nsolid - 1
+            bar = string(barglyphs.leftend,
+                         repeat(string(barglyphs.fill), max(0,nsolid)),
+                         compute_front(barglyphs, frac_solid),
+                         repeat(string(barglyphs.empty), max(0, nempty)),
+                         barglyphs.rightend)
+        end
+    end
+    bar
+end
+
+function durationstring(nsec)
+    days = div(nsec, 60*60*24)
+    r = nsec - 60*60*24*days
+    hours = div(r,60*60)
+    r = r - 60*60*hours
+    minutes = div(r, 60)
+    seconds = floor(r - 60*minutes)
+
+    hhmmss = @sprintf "%u:%02u:%02u" hours minutes seconds
+    if days>9
+        return @sprintf "%.2f days" nsec/(60*60*24)
+    elseif days>0
+        return @sprintf "%u days, %s" days hhmmss
+    end
+    hhmmss
+end
+
+end
diff --git a/src/TerminalLogger.jl b/src/TerminalLogger.jl
@@ -1,5 +1,5 @@
 """
-    TerminalLogger(stream=stderr, min_level=Info; meta_formatter=default_metafmt,
+    TerminalLogger(stream=stderr, min_level=$ProgressLevel; meta_formatter=default_metafmt,
                    show_limited=true, right_justify=0)
 
 Logger with formatting optimized for readability in a text console, for example
@@ -28,12 +28,21 @@ struct TerminalLogger <: AbstractLogger
     right_justify::Int
     message_limits::Dict{Any,Int}
     sticky_messages::StickyMessages
+    bars::Dict{Any,ProgressBar}
 end
-function TerminalLogger(stream::IO=stderr, min_level=Info;
+function TerminalLogger(stream::IO=stderr, min_level=ProgressLevel;
                         meta_formatter=default_metafmt, show_limited=true,
                         right_justify=0)
-    TerminalLogger(stream, min_level, meta_formatter,
-                   show_limited, right_justify, Dict{Any,Int}(), StickyMessages(stream))
+    TerminalLogger(
+        stream,
+        min_level,
+        meta_formatter,
+        show_limited,
+        right_justify,
+        Dict{Any,Int}(),
+        StickyMessages(stream),
+        Dict{Any,ProgressBar}(),
+    )
 end
 
 shouldlog(logger::TerminalLogger, level, _module, group, id) =
@@ -94,6 +103,46 @@ function termlength(str)
     return N
 end
 
+function handle_progress(logger, message, id, progress)
+    # Don't do anything when it's already done:
+    if (progress == "done" || progress >= 1) && !haskey(logger.bars, id)
+        return
+    end
+
+    try
+        bar = get!(ProgressBar, logger.bars, id)
+
+        if message == ""
+            message = "Progress: "
+        else
+            message = string(message)
+            if !endswith(message, " ")
+                message *= " "
+            end
+        end
+
+        bartxt = sprint(
+            printprogress,
+            bar,
+            message,
+            progress == "done" ? 1.0 : progress;
+            context = :displaysize => displaysize(logger.stream),
+        )
+
+        if progress == "done" || progress >= 1
+            pop!(logger.sticky_messages, id)
+            println(logger.stream, bartxt)
+        else
+            push!(logger.sticky_messages, id => bartxt)
+        end
+    finally
+        if progress == "done" || progress >= 1
+            pop!(logger.sticky_messages, id)  # redundant (but safe) if no error
+            pop!(logger.bars, id, nothing)
+        end
+    end
+end
+
 function handle_message(logger::TerminalLogger, level, message, _module, group, id,
                         filepath, line; maxlog=nothing, progress=nothing,
                         sticky=nothing, kwargs...)
@@ -103,6 +152,11 @@ function handle_message(logger::TerminalLogger, level, message, _module, group,
         remaining > 0 || return
     end
 
+    if progress == "done" || progress isa Real
+        handle_progress(logger, message, id, progress)
+        return
+    end
+
 	substr(s) = SubString(s, 1, length(s)) # julia 0.6 compat
 
     # Generate a text representation of the message and all key value pairs,
@@ -129,14 +183,6 @@ function handle_message(logger::TerminalLogger, level, message, _module, group,
         end
     end
 
-    if progress !== nothing
-        if (progress isa Symbol && progress == :done) || progress == 1
-            sticky = :done
-        else
-            sticky = true
-        end
-    end
-
     # Format lines as text with appropriate indentation and with a box
     # decoration on the left.
     color,prefix,suffix = logger.meta_formatter(level, _module, group, id, filepath, line)
@@ -162,12 +208,6 @@ function handle_message(logger::TerminalLogger, level, message, _module, group,
             printstyled(iob, prefix, " ", bold=true, color=color)
         end
         print(iob, " "^indent, msg)
-        if i == 1 && progress !== nothing
-            progress = clamp(convert(Float64, progress), 0.0, 1.0)
-            barfulllen = dsize[2] - length(boxstr) - length(prefix) - indent - length(msg) - 2
-            barlen = round(Int, barfulllen*progress)
-            print(iob, ' ', '='^barlen, ' '^(barfulllen-barlen))
-        end
         if i == length(msglines) && !isempty(suffix)
             npad = max(0, justify_width - nonpadwidth) + minsuffixpad
             print(iob, " "^npad)
diff --git a/src/TerminalLoggers.jl b/src/TerminalLoggers.jl
@@ -9,6 +9,12 @@ import Logging:
 
 export TerminalLogger
 
+const ProgressLevel = LogLevel(-1)
+
+include("ProgressMeter/ProgressMeter.jl")
+using .ProgressMeter:
+    ProgressBar, printprogress
+
 include("StickyMessages.jl")
 include("TerminalLogger.jl")
 
diff --git a/test/TerminalLogger.jl b/test/TerminalLogger.jl
@@ -42,20 +42,40 @@ import TerminalLoggers.default_metafmt
     end
 
     # Log formatting
-    function genmsg(message; level=Info, _module=Main,
-                    file="some/path.jl", line=101, color=false, width=75,
-                    meta_formatter=dummy_metafmt, show_limited=true,
-                    right_justify=0, kws...)
+    function genmsgs(events; level=Info, _module=Main,
+                     file="some/path.jl", line=101, color=false, width=75,
+                     meta_formatter=dummy_metafmt, show_limited=true,
+                     right_justify=0)
         buf = IOBuffer()
         io = IOContext(buf, :displaysize=>(30,width), :color=>color)
         logger = TerminalLogger(io, Debug,
                                 meta_formatter=meta_formatter,
                                 show_limited=show_limited,
                                 right_justify=right_justify)
         prev_have_color = Base.have_color
-        handle_message(logger, level, message, _module, :a_group, :an_id,
-                       file, line; kws...)
-        String(take!(buf))
+        return map(events) do (message, kws)
+            handle_message(logger, level, message, _module, :a_group, :an_id,
+                           file, line; kws...)
+            String(take!(buf))
+        end
+    end
+    function genmsg(message; kwargs...)
+        kws = Dict(kwargs)
+        logconfig = Dict(
+            k => pop!(kws, k)
+            for k in [
+                :level,
+                :_module,
+                :file,
+                :line,
+                :color,
+                :width,
+                :meta_formatter,
+                :show_limited,
+                :right_justify,
+            ] if haskey(kws, k)
+        )
+        return genmsgs([(message, kws)]; logconfig...)[1]
     end
 
     # Basic tests for the default setup
@@ -196,7 +216,7 @@ import TerminalLoggers.default_metafmt
         """,
         # EOL hack to work around git whitespace errors
         # VERSION dependence due to JuliaLang/julia#33339
-        (VERSION <= v"1.3" ? "EOL" : "       EOL")=>""
+        (VERSION < v"1.4-" ? "EOL" : "       EOL")=>""
         )
         # Limiting the amount which is printed
         @test genmsg("msg", a=fill(1.00001, 10,10), show_limited=false) ==
@@ -225,4 +245,18 @@ import TerminalLoggers.default_metafmt
     \e[36m\e[1m│ \e[22m\e[39mline2
     \e[36m\e[1m└ \e[22m\e[39m\e[90mSUFFIX\e[39m
     """
+
+    # Using infix operator so that `@test` prints lhs and rhs when failed:
+    ⊏(s, re) = match(re, s) !== nothing
+
+    @test genmsg("", progress=0.1, width=60) ⊏
+    r"Progress:  10%\|██.                  \|  ETA: 0:00:[0-9][0-9]"
+    @test genmsg("", progress=NaN, width=60) ⊏
+    r"Progress:   0%|.                    |  ETA: N/A"
+    @test genmsg("", progress=1.0, width=60) == ""
+    @test genmsg("", progress="done", width=60) == ""
+    @test genmsgs([("", (progress = 0.1,)), ("", (progress = 1.0,))], width = 60)[end] ⊏
+    r"Progress: 100%|█████████████████████| Time: 0:00:[0-9][0-9]"
+    @test genmsgs([("", (progress = 0.1,)), ("", (progress = "done",))], width = 60)[end] ⊏
+    r"Progress: 100%|█████████████████████| Time: 0:00:[0-9][0-9]"
 end
