From 03162bd82d365c7b6082975526c6b71df7db5aba Mon Sep 17 00:00:00 2001
From: Mike Bland <mbland@acm.org>
Date: Thu, 12 Jan 2017 22:24:46 -0500
Subject: [PATCH 1/9] lib/testing: Move log helpers to lib/testing/log

---
 lib/testing/log                | 147 +++++++++++++++++++++++++++++++++
 tests/log/add-output-file.bats |   2 +-
 tests/log/add-update.bats      |   2 +-
 tests/log/filters.bats         |   2 +-
 tests/log/helpers.bash         | 132 -----------------------------
 tests/log/log-command.bats     |   2 +-
 tests/log/main.bats            |   2 +-
 tests/log/setup-project.bats   |   2 +-
 tests/log/timestamp.bats       |   1 +
 9 files changed, 154 insertions(+), 138 deletions(-)
 delete mode 100644 tests/log/helpers.bash

diff --git a/lib/testing/log b/lib/testing/log
index b3bb6c8..bd46f56 100644
--- a/lib/testing/log
+++ b/lib/testing/log
@@ -6,6 +6,113 @@
 
 . "${BASH_SOURCE[0]%/*}/stack-trace"
 
+create_log_script(){
+  create_test_go_script \
+    ". \"\$_GO_USE_MODULES\" 'log'" \
+    'if [[ -n "$TEST_LOG_FILE" ]]; then' \
+    '  @go.log_add_output_file "$TEST_LOG_FILE"' \
+    'fi' \
+    "$@"
+}
+
+run_log_script() {
+  create_log_script "$@"
+  run "$TEST_GO_SCRIPT"
+}
+
+# For tests that run command scripts via @go, set _GO_CMD to make sure that's
+# the variable included in the log.
+test-go() {
+  env _GO_CMD="$FUNCNAME" "$TEST_GO_SCRIPT" "$@"
+}
+
+assert_log_equals() {
+  set "$BATS_ASSERTION_DISABLE_SHELL_OPTIONS"
+  local level
+  local __padding=''
+  local __log_level_label
+  local expected=()
+  local i
+  local result=0
+
+  . "$_GO_USE_MODULES" 'log'
+
+  for level in "${_GO_LOG_LEVELS[@]}"; do
+    while [[ "${#__padding}" -lt "${#level}" ]]; do
+      __padding+=' '
+    done
+  done
+
+  for ((i=0; $# != 0; ++i)); do
+    if __parse_log_level_label "$1"; then
+      expected+=("$(__expected_log_line "$__log_level_label" "$2")")
+      if ! shift 2; then
+        echo "ERROR: Wrong number of arguments for log line $i." >&2
+        return_from_bats_assertion 1
+        return
+      fi
+    else
+      expected+=("$1")
+      shift
+    fi
+  done
+
+  if ! assert_lines_equal "${expected[@]}"; then
+    return_from_bats_assertion '1'
+  else
+    return_from_bats_assertion
+  fi
+}
+
+assert_log_file_equals() {
+  set "$BATS_ASSERTION_DISABLE_SHELL_OPTIONS"
+  local log_file="$1"
+  shift
+
+  if ! set_bats_output_and_lines_from_file "$log_file"; then
+    return_from_bats_assertion '1'
+  else
+    assert_log_equals "$@"
+    return_from_bats_assertion "$?"
+  fi
+}
+
+# Note that this must be called before any other log assertion, because it needs
+# to set _GO_LOG_FORMATTING before importing the `log` module.
+format_label() {
+  local label="$1"
+
+  if [[ -n "$__GO_LOG_INIT" ]]; then
+    echo "$FUNCNAME must be called before any other function or assertion" \
+      "that calls \`. \$_GO_USE_MODULES 'log'\` because it needs to set" \
+      "\`_GO_LOG_FORMATTING\`." >&2
+      return 1
+  fi
+
+  _GO_LOG_FORMATTING='true'
+  . "$_GO_USE_MODULES" 'log'
+  _@go.log_init
+
+  local __go_log_level_index=0
+  if ! _@go.log_level_index "$label"; then
+    echo "Unknown log level label: $label" >&2
+    return 1
+  fi
+  echo "${__GO_LOG_LEVELS_FORMATTED[$__go_log_level_index]}"
+}
+
+# Creates `LOG_COMMAND_STACK_TRACE_ITEMS` to help validate stack trace output.
+#
+# Call this before using "${LOG_COMMAND_STACK_TRACE_ITEMS[@]}" to inject
+# entries from `@go.log_command` into your expected stack trace output. This
+# helps validate stack trace output generated by logged commands, and ensures
+# that your stack trace validation stays up-to-date even when the internal
+# structure of `lib/log` changes.
+#
+# Globals:
+#   LOG_COMMAND_STACK_TRACE_ITEMS:
+#     Stack trace lines from `@go.log_command` comprising the command logging
+#     mechanism
 set_log_command_stack_trace_items() {
   if [[ "${#LOG_COMMAND_STACK_TRACE_ITEMS[@]}" -eq '0' ]]; then
     export LOG_COMMAND_STACK_TRACE_ITEMS
@@ -18,3 +125,43 @@ set_log_command_stack_trace_items() {
       "$(stack_trace_item "$_GO_CORE_DIR/lib/log" '@go.log_command')")
   fi
 }
+
+# --------------------------------
+# IMPLEMENTATION - HERE BE DRAGONS
+#
+# None of the functions below this line are part of the public interface.
+# --------------------------------
+
+__parse_log_level_label() {
+  local level="$1"
+  local try_level="$level"
+  if [[ "${level:0:3}" == '\e[' ]]; then
+    try_level="${try_level//\\e\[[0-9]m}"
+    try_level="${try_level//\\e\[[0-9][0-9]m}"
+    try_level="${try_level//\\e\[[0-9][0-9][0-9]m}"
+    try_level="${try_level%% *}"
+  fi
+
+  if ! _@go.log_level_index "$try_level"; then
+    return 1
+  fi
+  __log_level_label="$level"
+
+  # If it's a label formatted with `format_label`, it's already padded.
+  if [[ "${level:0:3}" != '\e[' ]]; then
+    __log_level_label+="${__padding:0:$((${#__padding} - ${#try_level}))}"
+  fi
+}
+
+__expected_log_line() {
+  local level="$1"
+  local message="$2"
+
+  if [[ "${level:0:3}" == '\e[' ]]; then
+    printf '%b\n' "$level $message\e[0m"
+  else
+    printf '%b\n' "$level $message"
+  fi
+}
+
+
diff --git a/tests/log/add-output-file.bats b/tests/log/add-output-file.bats
index f0155ab..394cc28 100644
--- a/tests/log/add-output-file.bats
+++ b/tests/log/add-output-file.bats
@@ -1,7 +1,7 @@
 #! /usr/bin/env bats
 
 load ../environment
-load helpers
+load "$_GO_CORE_DIR/lib/testing/log"
 
 teardown() {
   remove_test_go_rootdir
diff --git a/tests/log/add-update.bats b/tests/log/add-update.bats
index e3268dc..92109c2 100644
--- a/tests/log/add-update.bats
+++ b/tests/log/add-update.bats
@@ -1,7 +1,7 @@
 #! /usr/bin/env bats
 
 load ../environment
-load helpers
+load "$_GO_CORE_DIR/lib/testing/log"
 
 INFO_FORMAT='\e[1m\e[36m'
 START_FORMAT='\e[1m\e[32m'
diff --git a/tests/log/filters.bats b/tests/log/filters.bats
index e833c0a..6d4248a 100644
--- a/tests/log/filters.bats
+++ b/tests/log/filters.bats
@@ -1,7 +1,7 @@
 #! /usr/bin/env bats
 
 load ../environment
-load helpers
+load "$_GO_CORE_DIR/lib/testing/log"
 
 teardown() {
   remove_test_go_rootdir
diff --git a/tests/log/helpers.bash b/tests/log/helpers.bash
deleted file mode 100644
index a9a447a..0000000
--- a/tests/log/helpers.bash
+++ /dev/null
@@ -1,132 +0,0 @@
-#! /bin/bash
-#
-# Helper functions for `lib/log` tests.
-
-load "$_GO_CORE_DIR/lib/testing/log"
-
-create_log_script(){
-  create_test_go_script \
-    ". \"\$_GO_USE_MODULES\" 'log'" \
-    'if [[ -n "$TEST_LOG_FILE" ]]; then' \
-    '  @go.log_add_output_file "$TEST_LOG_FILE"' \
-    'fi' \
-    "$@"
-}
-
-run_log_script() {
-  create_log_script "$@"
-  run "$TEST_GO_SCRIPT"
-}
-
-# For tests that run command scripts via @go, set _GO_CMD to make sure that's
-# the variable included in the log.
-test-go() {
-  env _GO_CMD="$FUNCNAME" "$TEST_GO_SCRIPT" "$@"
-}
-
-# Note that this must be called before any other log assertion, because it needs
-# to set _GO_LOG_FORMATTING before importing the `log` module.
-format_label() {
-  local label="$1"
-
-  if [[ -n "$__GO_LOG_INIT" ]]; then
-    echo "$FUNCNAME must be called before any other function or assertion" \
-      "that calls \`. \$_GO_USE_MODULES 'log'\` because it needs to set" \
-      "\`_GO_LOG_FORMATTING\`." >&2
-      return 1
-  fi
-
-  _GO_LOG_FORMATTING='true'
-  . "$_GO_USE_MODULES" 'log'
-  _@go.log_init
-
-  local __go_log_level_index=0
-  if ! _@go.log_level_index "$label"; then
-    echo "Unknown log level label: $label" >&2
-    return 1
-  fi
-  echo "${__GO_LOG_LEVELS_FORMATTED[$__go_log_level_index]}"
-}
-
-__parse_log_level_label() {
-  local level="$1"
-  local try_level="$level"
-  if [[ "${level:0:3}" == '\e[' ]]; then
-    try_level="${try_level//\\e\[[0-9]m}"
-    try_level="${try_level//\\e\[[0-9][0-9]m}"
-    try_level="${try_level//\\e\[[0-9][0-9][0-9]m}"
-    try_level="${try_level%% *}"
-  fi
-
-  if ! _@go.log_level_index "$try_level"; then
-    return 1
-  fi
-  __log_level_label="$level"
-
-  # If it's a label formatted with `format_label`, it's already padded.
-  if [[ "${level:0:3}" != '\e[' ]]; then
-    __log_level_label+="${__padding:0:$((${#__padding} - ${#try_level}))}"
-  fi
-}
-
-__expected_log_line() {
-  local level="$1"
-  local message="$2"
-
-  if [[ "${level:0:3}" == '\e[' ]]; then
-    printf '%b\n' "$level $message\e[0m"
-  else
-    printf '%b\n' "$level $message"
-  fi
-}
-
-assert_log_equals() {
-  set "$BATS_ASSERTION_DISABLE_SHELL_OPTIONS"
-  local level
-  local __padding=''
-  local __log_level_label
-  local expected=()
-  local i
-  local result=0
-
-  . "$_GO_USE_MODULES" 'log'
-
-  for level in "${_GO_LOG_LEVELS[@]}"; do
-    while [[ "${#__padding}" -lt "${#level}" ]]; do
-      __padding+=' '
-    done
-  done
-
-  for ((i=0; $# != 0; ++i)); do
-    if __parse_log_level_label "$1"; then
-      expected+=("$(__expected_log_line "$__log_level_label" "$2")")
-      if ! shift 2; then
-        echo "ERROR: Wrong number of arguments for log line $i." >&2
-        return_from_bats_assertion 1
-        return
-      fi
-    else
-      expected+=("$1")
-      shift
-    fi
-  done
-
-  if ! assert_lines_equal "${expected[@]}"; then
-    return_from_bats_assertion '1'
-  else
-    return_from_bats_assertion
-  fi
-}
-
-assert_log_file_equals() {
-  set "$BATS_ASSERTION_DISABLE_SHELL_OPTIONS"
-  local log_file="$1"
-  shift
-
-  if ! set_bats_output_and_lines_from_file "$log_file"; then
-    return_from_bats_assertion '1'
-  else
-    assert_log_equals "$@"
-    return_from_bats_assertion "$?"
-  fi
-}
diff --git a/tests/log/log-command.bats b/tests/log/log-command.bats
index 4824877..06bda12 100644
--- a/tests/log/log-command.bats
+++ b/tests/log/log-command.bats
@@ -1,7 +1,7 @@
 #! /usr/bin/env bats
 
 load ../environment
-load helpers
+load "$_GO_CORE_DIR/lib/testing/log"
 
 setup() {
   test_filter
diff --git a/tests/log/main.bats b/tests/log/main.bats
index 76ed3ed..e457d74 100644
--- a/tests/log/main.bats
+++ b/tests/log/main.bats
@@ -1,7 +1,7 @@
 #! /usr/bin/env bats
 
 load ../environment
-load helpers
+load "$_GO_CORE_DIR/lib/testing/log"
 
 setup() {
   test_filter
diff --git a/tests/log/setup-project.bats b/tests/log/setup-project.bats
index 6608f91..0bac75a 100644
--- a/tests/log/setup-project.bats
+++ b/tests/log/setup-project.bats
@@ -1,7 +1,7 @@
 #! /usr/bin/env bats
 
 load ../environment
-load helpers
+load "$_GO_CORE_DIR/lib/testing/log"
 
 teardown() {
   remove_test_go_rootdir
diff --git a/tests/log/timestamp.bats b/tests/log/timestamp.bats
index fba1eda..951ca0d 100644
--- a/tests/log/timestamp.bats
+++ b/tests/log/timestamp.bats
@@ -1,6 +1,7 @@
 #! /usr/bin/env bats
 
 load ../environment
+load "$_GO_CORE_DIR/lib/testing/log"
 
 HAS_TIMESTAMP_BUILTIN=
 DATE_CMD=

From 5c04be5ad4d72874ae542462c9f07d47ef89dbfd Mon Sep 17 00:00:00 2001
From: Mike Bland <mbland@acm.org>
Date: Fri, 13 Jan 2017 09:58:10 -0500
Subject: [PATCH 2/9] lib/testing: Test create/run_log_script, test-go

Also moves `test-go` from `lib/testing/log` to
`lib/testing/environment`, as it may prove generally useful.
---
 lib/testing/environment        | 13 +++++++++++++
 lib/testing/log                | 19 +++++++++++++------
 tests/testing/environment.bats |  6 ++++++
 tests/testing/log.bats         | 17 +++++++++++++++++
 4 files changed, 49 insertions(+), 6 deletions(-)

diff --git a/lib/testing/environment b/lib/testing/environment
index e52a949..315f406 100644
--- a/lib/testing/environment
+++ b/lib/testing/environment
@@ -62,6 +62,19 @@ create_test_go_script() {
   fi
 }
 
+# Sets `_GO_CMD` to make for neater test output when running `TEST_GO_SCRIPT`
+#
+# Use `run test-go` instead of `run "$TEST_GO_SCRIPT"` to achieve the effect.
+#
+# Useful for tests that contain `_GO_CMD` in the output, to avoid clouding the
+# output with the full `TEST_GO_SCRIPT` path.
+#
+# Arguments:
+#    ...:  Command line arguments for `TEST_GO_SCRIPT`
+test-go() {
+  _GO_CMD="$FUNCNAME" "$TEST_GO_SCRIPT" "$@"
+}
+
 # Creates an executable `./go` command script in `TEST_GO_SCRIPTS_DIR`
 #
 # The script will be created as `$TEST_GO_SCRIPTS_DIR/$script_name`.
diff --git a/lib/testing/log b/lib/testing/log
index bd46f56..b08068a 100644
--- a/lib/testing/log
+++ b/lib/testing/log
@@ -6,6 +6,16 @@
 
 . "${BASH_SOURCE[0]%/*}/stack-trace"
 
+# Creates a `./go` script that imports the `log` module
+#
+# If `TEST_LOG_FILE` is defined, it will add that file for logging output as
+# well.
+#
+# Globals:
+#   TEST_LOG_FILE:  (Optional) Path to the log file to add for all log levels
+#
+# Arguments:
+#   ...:  Lines comprising the `./go` script
 create_log_script(){
   create_test_go_script \
     ". \"\$_GO_USE_MODULES\" 'log'" \
@@ -15,17 +25,14 @@ create_log_script(){
     "$@"
 }
 
+# Creates and executes a `./go` script that imports the `log` module
+#
+# Globals and arguments are identical to `create_log_script`.
 run_log_script() {
   create_log_script "$@"
   run "$TEST_GO_SCRIPT"
 }
 
-# For tests that run command scripts via @go, set _GO_CMD to make sure that's
-# the variable included in the log.
-test-go() {
-  env _GO_CMD="$FUNCNAME" "$TEST_GO_SCRIPT" "$@"
-}
-
 assert_log_equals() {
   set "$BATS_ASSERTION_DISABLE_SHELL_OPTIONS"
   local level
diff --git a/tests/testing/environment.bats b/tests/testing/environment.bats
index ab5ef9c..60ddc47 100644
--- a/tests/testing/environment.bats
+++ b/tests/testing/environment.bats
@@ -87,3 +87,9 @@ teardown() {
   [ -x "$TEST_GO_SCRIPTS_DIR/foo.d/bar.d/xyzzy" ]
   [ -x "$TEST_GO_SCRIPTS_DIR/foo.d/bar.d/plugh" ]
 }
+
+@test "$SUITE: run TEST_GO_SCRIPT via test-go" {
+  create_test_go_script 'printf "_GO_CMD: %s\n" "$_GO_CMD"'
+  run test-go
+  assert_success '_GO_CMD: test-go'
+}
diff --git a/tests/testing/log.bats b/tests/testing/log.bats
index 6c7634e..f2d0326 100644
--- a/tests/testing/log.bats
+++ b/tests/testing/log.bats
@@ -11,6 +11,23 @@ teardown() {
   remove_test_go_rootdir
 }
 
+@test "$SUITE: create_log_script and run_log_script without log file" {
+  export TEST_LOG_FILE="$TEST_GO_ROOTDIR/test-script.log"
+  TEST_LOG_FILE= run_log_script '@go.log INFO Hello, World!'
+  assert_success
+  assert_output_matches '^INFO +Hello, World!$'
+  [ ! -e "$TEST_LOG_FILE" ]
+}
+
+@test "$SUITE: create_log_script and run_log_script with log file" {
+  export TEST_LOG_FILE="$TEST_GO_ROOTDIR/test-script.log"
+  run_log_script '@go.log INFO Hello, World!'
+  assert_success
+  assert_output_matches '^INFO +Hello, World!$'
+  [ -e "$TEST_LOG_FILE" ]
+  assert_file_matches "$TEST_LOG_FILE" '^INFO +Hello, World!$'
+}
+
 @test "$SUITE: set_log_command_stack_trace_items" {
   assert_equal '' "${LOG_COMMAND_STACK_TRACE_ITEMS[*]}"
   set_log_command_stack_trace_items

From e43e9e02a00f4094900d908c299acc7323d7197c Mon Sep 17 00:00:00 2001
From: Mike Bland <mbland@acm.org>
Date: Fri, 13 Jan 2017 11:35:16 -0500
Subject: [PATCH 3/9] lib/testing: Rename and test `format_log_label`

---
 lib/testing/log                | 56 ++++++++++++++++++----------------
 tests/log/add-output-file.bats |  2 +-
 tests/log/log-command.bats     |  4 +--
 tests/log/main.bats            |  2 +-
 tests/testing/log.bats         | 22 +++++++++++++
 5 files changed, 56 insertions(+), 30 deletions(-)

diff --git a/lib/testing/log b/lib/testing/log
index b08068a..527b23c 100644
--- a/lib/testing/log
+++ b/lib/testing/log
@@ -33,6 +33,36 @@ run_log_script() {
   run "$TEST_GO_SCRIPT"
 }
 
+# Format a `log` module log level label
+#
+# Note that this must be called before any other log assertion, because it needs
+# to set _GO_LOG_FORMATTING before importing the `log` module.
+#
+# Arguments:
+#   label:  Log level label to format
+format_log_label() {
+  local label="$1"
+
+  if [[ -n "$__GO_LOG_INIT" ]]; then
+    local err_format=("\`%s\` must be called before any other function"
+      "or assertion that calls \`. \"\$_GO_USE_MODULES\" 'log'\`"
+      'because it needs to set `_GO_LOG_FORMATTING`.')
+    printf "${err_format[*]}" "$FUNCNAME" >&2
+    exit 1
+  fi
+
+  _GO_LOG_FORMATTING='true'
+  . "$_GO_USE_MODULES" 'log'
+  _@go.log_init
+
+  local __go_log_level_index=0
+  if ! _@go.log_level_index "$label"; then
+    printf 'Unknown log level label: %s\n' "$label" >&2
+    exit 1
+  fi
+  printf '%s' "${__GO_LOG_LEVELS_FORMATTED[$__go_log_level_index]}"
+}
+
 assert_log_equals() {
   set "$BATS_ASSERTION_DISABLE_SHELL_OPTIONS"
   local level
@@ -84,30 +114,6 @@ assert_log_file_equals() {
   fi
 }
 
-# Note that this must be called before any other log assertion, because it needs
-# to set _GO_LOG_FORMATTING before importing the `log` module.
-format_label() {
-  local label="$1"
-
-  if [[ -n "$__GO_LOG_INIT" ]]; then
-    echo "$FUNCNAME must be called before any other function or assertion" \
-      "that calls \`. \$_GO_USE_MODULES 'log'\` because it needs to set" \
-      "\`_GO_LOG_FORMATTING\`." >&2
-      return 1
-  fi
-
-  _GO_LOG_FORMATTING='true'
-  . "$_GO_USE_MODULES" 'log'
-  _@go.log_init
-
-  local __go_log_level_index=0
-  if ! _@go.log_level_index "$label"; then
-    echo "Unknown log level label: $label" >&2
-    return 1
-  fi
-  echo "${__GO_LOG_LEVELS_FORMATTED[$__go_log_level_index]}"
-}
-
 # Creates `LOG_COMMAND_STACK_TRACE_ITEMS` to help validate stack trace output.
 #
 # Call this before using "${LOG_COMMAND_STACK_TRACE_ITEMS[@]}" to inject
@@ -170,5 +176,3 @@ __expected_log_line() {
     printf '%b\n' "$level $message"
   fi
 }
-
-
diff --git a/tests/log/add-output-file.bats b/tests/log/add-output-file.bats
index 394cc28..4d57104 100644
--- a/tests/log/add-output-file.bats
+++ b/tests/log/add-output-file.bats
@@ -66,7 +66,7 @@ run_log_script_and_assert_status_and_output() {
     "@go.log_add_output_file '$TEST_GO_ROOTDIR/info.log' 'INFO'" \
     "@go.log INFO Hello, World!"
   assert_success
-  assert_log_equals "$(format_label INFO)" 'Hello, World!'
+  assert_log_equals "$(format_log_label INFO)" 'Hello, World!'
   assert_file_equals "$TEST_GO_ROOTDIR/info.log" "${lines[@]}"
 }
 
diff --git a/tests/log/log-command.bats b/tests/log/log-command.bats
index 06bda12..4253cba 100644
--- a/tests/log/log-command.bats
+++ b/tests/log/log-command.bats
@@ -115,8 +115,8 @@ teardown() {
 }
 
 @test "$SUITE: log failing command to standard error with formatting" {
-  local formatted_run_level_label="$(format_label RUN)"
-  local formatted_error_level_label="$(format_label ERROR)"
+  local formatted_run_level_label="$(format_log_label RUN)"
+  local formatted_error_level_label="$(format_log_label ERROR)"
 
   _GO_LOG_FORMATTING='true' run_log_script \
       'function failing_function() {' \
diff --git a/tests/log/main.bats b/tests/log/main.bats
index e457d74..cd0a21b 100644
--- a/tests/log/main.bats
+++ b/tests/log/main.bats
@@ -23,7 +23,7 @@ teardown() {
     'echo Goodbye, World!'
   assert_success
   assert_log_equals \
-    "$(format_label INFO)" '\e[1m\e[36mHello, World!' \
+    "$(format_log_label INFO)" '\e[1m\e[36mHello, World!' \
     'Goodbye, World!'
 }
 
diff --git a/tests/testing/log.bats b/tests/testing/log.bats
index f2d0326..8eeae1b 100644
--- a/tests/testing/log.bats
+++ b/tests/testing/log.bats
@@ -36,3 +36,25 @@ teardown() {
     "^  $_GO_CORE_DIR/lib/log:[0-9]+ _@go.log_command_invoke$" \
     "^  $_GO_CORE_DIR/lib/log:[0-9]+ @go.log_command$"
 }
+
+@test "$SUITE: format_log_label" {
+  run format_log_label INFO
+  assert_success
+
+  local expected_message
+  printf -v expected_message '%b' "$output Hello, World!\e[0m"
+
+  _GO_LOG_FORMATTING='true' run_log_script '@go.log INFO Hello, World!'
+  assert_success "$expected_message"
+}
+
+@test "$SUITE: format_log_label exits if log module already initialized" {
+  __GO_LOG_INIT='true' run format_log_label INFO
+  assert_failure
+  assert_output_matches '^`format_log_label` must be called before any other '
+}
+
+@test "$SUITE: format_log_label exits if log level label invalid" {
+  run format_log_label FOOBAR
+  assert_failure 'Unknown log level label: FOOBAR'
+}

From 8e4b6fd5518f0f52a37b1bb179a4fbce1b1f9816 Mon Sep 17 00:00:00 2001
From: Mike Bland <mbland@acm.org>
Date: Sat, 14 Jan 2017 20:25:46 -0500
Subject: [PATCH 4/9] lib/log: Refactor _@go.log_format_level_labels

The updates to `lib/format` from #107 make this function much shorter.
Also, the logic to check the file descriptors was sort of confused and
not really doing anything, at least not anything helpful, since the
decision to print or strip formatting codes is now made per log level
file descriptor in `@go.log`.
---
 lib/log | 47 ++++-------------------------------------------
 1 file changed, 4 insertions(+), 43 deletions(-)

diff --git a/lib/log b/lib/log
index 191f861..4f0b9d9 100644
--- a/lib/log
+++ b/lib/log
@@ -651,57 +651,18 @@ _@go.log_init() {
 
 # Assigns formatted log level labels to __GO_LOG_LEVELS_FORMATTED.
 #
-# If `_GO_LOG_FORMATTING` is not empty, or the file descriptor corresponding to
-# a log level corresponds to a terminal, this will assign a corresponding value
-# wrapped by terminal formatting codes to __GO_LOG_LEVELS_FORMATTED. Otherwise
-# the original label value is assigned.
-#
 # Each element of `__GO_LOG_LEVELS_FORMATTED` will also be padded with trailing
 # spaces so that each element will be the same length.
 #
 # Globals:
 #   _GO_LOG_LEVELS:                    List of valid log level labels
-#   _GO_LOG_FORMATTING                 If set, always produce formatted labels
 #   __GO_LOG_LEVELS_FORMAT_CODES:      Terminal format codes for each log level
-#   __GO_LOG_LEVELS_FILE_DESCRIPTORS:  Output descriptors for each log level
 #   __GO_LOG_LEVELS_FORMATTED:         Formatted labels
 _@go.log_format_level_labels() {
-  local num_levels="${#_GO_LOG_LEVELS[@]}"
-  local label_length
-  local longest_label_length
-  local padding=''
-  local log_level
-  local padding_len
-  local level_var
-  local level_fd
-  local i
-
-  for ((i=0; i != num_levels; ++i)); do
-    label_length="${#_GO_LOG_LEVELS[$i]}"
-    if [[ "$label_length" -gt "$longest_label_length" ]]; then
-      longest_label_length="$label_length"
-    fi
-  done
-
-  for ((i=0; i != longest_label_length; ++i)); do
-    padding+=' '
-  done
-
-  for ((i=0; i != num_levels; ++i)); do
-    log_level="${_GO_LOG_LEVELS[$i]}"
-    padding_len="$((${#padding} - ${#log_level}))"
-
-    local __go_log_level_file_descriptors=()
-    _@go.log_level_file_descriptors "$i"
-
-    for level_fd in "${__go_log_level_file_descriptors[@]}"; do
-      if [[ -n "$_GO_LOG_FORMATTING" || -t "$level_fd" ]]; then
-        log_level="${__GO_LOG_LEVELS_FORMAT_CODES[$i]}$log_level\e[0m"
-        break
-      fi
-    done
-    __GO_LOG_LEVELS_FORMATTED[$i]="${log_level}${padding:0:$padding_len}"
-  done
+  __GO_LOG_LEVELS_FORMATTED=("${_GO_LOG_LEVELS[@]/%/\\e[0m}")
+  @go.pad_items __GO_LOG_LEVELS_FORMATTED "${__GO_LOG_LEVELS_FORMATTED[@]}"
+  @go.zip_items __GO_LOG_LEVELS_FORMAT_CODES __GO_LOG_LEVELS_FORMATTED '' \
+    __GO_LOG_LEVELS_FORMATTED
 }
 
 # Returns the set of file descriptors for the specified log level index.

From e681b862bbbcd15fcf4bce663f798b23d49c79cb Mon Sep 17 00:00:00 2001
From: Mike Bland <mbland@acm.org>
Date: Sat, 14 Jan 2017 20:35:21 -0500
Subject: [PATCH 5/9] lib/log: Use printf -v to create formatted message

Seems a little easier to understand the message format this way, and
using `%b` in the `printf -v` statement seems less subtle than using it
in the `printf` that actually generates the output.
---
 lib/log | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/lib/log b/lib/log
index 4f0b9d9..48d5bbd 100644
--- a/lib/log
+++ b/lib/log
@@ -251,10 +251,10 @@ readonly __GO_LOG_COMMAND_EXIT_PATTERN='^@go.log_command (exit|fatal):([0-9]+)$'
 
   local __go_log_timestamp
   if @go.log_timestamp; then
-    log_msg="$__go_log_timestamp "
+    __go_log_timestamp+=' '
   fi
-  log_msg+="${__GO_LOG_LEVELS_FORMATTED[$__go_log_level_index]} "
-  log_msg+="${args[*]}\\e[0m"
+  printf -v log_msg -- '%s%b %b' "$__go_log_timestamp" \
+    "${__GO_LOG_LEVELS_FORMATTED[$__go_log_level_index]}" "${args[*]}\\e[0m"
 
   local __go_log_level_file_descriptors=('1')
   if [[ "$__GO_LOG_COMMAND_DEPTH" == '0' || "$log_level" != 'RUN' ]]; then
@@ -271,7 +271,7 @@ readonly __GO_LOG_COMMAND_EXIT_PATTERN='^@go.log_command (exit|fatal):([0-9]+)$'
       fi
       printf '%s\n' "$stripped_log_msg" >&"$level_fd"
     else
-      printf '%b\n' "$log_msg" >&"$level_fd"
+      printf '%s\n' "$log_msg" >&"$level_fd"
     fi
 
     if [[ "$log_level" == 'FATAL' ]]; then

From 6f16183fd669e26ba6ddf4d9dfbe1717068a6df9 Mon Sep 17 00:00:00 2001
From: Mike Bland <mbland@acm.org>
Date: Sat, 14 Jan 2017 20:49:46 -0500
Subject: [PATCH 6/9] lib/log: Improve `@go.log_command` line formatting

It occurred to me that `@go.log_command` should not try to only convert
unexpanded formatting code sequences if they exist in the output, but
should strip them out entirely whether they're expanded or not.
---
 lib/log                    | 9 +++++++--
 tests/log/log-command.bats | 6 +++---
 2 files changed, 10 insertions(+), 5 deletions(-)

diff --git a/lib/log b/lib/log
index 48d5bbd..650e6b3 100644
--- a/lib/log
+++ b/lib/log
@@ -460,6 +460,7 @@ readonly __GO_LOG_COMMAND_EXIT_PATTERN='^@go.log_command (exit|fatal):([0-9]+)$'
   local __go_log_command_args=("$@")
   local cmd_string="${__go_log_command_args[*]}"
   local line
+  local stripped_line
   local exit_state
   local exit_status=1
 
@@ -482,6 +483,7 @@ readonly __GO_LOG_COMMAND_EXIT_PATTERN='^@go.log_command (exit|fatal):([0-9]+)$'
 
   while IFS= read -r line; do
     line="${line%$'\r'}"
+    stripped_line=''
 
     if [[ "$line" =~ $__GO_LOG_COMMAND_EXIT_PATTERN ]]; then
       # If the line immediately previous was fatal, keep the fatal state.
@@ -497,9 +499,12 @@ readonly __GO_LOG_COMMAND_EXIT_PATTERN='^@go.log_command (exit|fatal):([0-9]+)$'
 
     for fd in "${__go_log_level_file_descriptors[@]}"; do
       if [[ -t "$fd" || -n "$_GO_LOG_FORMATTING" ]]; then
-        printf '%b\n' "$line" >&"$fd"
-      else
         printf '%s\n' "$line" >&"$fd"
+      else
+        if [[ -z "$stripped_line" ]]; then
+          @go.strip_formatting_codes "$line" stripped_line
+        fi
+        printf '%s\n' "$stripped_line" >&"$fd"
       fi
     done
   done < <(_@go.log_command_invoke)
diff --git a/tests/log/log-command.bats b/tests/log/log-command.bats
index 4253cba..91ee6ca 100644
--- a/tests/log/log-command.bats
+++ b/tests/log/log-command.bats
@@ -101,7 +101,7 @@ teardown() {
 @test "$SUITE: log single failing command to standard error" {
   run_log_script \
       'function failing_function() {' \
-      '  printf "%s\n" "\e[1m$*\e[0m" >&2' \
+      '  printf "%b\n" "\e[1m$*\e[0m" >&2' \
       '  exit 127' \
       '}' \
       '@go.log_command failing_function foo bar baz'
@@ -109,7 +109,7 @@ teardown() {
   assert_failure
   assert_log_equals \
     RUN 'failing_function foo bar baz' \
-    '\e[1mfoo bar baz\e[0m' \
+    'foo bar baz' \
     ERROR 'failing_function foo bar baz (exit status 127)'
   assert_log_file_equals "$TEST_LOG_FILE" "${lines[@]}"
 }
@@ -120,7 +120,7 @@ teardown() {
 
   _GO_LOG_FORMATTING='true' run_log_script \
       'function failing_function() {' \
-      '  printf "%s\n" "\e[1m$*\e[0m" >&2' \
+      '  printf "%b\n" "\e[1m$*\e[0m" >&2' \
       '  exit 127' \
       '}' \
       '@go.log_command failing_function foo bar baz'

From 18a01d74955a55d6f7271f3ebac320a0ef473824 Mon Sep 17 00:00:00 2001
From: Mike Bland <mbland@acm.org>
Date: Sun, 15 Jan 2017 08:43:43 -0500
Subject: [PATCH 7/9] lib/log: Expand format codes on `@go.log_init`

This also precipitated a refactor of `assert_log_equals` and its
implementation functions to handle the expanded code, which actually
simplified the logic a bit.

By the same token, it's no longer required that `format_log_label` be
called before other `lib/log` functions, as `__GO_LOG_LEVELS_FORMATTED`
will always contain expanded format codes and `@go.log` will strip them
out if need be.
---
 lib/log                    |  4 ++-
 lib/testing/log            | 65 +++++++++++---------------------------
 tests/log/log-command.bats |  7 ++--
 tests/log/main.bats        |  2 +-
 tests/testing/log.bats     |  6 ----
 5 files changed, 25 insertions(+), 59 deletions(-)

diff --git a/lib/log b/lib/log
index 650e6b3..793a9a0 100644
--- a/lib/log
+++ b/lib/log
@@ -253,7 +253,7 @@ readonly __GO_LOG_COMMAND_EXIT_PATTERN='^@go.log_command (exit|fatal):([0-9]+)$'
   if @go.log_timestamp; then
     __go_log_timestamp+=' '
   fi
-  printf -v log_msg -- '%s%b %b' "$__go_log_timestamp" \
+  printf -v log_msg -- '%s%s %b' "$__go_log_timestamp" \
     "${__GO_LOG_LEVELS_FORMATTED[$__go_log_level_index]}" "${args[*]}\\e[0m"
 
   local __go_log_level_file_descriptors=('1')
@@ -668,6 +668,8 @@ _@go.log_format_level_labels() {
   @go.pad_items __GO_LOG_LEVELS_FORMATTED "${__GO_LOG_LEVELS_FORMATTED[@]}"
   @go.zip_items __GO_LOG_LEVELS_FORMAT_CODES __GO_LOG_LEVELS_FORMATTED '' \
     __GO_LOG_LEVELS_FORMATTED
+  @go.array_printf __GO_LOG_LEVELS_FORMATTED '%b' \
+    "${__GO_LOG_LEVELS_FORMATTED[@]}"
 }
 
 # Returns the set of file descriptors for the specified log level index.
diff --git a/lib/testing/log b/lib/testing/log
index 527b23c..f471e11 100644
--- a/lib/testing/log
+++ b/lib/testing/log
@@ -35,23 +35,11 @@ run_log_script() {
 
 # Format a `log` module log level label
 #
-# Note that this must be called before any other log assertion, because it needs
-# to set _GO_LOG_FORMATTING before importing the `log` module.
-#
 # Arguments:
 #   label:  Log level label to format
 format_log_label() {
   local label="$1"
 
-  if [[ -n "$__GO_LOG_INIT" ]]; then
-    local err_format=("\`%s\` must be called before any other function"
-      "or assertion that calls \`. \"\$_GO_USE_MODULES\" 'log'\`"
-      'because it needs to set `_GO_LOG_FORMATTING`.')
-    printf "${err_format[*]}" "$FUNCNAME" >&2
-    exit 1
-  fi
-
-  _GO_LOG_FORMATTING='true'
   . "$_GO_USE_MODULES" 'log'
   _@go.log_init
 
@@ -65,24 +53,21 @@ format_log_label() {
 
 assert_log_equals() {
   set "$BATS_ASSERTION_DISABLE_SHELL_OPTIONS"
-  local level
-  local __padding=''
   local __log_level_label
   local expected=()
   local i
-  local result=0
 
-  . "$_GO_USE_MODULES" 'log'
-
-  for level in "${_GO_LOG_LEVELS[@]}"; do
-    while [[ "${#__padding}" -lt "${#level}" ]]; do
-      __padding+=' '
-    done
-  done
+  . "$_GO_USE_MODULES" 'format' 'log'
+  _@go.log_init
 
   for ((i=0; $# != 0; ++i)); do
     if __parse_log_level_label "$1"; then
-      expected+=("$(__expected_log_line "$__log_level_label" "$2")")
+      expected+=("$__log_level_label $2")
+
+      if [[ "${__log_level_label:0:1}" == $'\e' ]]; then
+        expected["$((${#expected[@]} - 1))"]+=$'\e[0m'
+      fi
+
       if ! shift 2; then
         echo "ERROR: Wrong number of arguments for log line $i." >&2
         return_from_bats_assertion 1
@@ -146,33 +131,21 @@ set_log_command_stack_trace_items() {
 # --------------------------------
 
 __parse_log_level_label() {
-  local level="$1"
-  local try_level="$level"
-  if [[ "${level:0:3}" == '\e[' ]]; then
-    try_level="${try_level//\\e\[[0-9]m}"
-    try_level="${try_level//\\e\[[0-9][0-9]m}"
-    try_level="${try_level//\\e\[[0-9][0-9][0-9]m}"
-    try_level="${try_level%% *}"
+  local level_label="$1"
+  local try_level
+  local __go_log_level_index
+
+  @go.strip_formatting_codes "$level_label" 'try_level'
+  if [[ "$try_level" =~ \ +$ ]]; then
+    try_level="${try_level%${BASH_REMATCH[0]}}"
   fi
 
   if ! _@go.log_level_index "$try_level"; then
     return 1
-  fi
-  __log_level_label="$level"
-
-  # If it's a label formatted with `format_label`, it's already padded.
-  if [[ "${level:0:3}" != '\e[' ]]; then
-    __log_level_label+="${__padding:0:$((${#__padding} - ${#try_level}))}"
-  fi
-}
-
-__expected_log_line() {
-  local level="$1"
-  local message="$2"
-
-  if [[ "${level:0:3}" == '\e[' ]]; then
-    printf '%b\n' "$level $message\e[0m"
+  elif [[ "$level_label" != "$try_level" ]]; then
+    __log_level_label="$level_label"
   else
-    printf '%b\n' "$level $message"
+    @go.strip_formatting_codes \
+      "${__GO_LOG_LEVELS_FORMATTED[$__go_log_level_index]}" __log_level_label
   fi
 }
diff --git a/tests/log/log-command.bats b/tests/log/log-command.bats
index 91ee6ca..3b95b4d 100644
--- a/tests/log/log-command.bats
+++ b/tests/log/log-command.bats
@@ -115,9 +115,6 @@ teardown() {
 }
 
 @test "$SUITE: log failing command to standard error with formatting" {
-  local formatted_run_level_label="$(format_log_label RUN)"
-  local formatted_error_level_label="$(format_log_label ERROR)"
-
   _GO_LOG_FORMATTING='true' run_log_script \
       'function failing_function() {' \
       '  printf "%b\n" "\e[1m$*\e[0m" >&2' \
@@ -127,9 +124,9 @@ teardown() {
 
   assert_failure
   assert_log_equals \
-    "$formatted_run_level_label" 'failing_function foo bar baz' \
+    "$(format_log_label RUN)" 'failing_function foo bar baz' \
     "$(printf '%b' '\e[1mfoo bar baz\e[0m')" \
-    "$formatted_error_level_label" \
+    "$(format_log_label ERROR)" \
       'failing_function foo bar baz (exit status 127)'
   assert_log_file_equals "$TEST_LOG_FILE" "${lines[@]}"
 }
diff --git a/tests/log/main.bats b/tests/log/main.bats
index cd0a21b..9fa5dde 100644
--- a/tests/log/main.bats
+++ b/tests/log/main.bats
@@ -23,7 +23,7 @@ teardown() {
     'echo Goodbye, World!'
   assert_success
   assert_log_equals \
-    "$(format_log_label INFO)" '\e[1m\e[36mHello, World!' \
+    "$(format_log_label INFO)" "$(printf '%b' '\e[1m\e[36mHello, World!')" \
     'Goodbye, World!'
 }
 
diff --git a/tests/testing/log.bats b/tests/testing/log.bats
index 8eeae1b..bbaece8 100644
--- a/tests/testing/log.bats
+++ b/tests/testing/log.bats
@@ -48,12 +48,6 @@ teardown() {
   assert_success "$expected_message"
 }
 
-@test "$SUITE: format_log_label exits if log module already initialized" {
-  __GO_LOG_INIT='true' run format_log_label INFO
-  assert_failure
-  assert_output_matches '^`format_log_label` must be called before any other '
-}
-
 @test "$SUITE: format_log_label exits if log level label invalid" {
   run format_log_label FOOBAR
   assert_failure 'Unknown log level label: FOOBAR'

From 1f3840a3768730ea34ef0e344149b1f58f09bfd7 Mon Sep 17 00:00:00 2001
From: Mike Bland <mbland@acm.org>
Date: Sun, 15 Jan 2017 10:49:35 -0500
Subject: [PATCH 8/9] assertions: Replace `echo` with `printf`

---
 lib/bats/assertions | 17 +++++++++--------
 1 file changed, 9 insertions(+), 8 deletions(-)

diff --git a/lib/bats/assertions b/lib/bats/assertions
index dbfbd3e..1f0c1d8 100644
--- a/lib/bats/assertions
+++ b/lib/bats/assertions
@@ -279,7 +279,7 @@ assert_output_matches() {
   local pattern="$1"
 
   if [[ "$#" -ne 1 ]]; then
-    echo "ERROR: ${FUNCNAME[0]} takes exactly one argument" >&2
+    printf 'ERROR: %s takes exactly one argument\n' "${FUNCNAME[0]}" >&2
     return_from_bats_assertion '1'
   else
     assert_matches "$pattern" "$output" 'output'
@@ -568,20 +568,21 @@ __assert_lines() {
 
   if [[ "$lines_diff" -gt '0' ]]; then
     if [[ "$lines_diff" -eq '1' ]]; then
-      echo "There is one more line of output than expected:" >&2
+      printf 'There is one more line of output than expected:\n' >&2
     else
-      echo "There are $lines_diff more lines of output than expected:" >&2
+      printf 'There are %d more lines of output than expected:\n' \
+        "$lines_diff" >&2
     fi
-    local IFS=$'\n'
-    echo "${lines[*]:$num_lines}" >&2
+    printf '%s\n' "${lines[@]:$num_lines}" >&2
     ((++num_errors))
 
   elif [[ "$lines_diff" -lt '0' ]]; then
     lines_diff="$((-lines_diff))"
     if [[ "$lines_diff" -eq '1' ]]; then
-      echo "There is one fewer line of output than expected." >&2
+      printf 'There is one fewer line of output than expected.\n' >&2
     else
-      echo "There are $lines_diff fewer lines of output than expected." >&2
+      printf 'There are %d fewer lines of output than expected.\n' \
+        "$lines_diff" >&2
     fi
     ((++num_errors))
   fi
@@ -610,7 +611,7 @@ __assert_file() {
 
   if [[ "$assertion" == 'assert_matches' ]]; then
     if [[ "$#" -ne '1' ]]; then
-      echo "ERROR: ${FUNCNAME[1]} takes exactly two arguments" >&2
+      printf 'ERROR: %s takes exactly two arguments\n' "${FUNCNAME[1]}" >&2
       return '1'
     fi
     constraints=("$1" "$output" "The content of '$file_path'")

From 7a24d782199a2f424445a379377652f1cc3ce9d1 Mon Sep 17 00:00:00 2001
From: Mike Bland <mbland@acm.org>
Date: Sun, 15 Jan 2017 11:46:52 -0500
Subject: [PATCH 9/9] lib/testing: Add assert_log{,_file}_equals tests

---
 lib/testing/log                   |  52 +++++++++++++-
 tests/testing/log.bats            |   7 ++
 tests/testing/log/assertions.bats | 113 ++++++++++++++++++++++++++++++
 3 files changed, 171 insertions(+), 1 deletion(-)
 create mode 100644 tests/testing/log/assertions.bats

diff --git a/lib/testing/log b/lib/testing/log
index f471e11..ba11dbe 100644
--- a/lib/testing/log
+++ b/lib/testing/log
@@ -5,6 +5,10 @@
 # You must source `_GO_CORE_DIR/lib/testing/environment` before this file.
 
 . "${BASH_SOURCE[0]%/*}/stack-trace"
+. "$_GO_CORE_DIR/lib/bats/assertions"
+
+# Log timestamps are disabled by for testing by default.
+export _GO_LOG_TIMESTAMP_FORMAT=
 
 # Creates a `./go` script that imports the `log` module
 #
@@ -51,6 +55,24 @@ format_log_label() {
   printf '%s' "${__GO_LOG_LEVELS_FORMATTED[$__go_log_level_index]}"
 }
 
+# Validates that `output` matches the expected `@go.log` output
+#
+# Each line can be expressed one of two ways:
+# - As a pair of strings: first the log level label, then the log message
+# - As a single string without a log level label prefix
+#
+# Each log level label must exist within `_GO_LOG_LEVELS`, and can be either a
+# plaintext label or a label formatted with `format_log_label`. Any unknown
+# labels will be parsed as "a single string without a log label prefix".
+#
+# If you aren't looking for exact log output, consider using one of the standard
+# assertions from `_GO_CORE_DIR/lib/bats/assertions` instead.
+#
+# Note that this does NOT handle timestamps. If you wish to validate specific
+# timestamps, see `_GO_CORE_DIR/tests/log/timestamp.bats` for ideas.
+#
+# Arguments:
+#   ...:  Lines of expected log output
 assert_log_equals() {
   set "$BATS_ASSERTION_DISABLE_SHELL_OPTIONS"
   local __log_level_label
@@ -69,7 +91,7 @@ assert_log_equals() {
       fi
 
       if ! shift 2; then
-        echo "ERROR: Wrong number of arguments for log line $i." >&2
+        printf 'ERROR: Wrong number of arguments for log line %d.\n' "$i" >&2
         return_from_bats_assertion 1
         return
       fi
@@ -86,6 +108,24 @@ assert_log_equals() {
   fi
 }
 
+# Validates that a file matches the expected `@go.log` output
+#
+# Aside from the first file path argument, the remaining arguments and semantics
+# are exactly the same as `assert_log_equals`.
+#
+# In cases where `@go.log_add_output_file` is used to add a `TEST_LOG_FILE` to
+# all levels, and all test output comes from `@go.log`, this may be invoked
+# following `assert_log_equals` like so to ensure the log file output matches
+# standard output and standard error:
+#
+#   assert_log_file_equals "$TEST_LOG_FILE" "${lines[@]}"
+#
+# If you aren't looking for exact log output, consider using one of the standard
+# assertions from `_GO_CORE_DIR/lib/bats/assertions` instead.
+#
+# Arguments:
+#   log_file:  Path to the log file to validate
+#   ...:       Lines of expected log output
 assert_log_file_equals() {
   set "$BATS_ASSERTION_DISABLE_SHELL_OPTIONS"
   local log_file="$1"
@@ -130,6 +170,16 @@ set_log_command_stack_trace_items() {
 # None of the functions below this line are part of the public interface.
 # --------------------------------
 
+# Determines whether a log level label is a valid member of `_GO_LOG_LEVELS`.
+#
+# If so, pads the label and assigns it to `__log_level_label`.
+#
+# Arguments:
+#   level_label:  Log level label to examine
+#
+# Returns:
+#   zero if `level_label` exists in `_GO_LOG_LEVELS`, nonzero otherwise
+#   __log_level_label:  Assigned the padded version of `level_label` if valid
 __parse_log_level_label() {
   local level_label="$1"
   local try_level
diff --git a/tests/testing/log.bats b/tests/testing/log.bats
index bbaece8..99bddc7 100644
--- a/tests/testing/log.bats
+++ b/tests/testing/log.bats
@@ -11,6 +11,13 @@ teardown() {
   remove_test_go_rootdir
 }
 
+@test "$SUITE: log timestamps are disabled for testing by default" {
+  assert_equal '' "$_GO_LOG_TIMESTAMP_FORMAT"
+  _GO_LOG_TIMESTAMP_FORMAT='%Y:%m:%d %H:%M:%S'
+  . "$_GO_CORE_DIR/lib/testing/log"
+  assert_equal '' "$_GO_LOG_TIMESTAMP_FORMAT"
+}
+
 @test "$SUITE: create_log_script and run_log_script without log file" {
   export TEST_LOG_FILE="$TEST_GO_ROOTDIR/test-script.log"
   TEST_LOG_FILE= run_log_script '@go.log INFO Hello, World!'
diff --git a/tests/testing/log/assertions.bats b/tests/testing/log/assertions.bats
new file mode 100644
index 0000000..5c817ba
--- /dev/null
+++ b/tests/testing/log/assertions.bats
@@ -0,0 +1,113 @@
+#! /usr/bin/env bats
+
+load ../../environment
+
+ASSERTION_SOURCE="$_GO_CORE_DIR/lib/testing/log"
+load "$_GO_CORE_DIR/lib/bats/assertion-test-helpers"
+
+setup() {
+  test_filter
+  mkdir -p "$TEST_GO_ROOTDIR"
+}
+
+teardown() {
+  remove_test_go_rootdir
+}
+
+@test "$SUITE: assert_log_equals empty output" {
+  expect_assertion_success ':' 'assert_log_equals'
+}
+
+@test "$SUITE: assert_log_equals single non-@go.log line" {
+  expect_assertion_success 'printf "Hello, World!\n"' \
+    'assert_log_equals "Hello, World!"'
+}
+
+@test "$SUITE: assert_log_equals single @go.log line" {
+  create_log_script '@go.log INFO Hello, World!'
+  expect_assertion_success "'$TEST_GO_SCRIPT'" \
+    'assert_log_equals INFO "Hello, World!"'
+}
+
+@test "$SUITE: assert_log_equals single formatted @go.log line" {
+  create_log_script '@go.log INFO Hello, World!'
+  _GO_LOG_FORMATTING='true' expect_assertion_success "'$TEST_GO_SCRIPT'" \
+    "assert_log_equals \"\$(format_log_label INFO)\" 'Hello, World!'"
+}
+
+@test "$SUITE: assert_log_equals multiple mixed lines" {
+  create_log_script '@go.log INFO Hello, World!' \
+    'printf "%s\n" "Not a @go.log line."' \
+    '@go.log WARN Goodbye, World!' \
+    'printf "%s\n" "Also not a @go.log line."'
+
+  local args=("'INFO' 'Hello, World!'"
+    "'Not a @go.log line.'"
+    "'WARN' 'Goodbye, World!'"
+    "'Also not a @go.log line.'")
+  expect_assertion_success "'$TEST_GO_SCRIPT'" \
+    "assert_log_equals ${args[*]}"
+}
+
+@test "$SUITE: assert_log_equals multiple mixed lines with formatting" {
+  create_log_script '@go.log INFO Hello, World!' \
+    'printf "%s\n" "Not a @go.log line."' \
+    '@go.log WARN Goodbye, World!' \
+    'printf "%s\n" "Also not a @go.log line."'
+
+  local args=("\"\$(format_log_label INFO)\" 'Hello, World!'"
+    "'Not a @go.log line.'"
+    "\"\$(format_log_label WARN)\" 'Goodbye, World!'"
+    "'Also not a @go.log line.'")
+  _GO_LOG_FORMATTING='true' expect_assertion_success "'$TEST_GO_SCRIPT'" \
+    "assert_log_equals ${args[*]}"
+}
+
+@test "$SUITE: assert_log_equals error if wrong number of log line args" {
+  create_log_script '@go.log INFO Hello, World!'
+  expect_assertion_failure "'$TEST_GO_SCRIPT'" \
+    "assert_log_equals 'INFO' 'Hello, World!' 'INFO'" \
+    'ERROR: Wrong number of arguments for log line 1.'
+}
+
+@test "$SUITE: assert_log_equals fails if line doesn't match" {
+  local info_label="$(format_log_label INFO)"
+  local end_format_code="$(printf '%b' '\e[0m')"
+
+  create_log_script '@go.log INFO Goodbye, World!'
+  _GO_LOG_FORMATTING='true' expect_assertion_failure "'$TEST_GO_SCRIPT'" \
+    "assert_log_equals \"\$(format_log_label INFO)\" 'Hello, World!'" \
+    'line 0 not equal to expected value:' \
+    "  expected: '$info_label Hello, World!$end_format_code'" \
+    "  actual:   '$info_label Goodbye, World!$end_format_code'" \
+    'OUTPUT:' \
+    "$info_label Goodbye, World!$end_format_code"
+}
+
+@test "$SUITE: assert_log_file_equals returns error if file doesn't exist" {
+  expect_assertion_failure ':' "assert_log_file_equals 'nonexistent.log'" \
+    "'nonexistent.log' doesn't exist or isn't a regular file."
+}
+
+@test "$SUITE: assert_log_file_equals empty output" {
+  expect_assertion_success "printf '' >'$TEST_GO_ROOTDIR/empty.log'" \
+    "assert_log_file_equals '$TEST_GO_ROOTDIR/empty.log'"
+}
+
+@test "$SUITE: assert_log_file_equals multiple mixed lines with formatting" {
+  export TEST_LOG_FILE="$TEST_GO_ROOTDIR/test.log"
+
+  # We need to clear the `TEST_LOG_FILE` between the two runs performed by
+  # `expect_assertion_success`, since `@go.log` will append to the file.
+  create_log_script "printf '' >'$TEST_LOG_FILE'" \
+    '@go.log INFO Hello, World!' \
+    'printf "%s\n" "Not a @go.log line."' \
+    '@go.log WARN Goodbye, World!' \
+    'printf "%s\n" "Also not a @go.log line."'
+
+  # Note that the file should only get the `@go.log` lines.
+  local args=("\"\$(format_log_label INFO)\" 'Hello, World!'"
+    "\"\$(format_log_label WARN)\" 'Goodbye, World!'")
+  _GO_LOG_FORMATTING='true' expect_assertion_success "'$TEST_GO_SCRIPT'" \
+    "assert_log_file_equals \"\$TEST_LOG_FILE\" ${args[*]}"
+}