@@ -62,9 +62,79 @@ if VERSION >= v"1.13.0-DEV.1044"
6262 using Base. ScopedValues
6363end
6464
65+ abstract type AbstractTestRecord end
66+
67+ struct TestRecord <: AbstractTestRecord
68+ test:: Any
69+ time:: Float64
70+ bytes:: Int
71+ gctime:: Float64
72+ rss:: UInt
73+ end
74+
75+ function memory_usage (rec:: TestRecord )
76+ return rec. rss
77+ end
78+
79+ struct TestIOContext
80+ io:: IO
81+ lock:: ReentrantLock
82+ name_align:: Int
83+ elapsed_align:: Int
84+ gc_align:: Int
85+ percent_align:: Int
86+ alloc_align:: Int
87+ rss_align:: Int
88+ end
89+
90+ function test_IOContext (:: Type{TestRecord} , io:: IO , lock:: ReentrantLock , name_align:: Int )
91+ elapsed_align = textwidth (" Time (s)" )
92+ gc_align = textwidth (" GC (s)" )
93+ percent_align = textwidth (" GC %" )
94+ alloc_align = textwidth (" Alloc (MB)" )
95+ rss_align = textwidth (" RSS (MB)" )
96+
97+ return TestIOContext (
98+ io, lock, name_align, elapsed_align, gc_align, percent_align,
99+ alloc_align, rss_align
100+ )
101+ end
102+
103+ function print_header (:: Type{TestRecord} , ctx:: TestIOContext , testgroupheader, workerheader)
104+ printstyled (ctx. io, " " ^ (ctx. name_align + textwidth (testgroupheader) - 3 ), " | " )
105+ printstyled (ctx. io, " | ---------------- CPU ---------------- |\n " , color = :white )
106+ printstyled (ctx. io, testgroupheader, color = :white )
107+ printstyled (ctx. io, lpad (workerheader, ctx. name_align - textwidth (testgroupheader) + 1 ), " | " , color = :white )
108+ printstyled (ctx. io, " Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB) |\n " , color = :white )
109+ return nothing
110+ end
111+
112+ function print_testworker_stats (test, wrkr, record:: TestRecord , ctx:: TestIOContext )
113+ lock (ctx. lock)
114+ return try
115+ printstyled (ctx. io, test, color = :white )
116+ printstyled (ctx. io, lpad (" ($wrkr )" , ctx. name_align - textwidth (test) + 1 , " " ), " | " , color = :white )
117+ time_str = @sprintf (" %7.2f" , record. time)
118+ printstyled (ctx. io, lpad (time_str, ctx. elapsed_align, " " ), " | " , color = :white )
119+
120+ gc_str = @sprintf (" %5.2f" , record. gctime)
121+ printstyled (ctx. io, lpad (gc_str, ctx. gc_align, " " ), " | " , color = :white )
122+ percent_str = @sprintf (" %4.1f" , 100 * record. gctime / record. time)
123+ printstyled (ctx. io, lpad (percent_str, ctx. percent_align, " " ), " | " , color = :white )
124+ alloc_str = @sprintf (" %5.2f" , record. bytes / 2 ^ 20 )
125+ printstyled (ctx. io, lpad (alloc_str, ctx. alloc_align, " " ), " | " , color = :white )
126+
127+ rss_str = @sprintf (" %5.2f" , record. rss / 2 ^ 20 )
128+ printstyled (ctx. io, lpad (rss_str, ctx. rss_align, " " ), " |\n " , color = :white )
129+ finally
130+ unlock (ctx. lock)
131+ end
132+ end
133+
134+
65135# # entry point
66136
67- function runtest (f, name)
137+ function runtest (:: Type{TestRecord} , f, name)
68138 function inner ()
69139 # generate a temporary module to execute the tests in
70140 mod_name = Symbol (" Test" , rand (1 : 100 ), " Main_" , replace (name, ' /' => ' _' ))
@@ -83,9 +153,10 @@ function runtest(f, name)
83153 res = @timed @testset $ name begin
84154 Main. include ($ f)
85155 end
86- res... , 0 , 0 , 0
156+ ( res... ,)
87157 end
88158 data = Core. eval (mod, ex)
159+
89160 # data[1] is the testset
90161
91162 # process results
@@ -105,13 +176,9 @@ function runtest(f, name)
105176 data[2 ],
106177 data[3 ],
107178 data[4 ],
108- data[5 ],
109- data[6 ],
110- data[7 ],
111- data[8 ],
112179 )
113180 end
114- res = vcat ( collect ( data) , rss)
181+ res = TestRecord ( data... , rss)
115182
116183 GC. gc (true )
117184 return res
@@ -133,7 +200,7 @@ function runtest(f, name)
133200 return res
134201end
135202
136- function runtests (ARGS , testfilter = _ -> true )
203+ function runtests (ARGS , testfilter = _ -> true , RecordType = TestRecord )
137204 do_help, _ = extract_flag! (ARGS , " --help" )
138205 if do_help
139206 println (
@@ -270,42 +337,16 @@ function runtests(ARGS, testfilter = _ -> true)
270337 )
271338 ]
272339 )
340+
273341 elapsed_align = textwidth (" Time (s)" )
274- gc_align = textwidth (" GC (s)" )
275- percent_align = textwidth (" GC %" )
276- alloc_align = textwidth (" Alloc (MB)" )
277- rss_align = textwidth (" RSS (MB)" )
278- printstyled (" " ^ (name_align + textwidth (testgroupheader) - 3 ), " | " )
279- printstyled (" | ---------------- CPU ---------------- |\n " , color = :white )
280- printstyled (testgroupheader, color = :white )
281- printstyled (lpad (workerheader, name_align - textwidth (testgroupheader) + 1 ), " | " , color = :white )
282- printstyled (" Time (s) | GC (s) | GC % | Alloc (MB) | RSS (MB) |\n " , color = :white )
283342 print_lock = stdout isa Base. LibuvStream ? stdout . lock : ReentrantLock ()
284343 if stderr isa Base. LibuvStream
285344 stderr . lock = print_lock
286345 end
287- function print_testworker_stats (test, wrkr, resp)
288- @nospecialize resp
289- lock (print_lock)
290- return try
291- printstyled (test, color = :white )
292- printstyled (lpad (" ($wrkr )" , name_align - textwidth (test) + 1 , " " ), " | " , color = :white )
293- time_str = @sprintf (" %7.2f" , resp[2 ])
294- printstyled (lpad (time_str, elapsed_align, " " ), " | " , color = :white )
295-
296- gc_str = @sprintf (" %5.2f" , resp[4 ])
297- printstyled (lpad (gc_str, gc_align, " " ), " | " , color = :white )
298- percent_str = @sprintf (" %4.1f" , 100 * resp[4 ] / resp[2 ])
299- printstyled (lpad (percent_str, percent_align, " " ), " | " , color = :white )
300- alloc_str = @sprintf (" %5.2f" , resp[3 ] / 2 ^ 20 )
301- printstyled (lpad (alloc_str, alloc_align, " " ), " | " , color = :white )
302-
303- rss_str = @sprintf (" %5.2f" , resp[9 ] / 2 ^ 20 )
304- printstyled (lpad (rss_str, rss_align, " " ), " |\n " , color = :white )
305- finally
306- unlock (print_lock)
307- end
308- end
346+
347+ io_ctx = test_IOContext (RecordType, stdout , print_lock, name_align)
348+ print_header (RecordType, io_ctx, testgroupheader, workerheader)
349+
309350 global print_testworker_started = (name, wrkr) -> begin
310351 if do_verbose
311352 lock (print_lock)
@@ -391,7 +432,7 @@ function runtests(ARGS, testfilter = _ -> true)
391432 # run the test
392433 running_tests[test] = now ()
393434 try
394- resp = remotecall_fetch (runtest, wrkr, test_runners[test], test)
435+ resp = remotecall_fetch (runtest, wrkr, RecordType, test_runners[test], test)
395436 catch e
396437 isa (e, InterruptException) && return
397438 resp = Any[e]
@@ -400,20 +441,22 @@ function runtests(ARGS, testfilter = _ -> true)
400441 push! (results, (test, resp))
401442
402443 # act on the results
403- if resp[1 ] isa Exception
444+ if resp isa AbstractTestRecord
445+ print_testworker_stats (test, wrkr, resp:: RecordType , io_ctx)
446+
447+ if memory_usage (resp) > max_worker_rss
448+ # the worker has reached the max-rss limit, recycle it
449+ # so future tests start with a smaller working set
450+ p = recycle_worker (p)
451+ end
452+ else
453+ @assert resp[1 ] isa Exception
404454 print_testworker_errored (test, wrkr)
405455 do_quickfail && Base. throwto (t, InterruptException ())
406456
407457 # the worker encountered some failure, recycle it
408458 # so future tests get a fresh environment
409459 p = recycle_worker (p)
410- else
411- print_testworker_stats (test, wrkr, resp)
412- if resp[end ] > max_worker_rss
413- # the worker has reached the max-rss limit, recycle it
414- # so future tests start with a smaller working set
415- p = recycle_worker (p)
416- end
417460 end
418461 end
419462
@@ -460,7 +503,12 @@ function runtests(ARGS, testfilter = _ -> true)
460503 o_ts = Test. DefaultTestSet (" Overall" )
461504 with_testset (o_ts) do
462505 completed_tests = Set {String} ()
463- for (testname, (resp,)) in results
506+ for (testname, res) in results
507+ if res isa AbstractTestRecord
508+ resp = res. test
509+ else
510+ resp = res[1 ]
511+ end
464512 push! (completed_tests, testname)
465513 if isa (resp, Test. DefaultTestSet)
466514 with_testset (resp) do
0 commit comments