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

diff --git a/configure.ac b/configure.ac
index d9bf703e1c05b757e9061a7cd505ecbc7290a7fa..2b3957b3b5767216804ad48e81855ec78fec2a80 100644 (file)
--- 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 76a3ad91c91211e94de80445022675a66cbb40e0..90c1d7361d7c70e050bc5cd9fdb773456f4ff53c 100644 (file)
--- 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 54c2b3909d690f96cc0db1b2ee0d337c7cd58653..5228d457930e7d6122dfe0ab334aebf826d4c194 100755 (executable)
--- 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 10aaaf30ea50f3a465ebb54c9f037350da334279..d9f276e0e7ea9c2117c3b279b4e1182cbb512c31 100644 (file)
--- 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 8617034550e959313906e831802ebad5fddd5c84..ef4e6be9e980cf6631341bedd99e2c6b912ed331 100644 (file)
--- 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 (file)
index 0000000..71947f3
--- /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 (executable)
index 0000000..be001ad
--- /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 (executable)
index 0000000..3d8191d
--- /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 "================================================================="