Improve tests/run.sh (#1904)

- add colors
- count test files
- display error summary
- filter out a_dbus_connect warnings and "Test finished successfully." message
- print current step with VERBOSE=1
- kill clients at the end of tests in an extra step

tests/_runner.lua

@@ -6,6 +6,8 @@ local runner = {
     quit_awesome_on_error = os.getenv('TEST_PAUSE_ON_ERRORS') ~= '1',
 }
 
+local verbose = os.getenv('VERBOSE') == '1'
+
 -- Helpers.
 
 --- Add some rules to awful.rules.rules, after the defaults.
@@ -21,7 +23,7 @@ local running = false
 -- This is used if a test causes errors before starting the runner
 timer.start_new(1, function()
     if not running then
-        io.stderr:write("Error: run_steps() was never called\n")
+        io.stderr:write("Error: run_steps() was never called.\n")
         if not runner.quit_awesome_on_error then
             io.stderr:write("Keeping awesome open...\n")
             return  -- keep awesome open on error.
@@ -30,19 +32,42 @@ timer.start_new(1, function()
     end
 end)
 
-runner.run_steps = function(steps)
+runner.step_kill_clients = function(step)
+    if step == 1 then
+        for _,c in ipairs(client.get()) do
+            c:kill()
+        end
+    end
+    if #client.get() == 0 then
+        return true
+    end
+end
+
+runner.run_steps = function(steps, options)
     -- Setup timer/timeout to limit waiting for signal and quitting awesome.
-    -- This would be common for all tests.
     local t = timer({timeout=0})
     local wait=20
     local step=1
     local step_count=0
+    options = options or {
+        kill_clients=true,
+    }
     assert(not running, "run_steps() was called twice")
     running = true
+
+    if options.kill_clients then
+        -- Add a final step to kill all clients and wait for them to finish.
+        -- Ref: https://github.com/awesomeWM/awesome/pull/1904#issuecomment-312793006
+        steps[#steps + 1] = runner.step_kill_clients
+    end
+
     t:connect_signal("timeout", function() timer.delayed_call(function()
         io.flush()  -- for "tail -f".
         step_count = step_count + 1
         local step_as_string = step..'/'..#steps..' (@'..step_count..')'
+        if verbose then
+            print(string.format('Running step %s..', step_as_string))
+        end
 
         -- Call the current step's function.
         local success, result = xpcall(function()
@@ -78,6 +103,7 @@ runner.run_steps = function(steps)
             end
 
         else
+            -- No result yet, run this step again.
             wait = wait-1
             if wait > 0 then
                 t.timeout = 0.1
@@ -89,12 +115,20 @@ runner.run_steps = function(steps)
             end
             return
         end
-        -- Remove any clients.
+
-        for _,c in ipairs(client.get()) do
+        local client_count = #client.get()
-            c:kill()
+        if client_count > 0 then
+            io.stderr:write(string.format(
+                "NOTE: there were %d clients left after the test.\n", client_count))
+
+            -- Remove any clients.
+            for _,c in ipairs(client.get()) do
+                c:kill()
+            end
         end
+
         if success and result then
-            io.stderr:write("Test finished successfully\n")
+            io.stderr:write("Test finished successfully.\n")
         end
         awesome.quit()
     end) end)

tests/run.sh

@@ -82,7 +82,8 @@ else
 fi
 
 # Add test dir (for _runner.lua).
-awesome_options=($AWESOME_OPTIONS --search lib --search $this_dir)
+# shellcheck disable=SC2206
+awesome_options=($AWESOME_OPTIONS --search lib --search "$this_dir")
 export XDG_CONFIG_HOME="$build_dir"
 
 # Cleanup on errors / aborting.
@@ -187,13 +188,22 @@ start_awesome() {
     wait_until_success "wait for awesome startup via awesome-client" "dbus-send --reply-timeout=100 --dest=org.awesomewm.awful --print-reply / org.awesomewm.awful.Remote.Eval 'string:return 1' 2>&1"
 }
 
-# Count errors.
+if command -v tput >/dev/null; then
-errors=0
+    color_red() { tput setaf 1; }
+    color_reset() { tput sgr0; }
+else
+    color_red() { :; }
+    color_reset() { :; }
+fi
+
+count_tests=0
+errors=()
 # Seconds after when awesome gets killed.
 timeout_stale=180 # FIXME This should be no more than 60s
 
 for f in $tests; do
     echo "== Running $f =="
+    (( ++count_tests ))
 
     start_awesome
 
@@ -202,7 +212,7 @@ for f in $tests; do
             f=${f#tests/}
         else
             echo "===> ERROR $f is not readable! <==="
-            ((errors++))
+            errors+=("$f is not readable.")
             continue
         fi
     fi
@@ -211,7 +221,9 @@ for f in $tests; do
     DISPLAY=$D "$AWESOME_CLIENT" 2>&1 < "$f"
 
     # Tail the log and quit, when awesome quits.
-    tail -n 100000 -s 0.1 -f --pid "$awesome_pid" "$awesome_log"
+    # Use a single `grep`, otherwise `--line-buffered` would be required.
+    tail -n 100000 -s 0.1 -f --pid "$awesome_pid" "$awesome_log" \
+        | grep -vE '^(.{19} W: awesome: a_dbus_connect:[0-9]+: Could not connect to D-Bus system bus:|Test finished successfully\.$)' || true
 
     set +e
     wait $awesome_pid
@@ -223,20 +235,37 @@ for f in $tests; do
         *) echo "Awesome exited with status code $code" ;;
     esac
 
-    if ! grep -q -E '^Test finished successfully$' "$awesome_log" ||
+    # Parse any error from the log.
-            grep -q -E '[Ee]rror|assertion failed' "$awesome_log"; then
+    error="$(grep --color -o --binary-files=text -E \
+        '.*[Ee]rror.*|.*assertion failed.*|^Step .* failed:' "$awesome_log" ||
+        true)"
+    if [[ -n "$error" ]]; then
+        color_red
         echo "===> ERROR running $f <==="
-        grep --color -o --binary-files=text -E '.*[Ee]rror.*|.*assertion failed.*' "$awesome_log" || true
+        echo "$error"
-        ((++errors))
+        color_reset
+        errors+=("$f: $error")
+    elif ! grep -q -E '^Test finished successfully\.$' "$awesome_log"; then
+        color_red
+        echo "===> ERROR running $f <==="
+        color_reset
+        errors+=("$f: test did not indicate success. See the output above.")
     fi
 done
 
-if ((errors)); then
+echo "$count_tests tests finished."
+
+if (( "${#errors[@]}" )); then
     if [ "$TEST_PAUSE_ON_ERRORS" = 1 ]; then
         echo "Pausing... press Enter to continue."
         read -r
     fi
-    echo "There were $errors errors!"
+    color_red
+    echo "There were ${#errors[@]} errors:"
+    for error in "${errors[@]}"; do
+        echo " - $error"
+    done
+    color_reset
     exit 1
 fi
 exit 0