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.

6 files changed, 41 insertions, 25 deletions

diff --git a/regress/usr.bin/ssh/Makefile b/regress/usr.bin/ssh/Makefile
index e1c4c2bd239..ad438119ec8 100644
--- a/regress/usr.bin/ssh/Makefile
+++ b/regress/usr.bin/ssh/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
 
@@ -71,7 +71,8 @@ CLEANFILES+=	authorized_keys_${USER} known_hosts pidfile \
 		sshd_proxy_bak rsa_ssh2_cr.prv rsa_ssh2_crnl.prv \
 		known_hosts-cert host_ca_key* cert_user_key* cert_host_key* \
 		authorized_principals_${USER} expect actual ready \
-		sshd_proxy.* authorized_keys_${USER}.* revoked-* krl-*
+		sshd_proxy.* authorized_keys_${USER}.* revoked-* krl-* \
+		ssh.log sshd.log regress.log
 
 # Enable all malloc(3) randomisations and checks
 TEST_ENV=      "MALLOC_OPTIONS=AFGJPRX"
diff --git a/regress/usr.bin/ssh/cfgmatch.sh b/regress/usr.bin/ssh/cfgmatch.sh
index a44487376ae..4e36f4ffb4d 100644
--- a/regress/usr.bin/ssh/cfgmatch.sh
+++ b/regress/usr.bin/ssh/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/usr.bin/ssh/integrity.sh b/regress/usr.bin/ssh/integrity.sh
index 55d20f9a17f..ce33c52c7e5 100644
--- a/regress/usr.bin/ssh/integrity.sh
+++ b/regress/usr.bin/ssh/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"
@@ -19,7 +19,7 @@ macs="hmac-sha1 hmac-md5 umac-64@openssh.com umac-128@openssh.com
 macs="$macs aes128-gcm@openssh.com aes256-gcm@openssh.com"
 
 # sshd-command for proxy (see test-exec.sh)
-cmd="sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSH_LOGFILE} -i -f $OBJ/sshd_proxy"
+cmd="sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSHD_LOGFILE} -i -f $OBJ/sshd_proxy"
 
 for m in $macs; do
 	trace "test $tid: mac $m"
diff --git a/regress/usr.bin/ssh/multiplex.sh b/regress/usr.bin/ssh/multiplex.sh
index d95ab493dbe..49981e552e4 100644
--- a/regress/usr.bin/ssh/multiplex.sh
+++ b/regress/usr.bin/ssh/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=$OBJ/ctl-sock
@@ -50,13 +50,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}"
 
@@ -82,11 +82,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
@@ -102,9 +102,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/usr.bin/ssh/rekey.sh b/regress/usr.bin/ssh/rekey.sh
index 26848d27b56..d8c55a95b5c 100644
--- a/regress/usr.bin/ssh/rekey.sh
+++ b/regress/usr.bin/ssh/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}
 dd if=/dev/zero of=${DATA} bs=1k count=512 > /dev/null 2>&1
@@ -28,4 +28,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/usr.bin/ssh/test-exec.sh b/regress/usr.bin/ssh/test-exec.sh
index 7d6ac718116..9ada223be3b 100644
--- a/regress/usr.bin/ssh/test-exec.sh
+++ b/regress/usr.bin/ssh/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.
 
 USER=`id -un`
@@ -96,9 +96,24 @@ if [ ! -x /$SSHD ]; then
 	SSHD=`which sshd`
 fi
 
+# 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
 
 # these should be used in tests
 export SSH SSHD SSHAGENT SSHADD SSHKEYGEN SSHKEYSCAN SFTP SFTPSERVER SCP
@@ -131,7 +146,7 @@ cleanup ()
 
 trace ()
 {
-	echo "trace: $@" >>$TEST_SSH_LOGFILE
+	echo "trace: $@" >>$TEST_REGRESS_LOGFILE
 	if [ "X$TEST_SSH_TRACE" = "Xyes" ]; then
 		echo "$@"
 	fi
@@ -139,7 +154,7 @@ trace ()
 
 verbose ()
 {
-	echo "verbose: $@" >>$TEST_SSH_LOGFILE
+	echo "verbose: $@" >>$TEST_REGRESS_LOGFILE
 	if [ "X$TEST_SSH_QUIET" != "Xyes" ]; then
 		echo "$@"
 	fi
@@ -148,14 +163,14 @@ verbose ()
 
 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
 	echo -n "FATAL: "
 	fail "$@"
 	cleanup
@@ -286,7 +301,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
@@ -294,7 +309,7 @@ fi
 # create a proxy version of the client config
 (
 	cat $OBJ/ssh_config
-	echo proxycommand sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSH_LOGFILE} -i -f $OBJ/sshd_proxy
+	echo proxycommand sh ${SRC}/sshd-log-wrapper.sh ${SSHD} ${TEST_SSHD_LOGFILE} -i -f $OBJ/sshd_proxy
 ) > $OBJ/ssh_proxy
 
 # check proxy config
@@ -304,7 +319,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;