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

Authored by: Pavel Zakharov <pavel.zakharov@delphix.com>
Reviewed by: John Kennedy <john.kennedy@delphix.com>
Reviewed by: Matt Ahrens <mahrens@delphix.com>
Approved by: Gordon Ross <gordon.w.ross@gmail.com>
Reviewed-by: Giuseppe Di Natale <dinatale2@llnl.gov>
Reviewed-by: George Melikov <mail@gmelikov.ru>
Ported-by: Brian Behlendorf <behlendorf1@llnl.gov>

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

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

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;

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}"

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 ""

tests/zfs-tests/Makefile.am

@@ -1 +1 @@
-SUBDIRS = cmd include tests
+SUBDIRS = cmd include tests callbacks

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

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 "================================================================="

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 "================================================================="