OpenZFS 7503 - zfs-test should tail ::zfs_dbgmsg on test failure

Authored by: Pavel Zakharov <[email protected]>
Reviewed by: John Kennedy <[email protected]>
Reviewed by: Matt Ahrens <[email protected]>
Approved by: Gordon Ross <[email protected]>
Reviewed-by: Giuseppe Di Natale <[email protected]>
Reviewed-by: George Melikov <[email protected]>
Ported-by: Brian Behlendorf <[email protected]>

Porting Notes:
- Enable internal log for DEBUG builds and in zfs-tests.sh.
- callbacks/zfs_dbgmsg.ksh - Dump interal log via kstat.
- callbacks/zfs_dmesg.ksh - Dump dmesg log.
- default.cfg - 'Test Suite Specific Commands' dropped.

OpenZFS-issue: https://www.illumos.org/issues/7503
OpenZFS-commit: https://github.com/openzfs/openzfs/commit/55a1300
Closes #6002 

8 files changed, 99 insertions, 3 deletions

diff --git a/configure.ac b/configure.ac
index d9bf703e1..2b3957b3b 100644
--- a/configure.ac
+++ b/configure.ac
@@ -146,6 +146,7 @@ AC_CONFIG_FILES([
 	tests/test-runner/man/Makefile
 	tests/runfiles/Makefile
 	tests/zfs-tests/Makefile
+	tests/zfs-tests/callbacks/Makefile
 	tests/zfs-tests/cmd/Makefile
 	tests/zfs-tests/cmd/chg_usr_exec/Makefile
 	tests/zfs-tests/cmd/devname2devid/Makefile
diff --git a/module/zfs/zfs_debug.c b/module/zfs/zfs_debug.c
index 76a3ad91c..90c1d7361 100644
--- a/module/zfs/zfs_debug.c
+++ b/module/zfs/zfs_debug.c
@@ -42,7 +42,7 @@ kstat_t *zfs_dbgmsg_kstat;
  * # Clear the kernel debug message log.
  * echo 0 >/proc/spl/kstat/zfs/dbgmsg
  */
-#if defined(_KERNEL)
+#if defined(_KERNEL) && !defined(ZFS_DEBUG)
 int zfs_dbgmsg_enable = 0;
 #else
 int zfs_dbgmsg_enable = 1;
diff --git a/scripts/zfs-tests.sh b/scripts/zfs-tests.sh
index 54c2b3909..5228d4579 100755
--- a/scripts/zfs-tests.sh
+++ b/scripts/zfs-tests.sh
@@ -41,6 +41,9 @@ FILEDIR=${FILEDIR:-/var/tmp}
 DISKS=${DISKS:-""}
 SINGLETEST=()
 SINGLETESTUSER="root"
+ZFS_DBGMSG="$STF_SUITE/callbacks/zfs_dbgmsg.ksh"
+ZFS_DMESG="$STF_SUITE/callbacks/zfs_dmesg.ksh"
+TESTFAIL_CALLBACKS=${TESTFAIL_CALLBACKS:-"$ZFS_DBGMSG:$ZFS_DMESG"}
 
 #
 # Attempt to remove loopback devices and files which where created earlier
@@ -475,6 +478,14 @@ if [ -x "$STF_PATH/setenforce" ]; then
 	sudo setenforce permissive &>/dev/null
 fi
 
+#
+# Enable interal ZFS debug log and clear it.
+#
+if [ -e /sys/module/zfs/parameters/zfs_dbgmsg_enable ]; then
+	sudo /bin/sh -c "echo 1 >/sys/module/zfs/parameters/zfs_dbgmsg_enable"
+	sudo /bin/sh -c "echo 0 >/proc/spl/kstat/zfs/dbgmsg"
+fi
+
 msg "FILEDIR:         $FILEDIR"
 msg "FILES:           $FILES"
 msg "LOOPBACKS:       $LOOPBACKS"
@@ -491,6 +502,7 @@ export STF_PATH
 export DISKS
 export KEEP
 export __ZFS_POOL_EXCLUDE
+export TESTFAIL_CALLBACKS
 export PATH=$STF_PATH
 
 msg "${TEST_RUNNER} ${QUIET} -c ${RUNFILE} -i ${STF_SUITE}"
diff --git a/tests/test-runner/include/logapi.shlib b/tests/test-runner/include/logapi.shlib
index 10aaaf30e..d9f276e0e 100644
--- a/tests/test-runner/include/logapi.shlib
+++ b/tests/test-runner/include/logapi.shlib
@@ -24,7 +24,7 @@
 # Copyright 2007 Sun Microsystems, Inc.  All rights reserved.
 # Use is subject to license terms.
 #
-# Copyright (c) 2012 by Delphix. All rights reserved.
+# Copyright (c) 2012, 2016 by Delphix. All rights reserved.
 #
 
 . ${STF_TOOLS}/include/stf.shlib
@@ -392,6 +392,22 @@ function log_other
 # Internal functions
 #
 
+# Execute custom callback scripts on test failure
+#
+# callback script paths are stored in TESTFAIL_CALLBACKS, delimited by ':'.
+
+function _execute_testfail_callbacks
+{
+	typeset callback
+
+	print "$TESTFAIL_CALLBACKS:" | while read -d ":" callback; do
+		if [[ -n "$callback" ]] ; then
+			log_note "Performing test-fail callback ($callback)"
+			$callback
+		fi
+	done
+}
+
 # Perform cleanup and exit
 #
 # $1 - stf exit code
@@ -402,6 +418,10 @@ function _endlog
 	typeset logfile="/tmp/log.$$"
 	_recursive_output $logfile
 
+	if [[ $1 == $STF_FAIL ]] ; then
+		_execute_testfail_callbacks
+	fi
+
 	if [[ -n $_CLEANUP ]] ; then
 		typeset cleanup=$_CLEANUP
 		log_onexit ""
diff --git a/tests/zfs-tests/Makefile.am b/tests/zfs-tests/Makefile.am
index 861703455..ef4e6be9e 100644
--- a/tests/zfs-tests/Makefile.am
+++ b/tests/zfs-tests/Makefile.am
@@ -1 +1 @@
-SUBDIRS = cmd include tests
+SUBDIRS = cmd include tests callbacks
diff --git a/tests/zfs-tests/callbacks/Makefile.am b/tests/zfs-tests/callbacks/Makefile.am
new file mode 100644
index 000000000..71947f308
--- /dev/null
+++ b/tests/zfs-tests/callbacks/Makefile.am
@@ -0,0 +1,4 @@
+pkgdatadir = $(datadir)/@PACKAGE@/zfs-tests/callbacks
+dist_pkgdata_SCRIPTS = \
+	zfs_dbgmsg.ksh \
+	zfs_dmesg.ksh
diff --git a/tests/zfs-tests/callbacks/zfs_dbgmsg.ksh b/tests/zfs-tests/callbacks/zfs_dbgmsg.ksh
new file mode 100755
index 000000000..be001ad9d
--- /dev/null
+++ b/tests/zfs-tests/callbacks/zfs_dbgmsg.ksh
@@ -0,0 +1,29 @@
+#!/bin/ksh -p
+
+#
+# This file and its contents are supplied under the terms of the
+# Common Development and Distribution License ("CDDL"), version 1.0.
+# You may only use this file in accordance with the terms of version
+# 1.0 of the CDDL.
+#
+# A full copy of the text of the CDDL should have accompanied this
+# source.  A copy of the CDDL is also available via the Internet at
+# http://www.illumos.org/license/CDDL.
+#
+
+#
+# Copyright (c) 2016 by Delphix. All rights reserved.
+#
+
+# $1: number of lines to output (default: 200)
+typeset lines=${1:-200}
+
+echo "================================================================="
+echo " Tailing last $lines lines of zfs_dbgmsg log"
+echo "================================================================="
+
+sudo tail -n $lines /proc/spl/kstat/zfs/dbgmsg
+
+echo "================================================================="
+echo " End of zfs_dbgmsg log"
+echo "================================================================="
diff --git a/tests/zfs-tests/callbacks/zfs_dmesg.ksh b/tests/zfs-tests/callbacks/zfs_dmesg.ksh
new file mode 100755
index 000000000..3d8191de5
--- /dev/null
+++ b/tests/zfs-tests/callbacks/zfs_dmesg.ksh
@@ -0,0 +1,30 @@
+#!/bin/ksh -p
+
+#
+# This file and its contents are supplied under the terms of the
+# Common Development and Distribution License ("CDDL"), version 1.0.
+# You may only use this file in accordance with the terms of version
+# 1.0 of the CDDL.
+#
+# A full copy of the text of the CDDL should have accompanied this
+# source.  A copy of the CDDL is also available via the Internet at
+# http://www.illumos.org/license/CDDL.
+#
+
+#
+# Copyright (c) 2016 by Delphix. All rights reserved.
+# Copyright (c) 2017 Lawrence Livermore National Security, LLC.
+#
+
+# $1: number of lines to output (default: 200)
+typeset lines=${1:-200}
+
+echo "================================================================="
+echo " Tailing last $lines lines of dmesg log"
+echo "================================================================="
+
+sudo dmesg | tail -n $lines
+
+echo "================================================================="
+echo " End of dmesg log"
+echo "================================================================="