Add --enable-debug-log configure option

Until now the notion of an internal debug logging infrastructure
was conflated with enabling ASSERT()s.  This patch clarifies things
by cleanly breaking the two subsystem apart.  The result of this
is the following behavior.

--enable-debug      - Enable/disable code wrapped in ASSERT()s.
--disable-debug       ASSERT()s are used to check invariants and
                      are never required for correct operation.
                      They are disabled by default because they
                      may impact performance.

--enable-debug-log  - Enable/disable the debug log infrastructure.
--disable-debug-log   This infrastructure allows the spl code and
                      its consumer to log messages to an in-kernel
                      log.  The granularity of the logging can be
                      controlled by a debug mask.  By default the
                      mask disables most debug messages resulting
                      in a negligible performance impact.  Because
                      of this the debug log is enabled by default.

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>

diff --git a/config/spl-build.m4 b/config/spl-build.m4
index a20ee38d1e338af840210de1f7b49c9e8784e772..205eb6bc5172a4fd06a7872297404bf8b5403e7e 100644 (file)
--- a/config/spl-build.m4
+++ b/config/spl-build.m4
@@ -19,6 +19,7 @@ AC_DEFUN([SPL_AC_CONFIG_KERNEL], [
        AC_SUBST(KERNELCPPFLAGS)
 
        SPL_AC_DEBUG
+       SPL_AC_DEBUG_LOG
        SPL_AC_DEBUG_KMEM
        SPL_AC_DEBUG_KMEM_TRACKING
        SPL_AC_ATOMIC_SPINLOCK
@@ -485,6 +486,33 @@ AC_DEFUN([SPL_AC_DEBUG], [
        AC_MSG_RESULT([$enable_debug])
 ])
 
+dnl #
+dnl # Enabled by default it provides a basic debug log infrastructure.
+dnl # Each subsystem registers itself with a name and logs messages
+dnl # using predefined types.  If the debug mask it set to allow the
+dnl # message type it will be written to the internal log.  The log
+dnl # can be dumped to a file by echoing 1 to the 'dump' proc entry,
+dnl # after dumping the log it must be decoded using the spl utility.
+dnl #
+dnl # echo 1 >/proc/sys/kernel/spl/debug/dump
+dnl # spl /tmp/spl-log.xxx.yyy /tmp/spl-log.xxx.yyy.txt
+dnl #
+AC_DEFUN([SPL_AC_DEBUG_LOG], [
+       AC_ARG_ENABLE([debug-log],
+               [AS_HELP_STRING([--enable-debug-log],
+               [Enable basic debug logging @<:@default=yes@:>@])],
+               [],
+               [enable_debug_log=yes])
+
+       AS_IF([test "x$enable_debug_log" = xyes],
+               [AC_DEFINE([DEBUG_LOG], [1],
+               [Define to 1 to enable basic debug logging])
+               KERNELCPPFLAGS="${KERNELCPPFLAGS} -DDEBUG_LOG"])
+
+       AC_MSG_CHECKING([whether basic debug logging is enabled])
+       AC_MSG_RESULT([$enable_debug_log])
+])
+
 dnl #
 dnl # Enabled by default it provides a minimal level of memory tracking.
 dnl # A total count of bytes allocated is kept for each alloc and free.

diff --git a/configure b/configure
index 7b93f564f5a7f6f84677c335a7b33d7451a923ee..3b3439ad19325c73f4b524b6fe3551aa826db149 100755 (executable)
--- a/configure
+++ b/configure
@@ -961,6 +961,7 @@ with_config
 with_linux
 with_linux_obj
 enable_debug
+enable_debug_log
 enable_debug_kmem
 enable_debug_kmem_tracking
 enable_atomic_spinlocks
@@ -1615,6 +1616,7 @@ Optional Features:
                           optimize for fast installation [default=yes]
   --disable-libtool-lock  avoid locking (might break parallel builds)
   --enable-debug          Enable generic debug support [default=no]
+  --enable-debug-log      Enable basic debug logging [default=yes]
   --enable-debug-kmem     Enable basic kmem accounting [default=yes]
   --enable-debug-kmem-tracking
                           Enable detailed kmem tracking [default=no]
@@ -4783,13 +4785,13 @@ if test "${lt_cv_nm_interface+set}" = set; then
 else
   lt_cv_nm_interface="BSD nm"
   echo "int some_variable = 0;" > conftest.$ac_ext
-  (eval echo "\"\$as_me:4786: $ac_compile\"" >&5)
+  (eval echo "\"\$as_me:4788: $ac_compile\"" >&5)
   (eval "$ac_compile" 2>conftest.err)
   cat conftest.err >&5
-  (eval echo "\"\$as_me:4789: $NM \\\"conftest.$ac_objext\\\"\"" >&5)
+  (eval echo "\"\$as_me:4791: $NM \\\"conftest.$ac_objext\\\"\"" >&5)
   (eval "$NM \"conftest.$ac_objext\"" 2>conftest.err > conftest.out)
   cat conftest.err >&5
-  (eval echo "\"\$as_me:4792: output\"" >&5)
+  (eval echo "\"\$as_me:4794: output\"" >&5)
   cat conftest.out >&5
   if $GREP 'External.*some_variable' conftest.out > /dev/null; then
     lt_cv_nm_interface="MS dumpbin"
@@ -5995,7 +5997,7 @@ ia64-*-hpux*)
   ;;
 *-*-irix6*)
   # Find out which ABI we are using.
-  echo '#line 5998 "configure"' > conftest.$ac_ext
+  echo '#line 6000 "configure"' > conftest.$ac_ext
   if { (eval echo "$as_me:$LINENO: \"$ac_compile\"") >&5
   (eval $ac_compile) 2>&5
   ac_status=$?
@@ -7848,11 +7850,11 @@ else
    -e 's:.*FLAGS}\{0,1\} :&$lt_compiler_flag :; t' \
    -e 's: [^ ]*conftest\.: $lt_compiler_flag&:; t' \
    -e 's:$: $lt_compiler_flag:'`
-   (eval echo "\"\$as_me:7851: $lt_compile\"" >&5)
+   (eval echo "\"\$as_me:7853: $lt_compile\"" >&5)
    (eval "$lt_compile" 2>conftest.err)
    ac_status=$?
    cat conftest.err >&5
-   echo "$as_me:7855: \$? = $ac_status" >&5
+   echo "$as_me:7857: \$? = $ac_status" >&5
    if (exit $ac_status) && test -s "$ac_outfile"; then
      # The compiler can only warn and ignore the option if not recognized
      # So say no if there are warnings other than the usual output.
@@ -8187,11 +8189,11 @@ else
    -e 's:.*FLAGS}\{0,1\} :&$lt_compiler_flag :; t' \
    -e 's: [^ ]*conftest\.: $lt_compiler_flag&:; t' \
    -e 's:$: $lt_compiler_flag:'`
-   (eval echo "\"\$as_me:8190: $lt_compile\"" >&5)
+   (eval echo "\"\$as_me:8192: $lt_compile\"" >&5)
    (eval "$lt_compile" 2>conftest.err)
    ac_status=$?
    cat conftest.err >&5
-   echo "$as_me:8194: \$? = $ac_status" >&5
+   echo "$as_me:8196: \$? = $ac_status" >&5
    if (exit $ac_status) && test -s "$ac_outfile"; then
      # The compiler can only warn and ignore the option if not recognized
      # So say no if there are warnings other than the usual output.
@@ -8292,11 +8294,11 @@ else
    -e 's:.*FLAGS}\{0,1\} :&$lt_compiler_flag :; t' \
    -e 's: [^ ]*conftest\.: $lt_compiler_flag&:; t' \
    -e 's:$: $lt_compiler_flag:'`
-   (eval echo "\"\$as_me:8295: $lt_compile\"" >&5)
+   (eval echo "\"\$as_me:8297: $lt_compile\"" >&5)
    (eval "$lt_compile" 2>out/conftest.err)
    ac_status=$?
    cat out/conftest.err >&5
-   echo "$as_me:8299: \$? = $ac_status" >&5
+   echo "$as_me:8301: \$? = $ac_status" >&5
    if (exit $ac_status) && test -s out/conftest2.$ac_objext
    then
      # The compiler can only warn and ignore the option if not recognized
@@ -8347,11 +8349,11 @@ else
    -e 's:.*FLAGS}\{0,1\} :&$lt_compiler_flag :; t' \
    -e 's: [^ ]*conftest\.: $lt_compiler_flag&:; t' \
    -e 's:$: $lt_compiler_flag:'`
-   (eval echo "\"\$as_me:8350: $lt_compile\"" >&5)
+   (eval echo "\"\$as_me:8352: $lt_compile\"" >&5)
    (eval "$lt_compile" 2>out/conftest.err)
    ac_status=$?
    cat out/conftest.err >&5
-   echo "$as_me:8354: \$? = $ac_status" >&5
+   echo "$as_me:8356: \$? = $ac_status" >&5
    if (exit $ac_status) && test -s out/conftest2.$ac_objext
    then
      # The compiler can only warn and ignore the option if not recognized
@@ -11150,7 +11152,7 @@ else
   lt_dlunknown=0; lt_dlno_uscore=1; lt_dlneed_uscore=2
   lt_status=$lt_dlunknown
   cat > conftest.$ac_ext <<_LT_EOF
-#line 11153 "configure"
+#line 11155 "configure"
 #include "confdefs.h"
 
 #if HAVE_DLFCN_H
@@ -11246,7 +11248,7 @@ else
   lt_dlunknown=0; lt_dlno_uscore=1; lt_dlneed_uscore=2
   lt_status=$lt_dlunknown
   cat > conftest.$ac_ext <<_LT_EOF
-#line 11249 "configure"
+#line 11251 "configure"
 #include "confdefs.h"
 
 #if HAVE_DLFCN_H
@@ -11980,6 +11982,30 @@ fi
 $as_echo "$enable_debug" >&6; }
 
 
+       # Check whether --enable-debug-log was given.
+if test "${enable_debug_log+set}" = set; then
+  enableval=$enable_debug_log;
+else
+  enable_debug_log=yes
+fi
+
+
+       if test "x$enable_debug_log" = xyes; then
+
+cat >>confdefs.h <<\_ACEOF
+#define DEBUG_LOG 1
+_ACEOF
+
+               KERNELCPPFLAGS="${KERNELCPPFLAGS} -DDEBUG_LOG"
+fi
+
+
+       { $as_echo "$as_me:$LINENO: checking whether basic debug logging is enabled" >&5
+$as_echo_n "checking whether basic debug logging is enabled... " >&6; }
+       { $as_echo "$as_me:$LINENO: result: $enable_debug_log" >&5
+$as_echo "$enable_debug_log" >&6; }
+
+
        # Check whether --enable-debug-kmem was given.
 if test "${enable_debug_kmem+set}" = set; then
   enableval=$enable_debug_kmem;
@@ -16359,6 +16385,30 @@ fi
 $as_echo "$enable_debug" >&6; }
 
 
+       # Check whether --enable-debug-log was given.
+if test "${enable_debug_log+set}" = set; then
+  enableval=$enable_debug_log;
+else
+  enable_debug_log=yes
+fi
+
+
+       if test "x$enable_debug_log" = xyes; then
+
+cat >>confdefs.h <<\_ACEOF
+#define DEBUG_LOG 1
+_ACEOF
+
+               KERNELCPPFLAGS="${KERNELCPPFLAGS} -DDEBUG_LOG"
+fi
+
+
+       { $as_echo "$as_me:$LINENO: checking whether basic debug logging is enabled" >&5
+$as_echo_n "checking whether basic debug logging is enabled... " >&6; }
+       { $as_echo "$as_me:$LINENO: result: $enable_debug_log" >&5
+$as_echo "$enable_debug_log" >&6; }
+
+
        # Check whether --enable-debug-kmem was given.
 if test "${enable_debug_kmem+set}" = set; then
   enableval=$enable_debug_kmem;

diff --git a/include/spl-debug.h b/include/spl-debug.h
index 1e08e77bc2032eb2d84806f0727d9bba0005b3bd..98164966c308f8befddc98e3dc5d713116a4fc45 100644 (file)
--- a/include/spl-debug.h
+++ b/include/spl-debug.h
@@ -43,6 +43,7 @@
 #define _SPL_DEBUG_INTERNAL_H
 
 #include <linux/limits.h>
+#include <linux/sched.h>
 
 #define SS_UNDEFINED   0x00000001
 #define SS_ATOMIC      0x00000002
@@ -86,21 +87,8 @@
 #define SD_OTHER       0x00000100
 #define SD_CANTMASK    (SD_ERROR | SD_EMERG | SD_WARNING | SD_CONSOLE)
 
-#ifdef NDEBUG /* Debugging Disabled */
-
-#define SDEBUG(mask, fmt, a...)                ((void)0)
-#define SDEBUG_LIMIT(x, y, fmt, a...)  ((void)0)
-#define SWARN(fmt, a...)               ((void)0)
-#define SERROR(fmt, a...)              ((void)0)
-#define SEMERG(fmt, a...)              ((void)0)
-#define SCONSOLE(mask, fmt, a...)      ((void)0)
-
-#define SENTRY                         ((void)0)
-#define SEXIT                          ((void)0)
-#define SRETURN(x)                     return (x)
-#define SGOTO(x, y)                    { ((void)(y)); goto x; }
-
-#else /* Debugging Enabled */
+/* Debug log support enabled */
+#ifdef DEBUG_LOG
 
 #define __SDEBUG(cdls, subsys, mask, format, a...)                     \
 do {                                                                   \
@@ -149,8 +137,6 @@ do {                                                                        \
        goto label;                                                     \
 } while (0)
 
-#endif /* NDEBUG */
-
 typedef struct {
        unsigned long   cdls_next;
        int             cdls_count;
@@ -183,10 +169,46 @@ extern int spl_debug_set_mb(int mb);
 extern int spl_debug_get_mb(void);
 extern int spl_debug_dumplog(int flags);
 extern void spl_debug_dumpstack(struct task_struct *tsk);
+extern void spl_debug_bug(char *file, const char *fn, const int line, int fl);
+extern int spl_debug_msg(void *arg, int subsys, int mask, const char *file,
+    const char *fn, const int line, const char *format, ...);
 extern int spl_debug_clear_buffer(void);
 extern int spl_debug_mark_buffer(char *text);
 
 int spl_debug_init(void);
 void spl_debug_fini(void);
 
+/* Debug log support disabled */
+#else /* DEBUG_LOG */
+
+#define SDEBUG(mask, fmt, a...)                ((void)0)
+#define SDEBUG_LIMIT(x, y, fmt, a...)  ((void)0)
+#define SWARN(fmt, a...)               ((void)0)
+#define SERROR(fmt, a...)              ((void)0)
+#define SEMERG(fmt, a...)              ((void)0)
+#define SCONSOLE(mask, fmt, a...)      ((void)0)
+
+#define SENTRY                         ((void)0)
+#define SEXIT                          ((void)0)
+#define SRETURN(x)                     return (x)
+#define SGOTO(x, y)                    { ((void)(y)); goto x; }
+
+static inline int spl_debug_init(void) { return (0); }
+static inline void spl_debug_fini(void) { return; }
+
+static inline void
+spl_debug_bug(char *file, const char *fn, const int line, int fl)
+{
+       return;
+}
+
+static inline int
+spl_debug_msg(void *arg, int subsys, int mask, const char *file,
+    const char *fn, const int line, const char *format, ...)
+{
+       return (0);
+}
+
+#endif /* DEBUG_LOG */
+
 #endif /* SPL_DEBUG_INTERNAL_H */

diff --git a/include/sys/debug.h b/include/sys/debug.h
index fbf15143f8097db5fcbc17dcd23d920bcf119b30..271dbc21093798d53cd4962a3fa0a62b7a1b9ded 100644 (file)
--- a/include/sys/debug.h
+++ b/include/sys/debug.h
@@ -44,6 +44,8 @@
 #ifndef _SPL_DEBUG_H
 #define _SPL_DEBUG_H
 
+#include <spl-debug.h>
+
 #ifdef NDEBUG /* Debugging Disabled */
 
 /* Define SPL_DEBUG_STR to make clear which ASSERT definitions are used */
@@ -137,9 +139,4 @@ do {                                                                        \
 #define VERIFY(x)      ASSERT(x)
 
 #endif /* NDEBUG */
-
-extern void spl_debug_bug(char *file, const char *fn, const int line, int fl);
-extern int spl_debug_msg(void *arg, int subsys, int mask, const char *file,
-    const char *fn, const int line, const char *format, ...);
-
 #endif /* SPL_DEBUG_H */

diff --git a/module/spl/spl-debug.c b/module/spl/spl-debug.c
index 0dbbb5a7cababc06e00d02fb7421b559543125cd..4bcc34a8ef62ebce56706c64d83077b93ce3400a 100644 (file)
--- a/module/spl/spl-debug.c
+++ b/module/spl/spl-debug.c
@@ -47,6 +47,9 @@
 
 #define SS_DEBUG_SUBSYS SS_DEBUG
 
+/* Debug log support enabled */
+#ifdef DEBUG_LOG
+
 unsigned long spl_debug_subsys = ~0;
 EXPORT_SYMBOL(spl_debug_subsys);
 module_param(spl_debug_subsys, ulong, 0644);
@@ -1248,3 +1251,5 @@ spl_debug_fini(void)
 {
         trace_fini();
 }
+
+#endif /* DEBUG_LOG */

diff --git a/module/spl/spl-err.c b/module/spl/spl-err.c
index 200028f3bb690cc1765196191c3b1f9e14f328c0..c837d1eaaac5cc1eda99e047da72abca3ce30b25 100644 (file)
--- a/module/spl/spl-err.c
+++ b/module/spl/spl-err.c
@@ -34,7 +34,7 @@
 
 #define SS_DEBUG_SUBSYS SS_GENERIC
 
-#ifndef NDEBUG
+#ifdef DEBUG_LOG
 static char ce_prefix[CE_IGNORE][10] = { "", "NOTICE: ", "WARNING: ", "" };
 static char ce_suffix[CE_IGNORE][2] = { "", "\n", "\n", "" };
 #endif

diff --git a/module/spl/spl-kmem.c b/module/spl/spl-kmem.c
index 5a6011ad61a195e5b5af9e8fa7950f88c56403bf..446dab128f1392a694f4c6d5dfb9a3c318901282 100644 (file)
--- a/module/spl/spl-kmem.c
+++ b/module/spl/spl-kmem.c
@@ -672,7 +672,7 @@ kmem_alloc_debug(size_t size, int flags, const char *func, int line,
                    "large kmem_alloc(%llu, 0x%x) at %s:%d (%lld/%llu)\n",
                    (unsigned long long) size, flags, func, line,
                    kmem_alloc_used_read(), kmem_alloc_max);
-               spl_debug_dumpstack(NULL);
+               dump_stack();
        }
 
        /* Use the correct allocator */

diff --git a/module/spl/spl-proc.c b/module/spl/spl-proc.c
index 745b1071417f7458d2b82f1b36f6b6cbd65fe34b..8149143ae247e02ffb9dc84eb3f375caac3cdfb0 100644 (file)
--- a/module/spl/spl-proc.c
+++ b/module/spl/spl-proc.c
@@ -125,6 +125,7 @@ enum {
        CTL_HW_SERIAL,                  /* Hardware serial number from hostid */
        CTL_KALLSYMS,                   /* Address of kallsyms_lookup_name */
 
+#ifdef DEBUG_LOG
        CTL_DEBUG_SUBSYS,               /* Debug subsystem */
        CTL_DEBUG_MASK,                 /* Debug mask */
        CTL_DEBUG_PRINTK,               /* Force all messages to console */
@@ -136,6 +137,7 @@ enum {
        CTL_DEBUG_DUMP,                 /* Dump debug buffer to file */
        CTL_DEBUG_FORCE_BUG,            /* Hook to force a BUG */
        CTL_DEBUG_STACK_SIZE,           /* Max observed stack size */
+#endif
 
        CTL_CONSOLE_RATELIMIT,          /* Ratelimit console messages */
        CTL_CONSOLE_MAX_DELAY_CS,       /* Max delay which we skip messages */
@@ -221,6 +223,7 @@ proc_copyout_string(char *ubuffer, int ubuffer_size,
         return size;
 }
 
+#ifdef DEBUG_LOG
 SPL_PROC_HANDLER(proc_dobitmasks)
 {
         unsigned long *mask = table->data;
@@ -407,6 +410,7 @@ SPL_PROC_HANDLER(proc_console_backoff)
 
         SRETURN(rc);
 }
+#endif /* DEBUG_LOG */
 
 #ifdef DEBUG_KMEM
 SPL_PROC_HANDLER(proc_domemused)
@@ -716,6 +720,7 @@ static struct file_operations proc_slab_operations = {
 };
 #endif /* DEBUG_KMEM */
 
+#ifdef DEBUG_LOG
 static struct ctl_table spl_debug_table[] = {
         {
                 CTL_NAME    (CTL_DEBUG_SUBSYS)
@@ -829,6 +834,7 @@ static struct ctl_table spl_debug_table[] = {
         },
        {0},
 };
+#endif /* DEBUG_LOG */
 
 static struct ctl_table spl_vm_table[] = {
         {
@@ -1056,12 +1062,14 @@ static struct ctl_table spl_table[] = {
                 .proc_handler = &proc_dokallsyms_lookup_name,
         },
 #endif
+#ifdef DEBUG_LOG
        {
                CTL_NAME    (CTL_SPL_DEBUG)
                .procname = "debug",
                .mode     = 0555,
                .child    = spl_debug_table,
        },
+#endif
        {
                CTL_NAME    (CTL_SPL_VM)
                .procname = "vm",

diff --git a/scripts/check.sh b/scripts/check.sh
index 8c0e0c5cbe2fcbb2b97e5e75c157abfbdfef5ff1..4334ff3a52c465cb935200e9ba78e6ba51a1b142 100755 (executable)
--- a/scripts/check.sh
+++ b/scripts/check.sh
@@ -65,9 +65,8 @@ fi
 /sbin/modprobe zlib_inflate &>/dev/null
 /sbin/modprobe zlib_deflate &>/dev/null
 
-spl_module_params="spl_debug_mask=0xffffffff spl_debug_subsys=0xffffffff"
 echo "Loading ${spl_module}"
-/sbin/insmod ${spl_module} ${spl_module_params} || die "Failed to load ${spl_module}"
+/sbin/insmod ${spl_module} || die "Failed to load ${spl_module}"
 
 echo "Loading ${splat_module}"
 /sbin/insmod ${splat_module} || die "Unable to load ${splat_module}"

diff --git a/spl_config.h.in b/spl_config.h.in
index 847da2137a797b3c84b0fe571b3d44ebb8da3967..05dcdc5045202bfcd399ed6a02b5d5dadfe55e07 100644 (file)
--- a/spl_config.h.in
+++ b/spl_config.h.in
@@ -9,6 +9,9 @@
 /* Define to 1 to enable detailed kmem tracking */
 #undef DEBUG_KMEM_TRACKING
 
+/* Define to 1 to enable basic debug logging */
+#undef DEBUG_LOG
+
 /* invalidate_inodes() wants 2 args */
 #undef HAVE_2ARGS_INVALIDATE_INODES