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>
This commit is contained in:
Brian Behlendorf 2012-01-20 16:39:12 -08:00
parent 3c6ed5410b
commit 4b2220f0b9
10 changed files with 152 additions and 40 deletions

View File

@ -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.

78
configure vendored
View File

@ -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;

View File

@ -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 */

View File

@ -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 */

View File

@ -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 */

View File

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

View File

@ -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 */

View File

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

View File

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

View File

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