Fix #18739, Make testset results printing better

Now results come in one by one and print their memory/timing data
as they come in. We will no longer print rss results twice. Also,
each test now prints which worker it ran on.

test/runtests.jl

@@ -44,6 +44,16 @@ cd(dirname(@__FILE__)) do
     end
 
     @everywhere include("testdefs.jl")
+
+    #pretty print the information about gc and mem usage
+    name_align    = max(length("Test (Worker):"), maximum(map(x -> length(x) + 3 + ndigits(nworkers()), tests)))
+    elapsed_align = length("Total time (s):")
+    gc_align      = length("GC time (s):")
+    percent_align = length("Percent in gc:")
+    alloc_align   = length("Allocated (MB):")
+    rss_align     = length("RSS (MB):")
+    print_with_color(:white, rpad("Test (Worker):",name_align," "), " | ")
+    print_with_color(:white, "Total time (s): | GC time (s): | Percent in gc: | Allocated (MB): | RSS (MB):\n")
     results=[]
     @sync begin
         for p in workers()
@@ -57,6 +67,18 @@ cd(dirname(@__FILE__)) do
                         resp = [e]
                     end
                     push!(results, (test, resp))
+                    print_with_color(:white, rpad(test*" ($p)", name_align, " "), " | ")
+                    time_str = @sprintf("%7.2f",resp[2])
+                    print_with_color(:white, rpad(time_str,elapsed_align," "), " | ")
+                    gc_str = @sprintf("%7.2f",resp[5].total_time/10^9)
+                    print_with_color(:white, rpad(gc_str,gc_align," "), " | ")
+                    percent_str = @sprintf("%7.2f",100*resp[5].total_time/(10^9*resp[2]))
+                    print_with_color(:white, rpad(percent_str,percent_align," "), " | ")
+                    alloc_str = @sprintf("%7.2f",resp[3]/2^20)
+                    print_with_color(:white, rpad(alloc_str,alloc_align," "), " | ")
+                    rss_str = @sprintf("%7.2f",resp[6]/2^20)
+                    print_with_color(:white, rpad(rss_str,rss_align," "), "\n")
+
                     if (isa(resp[end], Integer) && (resp[end] > max_worker_rss)) || isa(resp, Exception)
                         if n > 1
                             rmprocs(p, waitfor=0.5)
@@ -161,31 +183,6 @@ cd(dirname(@__FILE__)) do
     end
     println()
     Base.Test.print_test_results(o_ts,1)
-    #pretty print the information about gc and mem usage
-    name_align    = maximum(map(x -> length(x[1]), results))
-    elapsed_align = length("Total time (s):")
-    gc_align      = length("GC time (s):")
-    percent_align = length("Percent in gc:")
-    alloc_align   = length("Allocated (MB):")
-    rss_align     = length("RSS (MB):")
-    print_with_color(:white, rpad("Test:",name_align," "), " | ")
-    print_with_color(:white, "Total time (s): | GC time (s): | Percent in gc: | Allocated (MB): | RSS (MB):\n")
-    for res in results
-        if !isa(res[2][1], Exception)
-            print_with_color(:white, rpad("$(res[1])",name_align," "), " | ")
-            time_str = @sprintf("%7.2f",res[2][2])
-            print_with_color(:white, rpad(time_str,elapsed_align," "), " | ")
-            gc_str = @sprintf("%7.2f",res[2][5].total_time/10^9)
-            print_with_color(:white, rpad(gc_str,gc_align," "), " | ")
-            percent_str = @sprintf("%7.2f",100*res[2][5].total_time/(10^9*res[2][2]))
-            print_with_color(:white, rpad(percent_str,percent_align," "), " | ")
-            alloc_str = @sprintf("%7.2f",res[2][3]/2^20)
-            print_with_color(:white, rpad(alloc_str,alloc_align," "), " | ")
-            rss_str = @sprintf("%7.2f",res[2][6]/2^20)
-            print_with_color(:white, rpad(rss_str,rss_align," "), "\n")
-        end
-    end
-
     if !o_ts.anynonpass
         println("    \033[32;1mSUCCESS\033[0m")
     else

test/testdefs.jl

@@ -8,15 +8,13 @@ function runtests(name, isolate=true)
         m = Main
     end
     eval(m, :(using Base.Test))
-    @printf("     \033[1m*\033[0m \033[31m%-21s\033[0m", name)
     ex = quote
         @timed @testset $"$name" begin
             include($"$name.jl")
         end
     end
     res_and_time_data = eval(m, ex)
     rss = Sys.maxrss()
-    @printf(" maxrss %7.2f MB\n", rss / 2^20)
     #res_and_time_data[1] is the testset
     passes,fails,error,broken,c_passes,c_fails,c_errors,c_broken = Base.Test.get_test_counts(res_and_time_data[1])
     if res_and_time_data[1].anynonpass == false