test_suite: formatting of test output

test_suite/README

@@ -15,6 +15,7 @@ Event this file is not complete!
 Contents
 --------
 1. Running a test
+1.1. Test output
 2. Naming conventions
 3. Error handling
 4. Signal handling
@@ -60,7 +61,7 @@ subdirectory (we call it start directory) as follows:
   -- user_modules.conf
   -- <subdirname>.conf where subdirname runs top down through the parent
      directories starting with the immediate subdirectory of the start directory
-     (or the immediate subdirectory directory given by optione --config_root_dir)
+     (or the immediate subdirectory directory given by option --config_root_dir)
      to the leaf directory.
 
      If the start directory is a leaf directory the <leaf directory name>.conf
@@ -70,9 +71,9 @@ subdirectory (we call it start directory) as follows:
          1. start directory = test_cases/perf
             leaf directory  = test_cases/perf/apply/no_parallel_writer
 
-            leads to including of apply.conf and no_parallel_writer.conf (in this
-            order!) which must reside as mentioned above in the leaf directory
-            or any of it's parent directories (up to 20 levels).
+            leads to including of apply.conf and no_parallel_writer.conf (in
+            this order!) which must reside as mentioned above in the leaf
+            directory or any of it's parent directories (up to 20 levels).
 
          2. start directory = test_cases/perf/apply/no_parallel_writer
                               --config_root_dir=.../test_cases/perf
@@ -85,6 +86,39 @@ subdirectory (we call it start directory) as follows:
 
             leads to including of no_parallel_writer.conf
 
+1.1 Test output
+---------------
+
+The output fo start_test.sh consists of the following sections:
+
+- List titled "Sourcing modules and default configuration" of included scripts
+  from scripts/modules/*.sh and corresponding included default-*.conf files.
+
+- Per leaf directory:
+    - List  titled "Sourcing config files between <config_root_dir> and
+      <leaf directory>" of included *.conf files corresponding to the directory
+      structure.
+
+    - List titled "Configuration variables" of all configuration variables set
+      via all included *.conf file
+
+    - Section titled "Creating lock files"
+
+    - Section titled "<date and time> Starting <leaf directory>"
+      In this section lines starting with "calling ..." mark the call to one of
+      the functions listed in the aforementioned variables prepare_list,
+      setup_list, run_list, cleanup_list and finish_list
+
+      - In case of an error: Subsection titled "Callstack" (to stderr)
+
+      - Subsection titled "Deleting lock files"
+
+      - Subsection titled "General checks of error and log files"
+    - Line titled "Failure <return code> <date and time>" (to stderr) in case
+      of failure, "Finished <date and time>" (to stdout) otherwise
+
+- Line titled "Finished pwd=<test directory>"
+
         
 2. Naming conventions
 ---------------------

test_suite/scripts/modules/07_lib_err.sh

@@ -66,9 +66,11 @@ function lib_check_for_kernel_oops_after_start_time
 
 function lib_general_checks_after_every_test
 {
+    echo "========================== General checks of error and log files ==============="
 	lib_err_check_and_copy_global_err_files_all
 	lib_check_proc_sys_mars_variables
     lib_check_for_kernel_oops_after_start_time
+    echo "========================== End general checks of error and log files ==========="
 }
 
 function lib_check_proc_sys_mars_variables

test_suite/scripts/modules/lib.sh

@@ -39,6 +39,7 @@ mkdir -p "$download_dir" || exit -1
 # general error exit function
 function lib_callstack
 {
+    echo "========================== Callstack ==========================================="
     local argv_index=0 i
     for i in ${!FUNCNAME[*]}; do
         local j args=
@@ -51,6 +52,7 @@ function lib_callstack
         fi
         echo ${BASH_SOURCE[(($i + 1))]:-"stdin"}:${BASH_LINENO[$i]} ${FUNCNAME[$i]} $args
     done
+    echo "========================== End callstack ======================================="
 }
 
 function lib_exit
@@ -60,11 +62,9 @@ function lib_exit
         echo "  $msg" >&2
     fi
     if [ $rc -ne 0 ]; then
-        printf "\nstack:\n" >&2
         lib_callstack >&2
     fi
     if [ $rc -ne $main_prevent_remove_lock_files_code ]; then
-        echo "lib_exit: releasing locks" >&2
         release_host_locks
     fi
     # to avoid recursion
@@ -75,7 +75,6 @@ function lib_exit
         exit $rc
     fi
     export lib_exit_recursion=1
-    echo "lib_exit: general after test checkings:" >&2
     lib_general_checks_after_every_test
     if [ ${#main_error_recovery_functions[*]} -ge 0 ]; then
         local func args

test_suite/scripts/start_test.sh

@@ -23,13 +23,14 @@
 
 shopt -s extdebug
 
-# Make many measurements in subtrees of current working directory.
 # Use directory names as basis for configuration variants
 
 script_dir="$(cd "$(dirname "$(which "$0")")"; pwd)"
+echo "========================== Sourcing modules and default configuration =========="
 for lib in $script_dir/modules/lib*.sh; do
     source "$lib" || exit $?
 done
+echo "========================== End sourcing modules and default configuration ======"
 
 to_produce="${to_produce:-replay.gz}"
 to_check="${to_check:-}"
@@ -62,6 +63,7 @@ function set_host_locks
         lib_vmsg "  warning: main_host_list empty"
         return
     fi
+    echo "========================== Creating lock files ================================="
     for host in "${main_host_list[@]}"; do
         local lock_file=${main_lock_file_list[$host]}
         if [ -z "$lock_file" ]; then
@@ -74,15 +76,18 @@ function set_host_locks
         date > $lock_file || lib_exit 1
         lib_vmsg "  created lockfile $lock_file on $host"
     done
+    echo "========================== End creating lock files ============================="
 }
 
 function release_host_locks
 {
+    echo "========================== Deleting lock files ================================="
     for host in "${main_host_list[@]}"; do
         local lock_file=${main_lock_file_list[$host]}
         rm -f $lock_file || lib_exit 1
         lib_vmsg "  deleted lockfile $lock_file on $host"
     done
+    echo "========================== End deleting lock files ============================="
 }
 
 function source_module
@@ -98,6 +103,42 @@ function source_module
     fi
 }
 
+function save_environment
+{
+    # we cannot use lib_exit because the libs are not yet sourced in
+    environ_save=/tmp/environ.sav.$$
+    rm -f $environ_save || lib_exit 1 "cannot remove $environ_save"
+    set >$environ_save || lib_exit 1 "cannot create $environ_save"
+}
+
+# prints all shell variables which are set via sourcing the *.conf files
+function print_config_environment
+{
+    local f
+    local environ_actual=/tmp/environ.act.$$
+    [ -n "$environ_save" ] || lib_exit 1 "variable environ_save not set"
+    [ -r "$environ_save" ] || lib_exit 1 "file $environ_save not readable"
+    rm -f $environ_actual || lib_exit 1 "cannot remove $environ_actual"
+    set >$environ_actual || lib_exit 1 "cannot create $environ_actual"
+    # delete function definitions and sort
+    for f in $environ_save $environ_actual; do
+        sed -i -e '/^.* () *$/d;/^{ *$/,/^} *$/d' $f || lib_exit 1
+        sort -o $f $f || lib_exit 1
+    done
+
+    echo "========================== Configuration variables ============================="
+    # print lines uniq to $environ_actual and remove some not interesting
+    # variables
+    comm -2 -3 $environ_actual $environ_save | \
+        egrep -v '^(BASH_LINENO|FUNCNAME|OLDPWD|_)='
+    rm -f $environ_actual $environ_save
+    echo "========================== End configuration variables ========================="
+    
+}
+
+
+save_environment # for later use in print_config_environment
+
 shopt -s nullglob
 for module in $module_dir/[0-9]*.sh; do
     source_module "$module"
@@ -139,7 +180,7 @@ ignore_cmd="grep -v '[/.]old' | grep -v 'ignore'"
 sort_cmd="while read i; do if [ -e \"\$i\"/prio-[0-9]* ]; then echo \"\$(cd \$i; ls prio-[0-9]*):\$i\"; else echo \"z:\$i\"; fi; done | sort | sed 's/^[^:]*://'"
 
 # find directories
-echo "Scanning directory structure starting from $(pwd)"
+echo "================= Sourcing config files between $config_root_dir and $(pwd)t ==="
 for test_dir in $(find . -type d | eval "$ignore_cmd" | eval "$sort_cmd"); do
     (( dry_run_script )) || rm -f $test_dir/dry-run.$to_produce
     if [ -e "$test_dir/skip" ]; then
@@ -196,6 +237,8 @@ for test_dir in $(find . -type d | eval "$ignore_cmd" | eval "$sort_cmd"); do
                 exit -1
             fi
         done
+        echo "================= End sourcing config files between $config_root_dir and $(pwd)t"
+        print_config_environment
         shopt -u nullglob
 
         export sub_prefix=$(echo $test_dir | sed 's/\//./g' | sed 's/\.\././g')
@@ -204,18 +247,17 @@ for test_dir in $(find . -type d | eval "$ignore_cmd" | eval "$sort_cmd"); do
             touch dry-run.$to_produce
         else
             set_host_locks
-            echo "==> $(date) Starting $sub_prefix"
+            echo "========================== $(date) Starting $sub_prefix ========================"
             eval "$to_start" # must call exit in case of failure
             release_host_locks
         fi
     )
     rc=$?
     if [ $rc -ne 0 ]; then
-        echo "Failure $rc $(date)."
+        echo "========================== Failure $rc $(date) =================================" >&2
     else
-        echo "Finished $(date)."
+        echo "========================== Finished $(date) ===================================="
     fi
-    echo "==============================================================="
     [ $rc -ne 0 ] && exit $rc
 done
 
@@ -224,5 +266,5 @@ if (( dry_run_script )); then
     rm -f $(find . -name "dry-run.$to_produce")
 fi
 
-echo "======== Finished pwd=$(pwd)"
+echo "========================== Finished pwd=$(pwd) ================================="
 exit 0