Markdown formatting for AbstractString log messages

Project.toml

@@ -6,6 +6,7 @@ version = "0.1.0"
 [deps]
 LeftChildRightSiblingTrees = "1d6d02ad-be62-4b6b-8a6d-2f90e265016e"
 Logging = "56ddb016-857b-54e1-b83d-db4d58db5568"
+Markdown = "d6f4376e-aef5-505a-96c1-9c027394607a"
 Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7"
 ProgressLogging = "33c8b6b6-d38a-422a-b730-caa89a2f386c"
 UUIDs = "cf7118a7-6976-5b1a-9a39-7adc72f591a4"

src/TerminalLogger.jl

@@ -1,3 +1,5 @@
+using Markdown
+
 """
     TerminalLogger(stream=stderr, min_level=$ProgressLevel; meta_formatter=default_metafmt,
                    show_limited=true, right_justify=0)
@@ -104,6 +106,46 @@ function termlength(str)
     return N
 end
 
+function format_message(message, prefix_width, io_context)
+    formatted = sprint(show, MIME"text/plain"(), message, context=io_context)
+    msglines = split(chomp(formatted), '\n')
+    if length(msglines) > 1
+        # For multi-line messages it's possible that the message was carefully
+        # formatted with vertical alignemnt. Therefore we play it safe by
+        # prepending a blank line.
+        pushfirst!(msglines, SubString(""))
+    end
+    msglines
+end
+
+function format_message(message::AbstractString, prefix_width, io_context)
+    # For strings, use Markdown to do the formatting. The markdown renderer
+    # isn't very composable with other text formatting so this is quite hacky.
+    message = Markdown.parse(message)
+    prepend_prefix = !isempty(message.content) &&
+                     message.content[1] isa Markdown.Paragraph
+    if prepend_prefix
+        # Hack: We prepend the prefix here to allow the markdown renderer to be
+        # aware of the indenting which will result from prepending the prefix.
+        # Without this we will get many issues of broken vertical alignment.
+        # Avoid collisions: using placeholder from unicode private use area
+        placeholder = '\uF8FF'^prefix_width
+        pushfirst!(message.content[1].content, placeholder)
+    end
+    formatted = sprint(show, MIME"text/plain"(), message, context=io_context)
+    msglines = split(chomp(formatted), '\n')
+    # Hack': strip left margin which can't be configured in Markdown
+    # terminal rendering.
+    msglines = [startswith(s, "  ") ? s[3:end] : s for s in msglines]
+    if prepend_prefix
+        # Hack'': Now remove the prefix from the rendered markdown.
+        msglines[1] = replace(msglines[1], placeholder=>""; count=1)
+    elseif !isempty(msglines[1])
+        pushfirst!(msglines, SubString(""))
+    end
+    msglines
+end
+
 function findbar(bartree, id)
     if !(bartree isa AbstractArray)
         bartree.data.id === id && return bartree
@@ -208,10 +250,15 @@ function handle_message(logger::TerminalLogger, level, message, _module, group,
 
 	substr(s) = SubString(s, 1, length(s)) # julia 0.6 compat
 
-    # Generate a text representation of the message and all key value pairs,
-    # split into lines.
-    msglines = [(0,l) for l in split(chomp(string(message)), '\n')]
+    color,prefix,suffix = logger.meta_formatter(level, _module, group, id, filepath, line)
+
+    # Generate a text representation of the message
     dsize = displaysize(logger.stream)
+    msglines = format_message(message, textwidth(prefix),
+                              IOContext(logger.stream, :displaysize=>(dsize[1],dsize[2]-2)))
+    # Add indentation level
+    msglines = [(0,l) for l in msglines]
+    # Generate a text representation of all key value pairs, split into lines.
     if !isempty(kwargs)
         valbuf = IOBuffer()
         rows_per_value = max(1, dsize[1]÷(length(kwargs)+1))
@@ -234,7 +281,6 @@ function handle_message(logger::TerminalLogger, level, message, _module, group,
 
     # 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)
     minsuffixpad = 2
     buf = IOBuffer()
     iob = IOContext(buf, logger.stream)

test/TerminalLogger.jl

@@ -1,7 +1,55 @@
-import TerminalLoggers.default_metafmt
+using TerminalLoggers: default_metafmt, format_message
 
 @noinline func1() = backtrace()
 
+function dummy_metafmt(level, _module, group, id, file, line)
+    :cyan,"PREFIX","SUFFIX"
+end
+
+# Log formatting
+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
+    return map(events) do (message, kws)
+        kws = Dict(pairs(kws))
+        id = pop!(kws, :_id, :an_id)
+        # Avoid markdown formatting while testing layouting. Don't wrap
+        # progress messages though; ProgressLogging.asprogress() doesn't
+        # like that.
+        is_progress = message isa Progress || haskey(kws, :progress)
+        handle_message(logger, level, message, _module, :a_group, 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
+
 @testset "TerminalLogger" begin
     # First pass log limiting
     @test min_enabled_level(TerminalLogger(devnull, Debug)) == Debug
@@ -35,59 +83,15 @@ import TerminalLoggers.default_metafmt
             (:yellow,    "Warning:", "@ Main b.jl:2-5")
     end
 
-    function dummy_metafmt(level, _module, group, id, file, line)
-        :cyan,"PREFIX","SUFFIX"
-    end
-
-    # Log formatting
-    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
-        return map(events) do (message, kws)
-            kws = Dict(pairs(kws))
-            id = pop!(kws, :_id, :an_id)
-            handle_message(logger, level, message, _module, :a_group, 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
     @test genmsg("msg", level=Info, meta_formatter=default_metafmt) ==
     """
     [ Info: msg
     """
-    @test genmsg("line1\nline2", level=Warn, _module=Base,
+    @test genmsg("msg", level=Warn, _module=Base,
                  file="other.jl", line=42, meta_formatter=default_metafmt) ==
     """
-    ┌ Warning: line1
-    │ line2
+    ┌ Warning: msg
     └ @ Base other.jl:42
     """
     # Full metadata formatting
@@ -127,10 +131,10 @@ import TerminalLoggers.default_metafmt
         """
         [ PREFIX xxx  SUFFIX
         """
-        @test genmsg("xxx\nxxx", width=20, right_justify=200) ==
+        @test genmsg("xxxxxxxx xxxxxxxx", width=20, right_justify=200) ==
         """
-        ┌ PREFIX xxx
-        └ xxx         SUFFIX
+        ┌ PREFIX xxxxxxxx
+        └ xxxxxxxx    SUFFIX
         """
         # When adding the suffix would overflow the display width, add it on
         # the next line:
@@ -239,9 +243,10 @@ import TerminalLoggers.default_metafmt
     end
 
     # Basic colorization test.
-    @test genmsg("line1\nline2", color=true) ==
+    @test genmsg("line1\n\nline2", color=true) ==
     """
     \e[36m\e[1m┌ \e[22m\e[39m\e[36m\e[1mPREFIX \e[22m\e[39mline1
+    \e[36m\e[1m│ \e[22m\e[39m
     \e[36m\e[1m│ \e[22m\e[39mline2
     \e[36m\e[1m└ \e[22m\e[39m\e[90mSUFFIX\e[39m
     """
@@ -260,6 +265,34 @@ import TerminalLoggers.default_metafmt
     @test genmsgs([("", (progress = 0.1,)), ("", (progress = "done",))], width = 60)[end] ⊏
     r"Progress: 100%\|█+\| Time: .*"
 
+    @testset "Message formatting" begin
+        io_ctx = IOContext(IOBuffer(), :displaysize=>(20,20))
+
+        # Short paragraph on a single line
+        @test format_message("Hi `code`", 6, io_ctx) ==
+            ["Hi code"]
+
+        # Longer paragraphs wrap around the prefix
+        @test format_message("x x x x x x x x x x x x x x x x x x x x x", 6, io_ctx) ==
+             ["x x x x x"
+              "x x x x x x x x"
+              "x x x x x x x x"]
+
+        # Markdown block elements get their own lines
+        @test format_message("# Hi", 6, io_ctx) ==
+            ["",
+             "Hi",
+             "≡≡≡≡"]
+
+        # For non-strings a blank line is added so that any formatting for
+        # vertical alignment isn't broken
+        @test format_message([1 2; 3 4], 6, io_ctx) ==
+            ["",
+             "2×2 Array{Int64,2}:",
+             " 1  2",
+             " 3  4"]
+    end
+
     @testset "Independent progress bars" begin
         msgs = genmsgs([
             ("Bar1", (progress = 0.0, _id = 1111)), # 1