Merge remote-tracking branch 'myk002/myk_test_elapsed' into develop

ci/test.lua

@@ -421,12 +421,18 @@ local function wrap_test(func)
     )
 end
 
+local function get_elapsed_str(elapsed)
+    return elapsed < 1 and "<1" or tostring(elapsed)
+end
+
 local function run_test(test, status, counts)
     test.private.checks = 0
     test.private.checks_ok = 0
     counts.tests = counts.tests + 1
     dfhack.internal.IN_TEST = true
+    local start_ms = dfhack.getTickCount()
     local ok, err = wrap_test(test.func)
+    local elapsed_ms = dfhack.getTickCount() - start_ms
     dfhack.internal.IN_TEST = false
     local passed = false
     if not ok then
@@ -435,7 +441,8 @@ local function run_test(test, status, counts)
     elseif test.private.checks ~= test.private.checks_ok then
         dfhack.printerr('test failed: ' .. test.name)
     else
-        print('test passed: ' .. test.name)
+        local elapsed_str = get_elapsed_str(elapsed_ms)
+        print(('test passed in %s ms: %s'):format(elapsed_str, test.name))
         passed = true
         counts.tests_ok = counts.tests_ok + 1
     end
@@ -513,6 +520,7 @@ end
 
 local function run_tests(tests, status, counts, config)
     print(('Running %d tests'):format(#tests))
+    local start_ms = dfhack.getTickCount()
     local num_skipped = 0
     for _, test in pairs(tests) do
         if MODES[test.config.mode].failed then
@@ -536,6 +544,7 @@ local function run_tests(tests, status, counts, config)
         save_test_status(status)
         ::skip::
     end
+    local elapsed_ms = dfhack.getTickCount() - start_ms
 
     local function print_summary_line(ok, message)
         local print_fn = print
@@ -543,11 +552,11 @@ local function run_tests(tests, status, counts, config)
             status['*'] = TestStatus.FAILED
             print_fn = dfhack.printerr
         end
-        print_fn(message)
+        print_fn('  ' .. message)
     end
 
     status['*'] = status['*'] or TestStatus.PASSED
-    print('\nTest summary:')
+    print(('\nTests completed in %s ms:'):format(get_elapsed_str(elapsed_ms)))
     print_summary_line(counts.tests_ok == counts.tests,
         ('%d/%d tests passed'):format(counts.tests_ok, counts.tests))
     print_summary_line(counts.checks_ok == counts.checks,