Merge pull request #578 from TypedDevs/feat/577-align-timing-to-right

Align all displayed timings to the right

Author: Chemaclass

CHANGELOG.md

@@ -2,11 +2,14 @@
 
 ## Unreleased
 
+### Changed
+- Hook output now displays with right-aligned timing and bullet prefix (`● set_up_before_script  2.03s`)
+
 ### Added
 - Better code coverage HTML report
 - Auto-discover coverage paths from test file names when `BASHUNIT_COVERAGE_PATHS` is not set
     - `tests/unit/assert_test.sh` automatically tracks `src/assert.sh`
-    - Removes need for manual `--coverage-paths` configuration in most cases
+    - Removes the need for manual `--coverage-paths` configuration in most cases
 - `--coverage-report-html` now defaults to `coverage/html` when no directory is specified
 
 ### Fixed

docs/blog/2025-12-19-release-0-31.md

@@ -72,9 +72,9 @@ See exactly how long your setup and teardown scripts take:
 
 ::: code-group
 ```[Output]
-Running set_up_before_script... done (2.3s)
-✓ Passed: My test                              45 ms
-Running tear_down_after_script... done (0.5s)
+● set_up_before_script                                               2.30s
+✓ Passed: My test                                                      45ms
+● tear_down_after_script                                              0.5s
 ```
 :::
 

docs/test-files.md

@@ -85,12 +85,12 @@ function tear_down() {
 The `set_up_before_script` auxiliary function is called, if it is present in the test file, only once before all tests functions in the test file begin.
 This is useful for global setup that applies to all test functions in the script, such as loading shared resources.
 
-During test execution, bashunit displays the hook execution with its duration:
+During test execution, bashunit displays the hook execution with its duration, right-aligned to match test output:
 
 ```
 Running tests/example_test.sh
-  Running set_up_before_script... done (2.03s)
-✓ Passed: test_example
+● set_up_before_script                                               2.03s
+✓ Passed: test_example                                                 12ms
 ```
 
 This visibility helps identify slow setup operations that may impact test run time.
@@ -114,8 +114,8 @@ It provides a hook for any cleanup that should occur after all tests have run, s
 Like `set_up_before_script`, the execution is displayed with its duration:
 
 ```
-✓ Passed: test_example
-  Running tear_down_after_script... done (1.05s)
+✓ Passed: test_example                                                 12ms
+● tear_down_after_script                                             1.05s
 
 Tests:      1 passed, 1 total
 ```

src/console_results.sh

@@ -160,24 +160,6 @@ function bashunit::console_results::format_duration() {
   fi
 }
 
-function bashunit::console_results::print_hook_running() {
-  local hook_name="$1"
-
-  if bashunit::env::is_simple_output_enabled; then
-    return
-  fi
-
-  if bashunit::env::is_failures_only_enabled; then
-    return
-  fi
-
-  if bashunit::parallel::is_enabled; then
-    return
-  fi
-
-  printf "  ${_BASHUNIT_COLOR_FAINT}Running %s...${_BASHUNIT_COLOR_DEFAULT}" "$hook_name"
-}
-
 function bashunit::console_results::print_hook_completed() {
   local hook_name="$1"
   local duration_ms="$2"
@@ -194,12 +176,14 @@ function bashunit::console_results::print_hook_completed() {
     return
   fi
 
+  local line
+  line=$(printf "%s● %s%s" \
+    "$_BASHUNIT_COLOR_PASSED" "$hook_name" "$_BASHUNIT_COLOR_DEFAULT")
+
   local time_display
   time_display=$(bashunit::console_results::format_duration "$duration_ms")
 
-  printf " %sdone%s %s(%s)%s\n" \
-    "$_BASHUNIT_COLOR_PASSED" "$_BASHUNIT_COLOR_DEFAULT" \
-    "$_BASHUNIT_COLOR_FAINT" "$time_display" "$_BASHUNIT_COLOR_DEFAULT"
+  printf "%s\n" "$(bashunit::str::rpad "$line" "$time_display")"
 }
 
 function bashunit::console_results::print_successful_test() {

src/runner.sh

@@ -893,9 +893,6 @@ function bashunit::runner::run_set_up_before_script() {
     return 0
   fi
 
-  # Print "Running..." message
-  bashunit::console_results::print_hook_running "set_up_before_script"
-
   local start_time
   start_time=$(bashunit::clock::now)
 
@@ -1014,9 +1011,6 @@ function bashunit::runner::run_tear_down_after_script() {
     return 0
   fi
 
-  # Print "Running..." message
-  bashunit::console_results::print_hook_running "tear_down_after_script"
-
   local start_time
   start_time=$(bashunit::clock::now)
 

tests/acceptance/bashunit_lifecycle_output_test.sh

@@ -124,9 +124,8 @@ EOF
   # Explicitly disable simple/parallel modes to ensure normal output
   output=$(BASHUNIT_SIMPLE_OUTPUT=false BASHUNIT_PARALLEL_RUN=false ./bashunit "$test_file" 2>&1)
 
-  assert_contains "Running set_up_before_script..." "$output"
-  assert_contains "done" "$output"
-  assert_contains "Running tear_down_after_script..." "$output"
+  assert_contains "● set_up_before_script" "$output"
+  assert_contains "● tear_down_after_script" "$output"
 }
 
 function test_hook_visibility_suppressed_in_failures_only_mode() {
@@ -150,8 +149,8 @@ EOF
   local output
   output=$(./bashunit --failures-only "$test_file" 2>&1)
 
-  assert_not_contains "Running set_up_before_script" "$output"
-  assert_not_contains "Running tear_down_after_script" "$output"
+  assert_not_contains "● set_up_before_script" "$output"
+  assert_not_contains "● tear_down_after_script" "$output"
 }
 
 function test_hook_visibility_suppressed_in_simple_mode() {
@@ -193,6 +192,6 @@ EOF
   local output
   output=$(BASHUNIT_SIMPLE_OUTPUT=false BASHUNIT_PARALLEL_RUN=false ./bashunit "$test_file" 2>&1)
 
-  assert_not_contains "Running set_up_before_script" "$output"
-  assert_not_contains "Running tear_down_after_script" "$output"
+  assert_not_contains "● set_up_before_script" "$output"
+  assert_not_contains "● tear_down_after_script" "$output"
 }

tests/unit/console_results_test.sh

@@ -659,3 +659,63 @@ function test_print_successful_test_output_in_minutes_exact() {
 
   export BASHUNIT_SIMPLE_OUTPUT=$original_simple_output
 }
+
+function test_print_hook_completed_output_milliseconds() {
+  local original_simple_output=$BASHUNIT_SIMPLE_OUTPUT
+  local original_parallel_run=$BASHUNIT_PARALLEL_RUN
+  export BASHUNIT_SIMPLE_OUTPUT=false
+  export BASHUNIT_PARALLEL_RUN=false
+  export TERMINAL_WIDTH=80
+
+  local output
+  output=$(bashunit::console_results::print_hook_completed "set_up_before_script" "12")
+
+  assert_matches "● set_up_before_script.*12ms" "$output"
+
+  export BASHUNIT_SIMPLE_OUTPUT=$original_simple_output
+  export BASHUNIT_PARALLEL_RUN=$original_parallel_run
+}
+
+function test_print_hook_completed_output_seconds() {
+  local original_simple_output=$BASHUNIT_SIMPLE_OUTPUT
+  local original_parallel_run=$BASHUNIT_PARALLEL_RUN
+  export BASHUNIT_SIMPLE_OUTPUT=false
+  export BASHUNIT_PARALLEL_RUN=false
+  export TERMINAL_WIDTH=80
+
+  local output
+  output=$(bashunit::console_results::print_hook_completed "set_up_before_script" "2340")
+
+  assert_matches "● set_up_before_script.*2.34s" "$output"
+
+  export BASHUNIT_SIMPLE_OUTPUT=$original_simple_output
+  export BASHUNIT_PARALLEL_RUN=$original_parallel_run
+}
+
+function test_print_hook_completed_output_minutes() {
+  local original_simple_output=$BASHUNIT_SIMPLE_OUTPUT
+  local original_parallel_run=$BASHUNIT_PARALLEL_RUN
+  export BASHUNIT_SIMPLE_OUTPUT=false
+  export BASHUNIT_PARALLEL_RUN=false
+  export TERMINAL_WIDTH=80
+
+  local output
+  output=$(bashunit::console_results::print_hook_completed "tear_down_after_script" "125000")
+
+  assert_matches "● tear_down_after_script.*2m 5s" "$output"
+
+  export BASHUNIT_SIMPLE_OUTPUT=$original_simple_output
+  export BASHUNIT_PARALLEL_RUN=$original_parallel_run
+}
+
+function test_print_hook_completed_suppressed_in_simple_mode() {
+  local original_simple_output=$BASHUNIT_SIMPLE_OUTPUT
+  export BASHUNIT_SIMPLE_OUTPUT=true
+
+  local output
+  output=$(bashunit::console_results::print_hook_completed "set_up_before_script" "12")
+
+  assert_empty "$output"
+
+  export BASHUNIT_SIMPLE_OUTPUT=$original_simple_output
+}