- dtucker@cvs.openbsd.org 2013/04/06 06:00:22

     [regress/rekey.sh regress/test-exec.sh regress/integrity.sh
     regress/multiplex.sh Makefile regress/cfgmatch.sh]
     Split the regress log into 3 parts: the debug output from ssh, the debug
     log from sshd and the output from the client command (ssh, scp or sftp).
     Somewhat functional now, will become more useful when ssh/sshd -E is added.

7 files changed, 48 insertions, 27 deletions

diff --git a/ChangeLog b/ChangeLog
index 95586e871..14450ac65 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -4,10 +4,16 @@
      [regress/proxy-connect.sh]
      repeat test with a style appended to the username
    - dtucker@cvs.openbsd.org 2013/03/23 11:09:43
-     [test-exec.sh]
+     [regress/test-exec.sh]
      Only regenerate host keys if they don't exist or if ssh-keygen has changed
      since they were.  Reduces test runtime by 5-30% depending on machine
      speed.
+   - dtucker@cvs.openbsd.org 2013/04/06 06:00:22
+     [regress/rekey.sh regress/test-exec.sh regress/integrity.sh
+     regress/multiplex.sh Makefile regress/cfgmatch.sh]
+     Split the regress log into 3 parts: the debug output from ssh, the debug
+     log from sshd and the output from the client command (ssh, scp or sftp).
+     Somewhat functional now, will become more useful when ssh/sshd -E is added.
 
 20130516
  - (djm) [contrib/ssh-copy-id] Fix bug that could cause "rm *" to be 
diff --git a/regress/Makefile b/regress/Makefile
index 6ef5d9cce..b99bd3e83 100644
--- a/regress/Makefile
+++ b/regress/Makefile
@@ -1,4 +1,4 @@
-#       $OpenBSD: Makefile,v 1.62 2013/01/18 00:45:29 djm Exp $
+#       $OpenBSD: Makefile,v 1.63 2013/04/06 06:00:22 dtucker Exp $
 
 REGRESS_TARGETS=        t1 t2 t3 t4 t5 t6 t7 t8 t9 t-exec
 tests:          $(REGRESS_TARGETS)
@@ -82,8 +82,8 @@ CLEANFILES=	t2.out t3.out t6.out1 t6.out2 t7.out t7.out.pub copy.1 copy.2 \
                 putty.rsa2 sshd_proxy_orig ssh_proxy_bak \
                 key.rsa-* key.dsa-* key.ecdsa-* \
                 authorized_principals_${USER} expect actual ready \
-                sshd_proxy.* authorized_keys_${USER}.* modpipe revoked-* krl-*
-
+                sshd_proxy.* authorized_keys_${USER}.* modpipe revoked-* krl-* \
+                ssh.log sshd.log regress.log
 
 # Enable all malloc(3) randomisations and checks
 TEST_ENV=      "MALLOC_OPTIONS=AFGJPRX"
diff --git a/regress/cfgmatch.sh b/regress/cfgmatch.sh
index 0603fab64..02755d9d0 100644
--- a/regress/cfgmatch.sh
+++ b/regress/cfgmatch.sh
@@ -1,4 +1,4 @@
-#       $OpenBSD: cfgmatch.sh,v 1.6 2011/06/03 05:35:10 dtucker Exp $
+#       $OpenBSD: cfgmatch.sh,v 1.7 2013/04/06 06:00:22 dtucker Exp $
 #       Placed in the Public Domain.
 
 tid="sshd_config match"
@@ -15,7 +15,7 @@ start_client()
         rm -f $pidfile
         ${SSH} -q -$p $fwd "$@" somehost \
             exec sh -c \'"echo \$\$ > $pidfile; exec sleep 100"\' \
-            >>$TEST_SSH_LOGFILE 2>&1 &
+            >>$TEST_REGRESS_LOGFILE 2>&1 &
         client_pid=$!
         # Wait for remote end
         n=0
diff --git a/regress/integrity.sh b/regress/integrity.sh
index 4d46926d5..1bd330a18 100644
--- a/regress/integrity.sh
+++ b/regress/integrity.sh
@@ -1,4 +1,4 @@
-#       $OpenBSD: integrity.sh,v 1.7 2013/02/20 08:27:50 djm Exp $
+#       $OpenBSD: integrity.sh,v 1.8 2013/04/06 06:00:22 dtucker Exp $
 #       Placed in the Public Domain.
 
 tid="integrity"
@@ -22,7 +22,7 @@ config_defined OPENSSL_HAVE_EVPGCM && \
         macs="$macs aes128-gcm@openssh.com aes256-gcm@openssh.com"
 
 # sshd-command for proxy (see test-exec.sh)
-cmd="$SUDO sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSH_LOGFILE} -i -f $OBJ/sshd_proxy"
+cmd="$SUDO sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSHD_LOGFILE} -i -f $OBJ/sshd_proxy"
 
 jot() {
         awk "BEGIN { for (i = $2; i < $2 + $1; i++) { printf \"%d\n\", i } exit }"
diff --git a/regress/multiplex.sh b/regress/multiplex.sh
index 1e6cc7606..6491837a4 100644
--- a/regress/multiplex.sh
+++ b/regress/multiplex.sh
@@ -1,4 +1,4 @@
-#       $OpenBSD: multiplex.sh,v 1.17 2012/10/05 02:05:30 dtucker Exp $
+#       $OpenBSD: multiplex.sh,v 1.18 2013/04/06 06:00:22 dtucker Exp $
 #       Placed in the Public Domain.
 
 CTL=/tmp/openssh.regress.ctl-sock.$$
@@ -55,13 +55,13 @@ cmp ${DATA} ${COPY}		|| fail "ssh -S ctl: corrupted copy of ${DATA}"
 rm -f ${COPY}
 trace "sftp transfer over multiplexed connection and check result"
 echo "get ${DATA} ${COPY}" | \
-        ${SFTP} -S ${SSH} -F $OBJ/ssh_config -oControlPath=$CTL otherhost >>$TEST_SSH_LOGFILE 2>&1
+        ${SFTP} -S ${SSH} -F $OBJ/ssh_config -oControlPath=$CTL otherhost >>$TEST_REGRESS_LOGFILE 2>&1
 test -f ${COPY}                 || fail "sftp: failed copy ${DATA}" 
 cmp ${DATA} ${COPY}             || fail "sftp: corrupted copy of ${DATA}"
 
 rm -f ${COPY}
 trace "scp transfer over multiplexed connection and check result"
-${SCP} -S ${SSH} -F $OBJ/ssh_config -oControlPath=$CTL otherhost:${DATA} ${COPY} >>$TEST_SSH_LOGFILE 2>&1
+${SCP} -S ${SSH} -F $OBJ/ssh_config -oControlPath=$CTL otherhost:${DATA} ${COPY} >>$TEST_REGRESS_LOGFILE 2>&1
 test -f ${COPY}                 || fail "scp: failed copy ${DATA}" 
 cmp ${DATA} ${COPY}             || fail "scp: corrupted copy of ${DATA}"
 
@@ -87,11 +87,11 @@ for s in 0 1 4 5 44; do
 done
 
 verbose "test $tid: cmd check"
-${SSH} -F $OBJ/ssh_config -S $CTL -Ocheck otherhost >>$TEST_SSH_LOGFILE 2>&1 \
+${SSH} -F $OBJ/ssh_config -S $CTL -Ocheck otherhost >>$TEST_REGRESS_LOGFILE 2>&1 \
     || fail "check command failed" 
 
 verbose "test $tid: cmd exit"
-${SSH} -F $OBJ/ssh_config -S $CTL -Oexit otherhost >>$TEST_SSH_LOGFILE 2>&1 \
+${SSH} -F $OBJ/ssh_config -S $CTL -Oexit otherhost >>$TEST_REGRESS_LOGFILE 2>&1 \
     || fail "send exit command failed" 
 
 # Wait for master to exit
@@ -107,9 +107,9 @@ wait_for_mux_master_ready
 
 # start a long-running command then immediately request a stop
 ${SSH} -F $OBJ/ssh_config -S $CTL otherhost "sleep 10; exit 0" \
-     >>$TEST_SSH_LOGFILE 2>&1 &
+     >>$TEST_REGRESS_LOGFILE 2>&1 &
 SLEEP_PID=$!
-${SSH} -F $OBJ/ssh_config -S $CTL -Ostop otherhost >>$TEST_SSH_LOGFILE 2>&1 \
+${SSH} -F $OBJ/ssh_config -S $CTL -Ostop otherhost >>$TEST_REGRESS_LOGFILE 2>&1 \
     || fail "send stop command failed"
 
 # wait until both long-running command and master have exited.
diff --git a/regress/rekey.sh b/regress/rekey.sh
index 3c5f266fc..b23cfca70 100644
--- a/regress/rekey.sh
+++ b/regress/rekey.sh
@@ -1,11 +1,11 @@
-#       $OpenBSD: rekey.sh,v 1.1 2003/03/28 13:58:28 markus Exp $
+#       $OpenBSD: rekey.sh,v 1.2 2013/04/06 06:00:22 dtucker Exp $
 #       Placed in the Public Domain.
 
 tid="rekey during transfer data"
 
 DATA=${OBJ}/data
 COPY=${OBJ}/copy
-LOG=${OBJ}/log
+LOG=${TEST_SSH_LOGFILE}
 
 rm -f ${COPY} ${LOG} ${DATA}
 touch ${DATA}
@@ -29,4 +29,4 @@ for s in 16 1k 128k 256k; do
                 fail "no rekeying occured"
         fi
 done
-rm -f ${COPY} ${LOG} ${DATA}
+rm -f ${COPY} ${DATA}
diff --git a/regress/test-exec.sh b/regress/test-exec.sh
index 29dac3de9..b02172c03 100644
--- a/regress/test-exec.sh
+++ b/regress/test-exec.sh
@@ -1,4 +1,4 @@
-#       $OpenBSD: test-exec.sh,v 1.38 2013/03/23 11:09:43 dtucker Exp $
+#       $OpenBSD: test-exec.sh,v 1.39 2013/04/06 06:00:22 dtucker Exp $
 #       Placed in the Public Domain.
 
 #SUDO=sudo
@@ -136,9 +136,24 @@ case "$SSHD" in
 *) SSHD=`which sshd` ;;
 esac
 
+# Logfiles.
+# SSH_LOGFILE should be the debug output of ssh(1) only
+# SSHD_LOGFILE should be the debug output of sshd(8) only
+# REGRESS_LOGFILE is the output of the test itself stdout and stderr
 if [ "x$TEST_SSH_LOGFILE" = "x" ]; then
-        TEST_SSH_LOGFILE=/dev/null
+        TEST_SSH_LOGFILE=$OBJ/ssh.log
 fi
+if [ "x$TEST_SSHD_LOGFILE" = "x" ]; then
+        TEST_SSHD_LOGFILE=$OBJ/sshd.log
+fi
+if [ "x$TEST_REGRESS_LOGFILE" = "x" ]; then
+        TEST_REGRESS_LOGFILE=$OBJ/regress.log
+fi
+
+# truncate logfiles
+>$TEST_SSH_LOGFILE
+>$TEST_SSHD_LOGFILE
+>$TEST_REGRESS_LOGFILE
 
 # Some data for test copies
 DATA=$OBJ/testdata
@@ -201,7 +216,7 @@ cleanup ()
 
 trace ()
 {
-        echo "trace: $@" >>$TEST_SSH_LOGFILE
+        echo "trace: $@" >>$TEST_REGRESS_LOGFILE
         if [ "X$TEST_SSH_TRACE" = "Xyes" ]; then
                 echo "$@"
         fi
@@ -209,7 +224,7 @@ trace ()
 
 verbose ()
 {
-        echo "verbose: $@" >>$TEST_SSH_LOGFILE
+        echo "verbose: $@" >>$TEST_REGRESS_LOGFILE
         if [ "X$TEST_SSH_QUIET" != "Xyes" ]; then
                 echo "$@"
         fi
@@ -223,14 +238,14 @@ warn ()
 
 fail ()
 {
-        echo "FAIL: $@" >>$TEST_SSH_LOGFILE
+        echo "FAIL: $@" >>$TEST_REGRESS_LOGFILE
         RESULT=1
         echo "$@"
 }
 
 fatal ()
 {
-        echo "FATAL: $@" >>$TEST_SSH_LOGFILE
+        echo "FATAL: $@" >>$TEST_REGRESS_LOGFILE
         echon "FATAL: "
         fail "$@"
         cleanup
@@ -372,7 +387,7 @@ if test "$REGRESS_INTEROP_PUTTY" = "yes" ; then
         echo "Hostname=127.0.0.1" >> ${OBJ}/.putty/sessions/localhost_proxy
         echo "PortNumber=$PORT" >> ${OBJ}/.putty/sessions/localhost_proxy
         echo "ProxyMethod=5" >> ${OBJ}/.putty/sessions/localhost_proxy
-        echo "ProxyTelnetCommand=sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSH_LOGFILE} -i -f $OBJ/sshd_proxy" >> ${OBJ}/.putty/sessions/localhost_proxy 
+        echo "ProxyTelnetCommand=sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSHD_LOGFILE} -i -f $OBJ/sshd_proxy" >> ${OBJ}/.putty/sessions/localhost_proxy
 
         REGRESS_INTEROP_PUTTY=yes
 fi
@@ -380,7 +395,7 @@ fi
 # create a proxy version of the client config
 (
         cat $OBJ/ssh_config
-        echo proxycommand ${SUDO} sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSH_LOGFILE} -i -f $OBJ/sshd_proxy
+        echo proxycommand ${SUDO} sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSHD_LOGFILE} -i -f $OBJ/sshd_proxy
 ) > $OBJ/ssh_proxy
 
 # check proxy config
@@ -390,7 +405,7 @@ start_sshd ()
 {
         # start sshd
         $SUDO ${SSHD} -f $OBJ/sshd_config "$@" -t || fatal "sshd_config broken"
-        $SUDO ${SSHD} -f $OBJ/sshd_config -e "$@" >>$TEST_SSH_LOGFILE 2>&1
+        $SUDO ${SSHD} -f $OBJ/sshd_config -e "$@" >>$TEST_SSHD_LOGFILE 2>&1
 
         trace "wait for sshd"
         i=0;