Rewrite expect script in C to avoid multiple issues with shell

Author: richiejp

app/ext_example/Makefile

@@ -61,7 +61,7 @@ else
   CFLAGS += -g
 endif
 
-export THIS_LIB_BASE=$(shell cd ../.. && pwd)
+THIS_LIB_BASE=$(shell cd ../.. && pwd)
 CCBN=$(shell basename ${CC})
 BUILD_DIR=${THIS_LIB_BASE}/build/${BUILD_SUBDIR}/${CCBN}
 TARGET=${BUILD_DIR}/bin/zsvextmy.${SO}
@@ -77,9 +77,15 @@ TEST_PASS=printf "${COLOR_BLUE}$@: ${COLOR_GREEN}Passed${COLOR_NONE}\n"
 TEST_FAIL=(printf "${COLOR_BLUE}$@: ${COLOR_RED}Failed!${COLOR_NONE}\n" && exit 1)
 TEST_INIT=printf "${COLOR_PINK}$@: ${COLOR_NONE}\n"
 
+# test-expect.sh needs some of these to be exported
+export EXPECT_TIMEOUT ?= 5
 EXPECT=../../scripts/test-expect.sh
+export EXPECT_BIN=${BUILD_DIR}/bin/test-expect${EXE}
 export EXPECTED_PATH=test/expected
 
+${EXPECT_BIN}: ${THIS_LIB_BASE}/util/expect.c
+	${CC} ${CFLAGS} -Wall -o $@ $<
+
 CFLAGS_SHARED=-shared
 ifneq ($(findstring emcc,$(CC)),) # emcc
   CFLAGS_SHARED=-s SIDE_MODULE=1 -s LINKABLE=1
@@ -145,11 +151,17 @@ test-3: test-%: ${CLI} ${TARGET}
 	make -C ../test worldcitiespop_mil.csv
 
 export TMP_DIR=/tmp
-DATE_TIME:=$(shell date +%F-%H-%M-%S)
-export TIMINGS_CSV:=${TMP_DIR}/timings-${DATE_TIME}.csv
+export TIMINGS_CSV:=${TMP_DIR}/timings.csv
+
+${TIMINGS_CSV}:
+	@mkdir -p ${TMP_DIR}
+	@echo -n "Git, Test, Stage, Date, Time, Elapsed (s)" > ${TIMINGS_CSV}
+
+test-sheet-extension-1 test-sheet-extension-2: ${TARGET} ${TIMINGS_CSV} ${EXPECT_BIN}
+
 export CMP=cmp
 TMUX_TERM=xterm-256color
-test-sheet-extension-1: ${CLI} ${TARGET} ../test/worldcitiespop_mil.csv
+test-sheet-extension-1: ${CLI} ../test/worldcitiespop_mil.csv
 	@${TEST_INIT}
 	@rm -f ${TMP_DIR}/zsvext-$@.out tmux-*.log
 	@tmux kill-session -t $@ || echo 'No tmux session to kill'
@@ -161,7 +173,7 @@ test-sheet-extension-1: ${CLI} ${TARGET} ../test/worldcitiespop_mil.csv
 	tmux send-keys -t $@ "t" "hello" Enter && \
   ${EXPECT} $@ && ${TEST_PASS} || ${TEST_FAIL})
 
-test-sheet-extension-2: ${CLI} ${TARGET}
+test-sheet-extension-2: ${CLI}
 	@${TEST_INIT}
 	@rm -f ${TMP_DIR}/zsvext-$@.out tmux-*.log
 	@tmux kill-session -t $@ || echo 'No tmux session to kill'

app/test/Makefile

@@ -39,9 +39,10 @@ else
   EXE=.exe
 endif
 
-export THIS_LIB_BASE=$(shell cd ../.. && pwd)
+THIS_LIB_BASE=$(shell cd ../.. && pwd)
 CCBN=$(shell basename ${CC})
 BUILD_DIR=${THIS_LIB_BASE}/build/${BUILD_SUBDIR}/${CCBN}
+# exported for expect
 export TMP_DIR=${THIS_LIB_BASE}/tmp
 TEST_DATA_DIR=${THIS_LIB_BASE}/data
 
@@ -87,14 +88,18 @@ else
 endif
 
 BIG_FILE ?= none
-EXPECT_TIMEOUT ?= 5
+# test-expect.sh needs some of these to be exported
+export EXPECT_TIMEOUT ?= 5
 EXPECT=../../scripts/test-expect.sh
+export EXPECT_BIN=${BUILD_DIR}/bin/test-expect${EXE}
 export EXPECTED_PATH=expected
 
+${EXPECT_BIN}: ${THIS_LIB_BASE}/util/expect.c
+	${CC} ${CFLAGS} -Wall -o $@ $<
+
 MAKE_BIN=$(notdir ${MAKE})
 
-DATE_TIME:=$(shell date +%F-%H-%M-%S)
-export TIMINGS_CSV:=${TMP_DIR}/timings-${DATE_TIME}.csv
+export TIMINGS_CSV:=${TMP_DIR}/timings.csv
 
 help:
 	@echo "To run all tests: ${MAKE_BIN} test [LEAKS=1]"
@@ -116,7 +121,7 @@ test-paste:
 
 ${TIMINGS_CSV}:
 	@mkdir -p ${TMP_DIR}
-	@echo -n "Test, Stage, Time" > ${TIMINGS_CSV}
+	@echo -n "Git, Test, Stage, Date, Time, Elapsed (s)" > ${TIMINGS_CSV}
 
 .SECONDARY: worldcitiespop_mil.csv
 
@@ -613,7 +618,9 @@ test-sheet-cleanup:
 	@rm -f tmux-*.log
 	@tmux kill-server || printf ''
 
-test-sheet-all: test-sheet-1 test-sheet-2 test-sheet-3 test-sheet-4 test-sheet-5 test-sheet-6 test-sheet-7 test-sheet-8 test-sheet-9 test-sheet-10 test-sheet-11 test-sheet-12 test-sheet-13 test-sheet-14 test-sheet-subcommand test-sheet-prop-cmd-opt
+ALL_SHEET_TESTS=test-sheet-1 test-sheet-2 test-sheet-3 test-sheet-4 test-sheet-5 test-sheet-6 test-sheet-7 test-sheet-8 test-sheet-9 test-sheet-10 test-sheet-11 test-sheet-12 test-sheet-13 test-sheet-14 test-sheet-subcommand test-sheet-prop-cmd-opt
+${ALL_SHEET_TESTS}: ${BUILD_DIR}/bin/zsv_sheet${EXE} ${TIMINGS_CSV} ${EXPECT_BIN}
+test-sheet-all: ${ALL_SHEET_TESTS}
 	@(for SESSION in $^; do ! tmux kill-session -t "$$SESSION" 2>/dev/null; done && ${TEST_PASS} || ${TEST_FAIL})
 
 TMUX_TERM=xterm-256color

scripts/test-expect.sh

@@ -1,49 +1,46 @@
 #!/bin/sh -eu
 
-script_dir=$(dirname "$0")
+# The Makefile target which will be the test name
+TARGET="$1"
 
-export TARGET="$1"
+# The intermediate test stage if the test is split into multiple stages
+# if it is blank then it is the last stage
 if [ -z "${2:-}" ]; then
-  export STAGE=""
+   STAGE=""
 else
-  export STAGE=-"$2"
+   STAGE=-"$2"
 fi
-export CAPTURE="${TMP_DIR}/$TARGET$STAGE".out
-EXPECTED="$EXPECTED_PATH/$TARGET$STAGE".out
-export EXPECTED
-matched=false
-
-t=${EXPECT_TIMEOUT:-5}
-
-cleanup() {
-  if $matched; then
-    if [ -z "$STAGE" ]; then
-      tmux send-keys -t "$TARGET" "q"
-    fi
-    exit 0
-  fi
-
-  tmux send-keys -t "$TARGET" "q"
-  echo 'Incorrect output:'
-  cat "$CAPTURE"
-  ${CMP} -s "$CAPTURE" "$EXPECTED"
-  exit 1
-}
 
-trap cleanup INT TERM QUIT
+# The capture file that is written to if we fail to match. If the capture is correct
+# but expected is missing or wrong, then we can copy this to the expected location
+CAPTURE="${TMP_DIR}/$TARGET$STAGE".out
+# The expected output to match against
+EXPECTED="$EXPECTED_PATH/$TARGET$STAGE".out
 
-printf "\n%s, %s" "$TARGET" "${2:-}" >> "${TIMINGS_CSV}"
+# write Git hash, target, stage, date, time to the CSV timings file
+printf "\n%s, %s, %s, %s" "$(git rev-parse --short HEAD)" "$TARGET" "${2:-}" "$(date '+%F, %T')" >> "${TIMINGS_CSV}"
 
+# temporarily disable error checking
 set +e
-match_time=$(time -p timeout -k $(( t + 1 )) $t "${script_dir}"/test-retry-capture-cmp.sh 2>&1)
+# run the expect utility which will repeatedly
+# try to match the expected output to the screen captured by tmux. If successfull
+# it will output the elapsed time to stdout and therefor match_time, on failure it
+# will print to stderr which the user will see
+match_time=$($EXPECT_BIN "$EXPECTED" "$TARGET" "$CAPTURE" "$EXPECT_TIMEOUT")
 status=$?
 set -e
 
 if [ $status -eq 0 ]; then
-  matched=true
-  match_time=$(echo "$match_time" | head -n 1 | cut -f 2 -d ' ')
+  # write the time it took to match the expected text with the capture
   echo "$TARGET$STAGE took $match_time"
   printf ", %s" "$match_time" >> "${TIMINGS_CSV}"
+else
+  echo "$TARGET$STAGE did not match"
+fi
+
+# Quit if this is the last stage or there was an error
+if [ -z "$STAGE" ] || [ $status -eq 1 ]; then
+  tmux send-keys -t "$TARGET" "q"
 fi
 
-cleanup
+exit $status

scripts/test-retry-capture-cmp.sh

@@ -0,0 +1,159 @@
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <unistd.h>
+#include <time.h>
+
+/*
+ * This utility allows us to wait for a particular output from zsv sheet.
+ *
+ * It avoids needing to call sleep with a set time and instead we specify the output
+ * we wish to see and a timeout. If the timeout is exceeded then it fails and prints
+ * the output that was last seen and saves it to a file.
+ *
+ * It repeatedly calls tmux capture-pane and compares the contents with the expected file.
+ *
+ * There is a wrapper for this utility which is used in the Makefiles scripts/test-expect.sh
+ */
+
+int main(int argc, char **argv) {
+  if (argc != 5) {
+    fprintf(stderr, "Usage: %s <expected> <pane> <actual> <timeout>\n", argv[0]);
+    return 1;
+  }
+
+  char *expected = argv[1];
+  char *pane = argv[2];
+  char *actual = argv[3];
+  char *timeout_s = argv[4];
+
+  char *endptr;
+  double timeout = strtod(timeout_s, &endptr);
+
+  if (endptr == timeout_s) {
+    perror("strtod");
+    return 1;
+  }
+
+  // Read the contents of the file
+  FILE *file = fopen(expected, "r");
+  if (file == NULL) {
+    perror("fopen");
+    return 1;
+  }
+
+  if (fseek(file, 0, SEEK_END) != 0) {
+    perror("fseek");
+    return 1;
+  }
+
+  long file_size = ftell(file);
+  if (file_size < 0) {
+    perror("ftell");
+    return 1;
+  }
+
+  rewind(file);
+
+  char *expected_output = malloc(file_size + 1);
+  if (expected_output == NULL) {
+    perror("malloc");
+    return 1;
+  }
+
+  size_t bytes_read = fread(expected_output, 1, file_size, file);
+  if (bytes_read != (size_t)file_size) {
+    if (ferror(file)) {
+      perror("fread");
+      return 1;
+    }
+  }
+
+  expected_output[file_size] = '\0';
+
+  if (fclose(file) != 0) {
+    perror("fclose");
+    return 1;
+  }
+
+  struct timespec start_time;
+  if (clock_gettime(CLOCK_MONOTONIC, &start_time) != 0) {
+    perror("clock_gettime");
+    return 1;
+  }
+
+  struct timespec current_time;
+  char *expected_input = malloc(file_size + 1);
+  if (expected_input == NULL) {
+    perror("malloc");
+    return 1;
+  }
+
+  double elapsed_time;
+  char command[256];
+  snprintf(command, sizeof(command), "tmux capture-pane -t %s -p", pane);
+
+  while (1) {
+    // Run tmux capture-pane -p
+    FILE *pipe = popen(command, "r");
+    if (pipe == NULL) {
+      perror("popen");
+      return 1;
+    }
+
+    size_t len = 0;
+    for (int i = 0; i < 10 && len < (size_t)file_size; i++) {
+      len += fread(expected_input + len, 1, file_size - len, pipe);
+      if (ferror(pipe)) {
+        perror("fread");
+        return 1;
+      }
+      usleep(1);
+    }
+
+    if (pclose(pipe) != 0) {
+      return 1;
+    }
+
+    // Check if the timeout has expired
+    if (clock_gettime(CLOCK_MONOTONIC, &current_time) != 0) {
+      perror("clock_gettime");
+      return 1;
+    }
+
+    elapsed_time =
+      (current_time.tv_sec - start_time.tv_sec) + (current_time.tv_nsec - start_time.tv_nsec) / 1000000000.0;
+
+    // Check if the output matches the expected output
+    if (strcmp(expected_input, expected_output) == 0) {
+      break;
+    }
+
+    if (elapsed_time > timeout) {
+      fprintf(stderr, "Timeout expired after %.2f seconds\n", elapsed_time);
+      fprintf(stderr, "Last output that failed to match:\n%s\n", expected_input);
+
+      FILE *output = fopen(actual, "w");
+      if (output == NULL) {
+        perror("fopen");
+        return 1;
+      }
+
+      fprintf(output, "%s", expected_input);
+      fclose(output);
+
+      return 1;
+    }
+
+    // Sleep for a short period of time before trying again
+    struct timespec sleep_time = {0, 10000000}; // 10 milliseconds
+    if (nanosleep(&sleep_time, NULL) != 0) {
+      perror("nanosleep");
+      return 1;
+    }
+  }
+
+  printf("%.2f\n", elapsed_time);
+
+  return 0;
+}