From d7e398ce1a3e6f9c705af43955a684685a798c32 Mon Sep 17 00:00:00 2001 From: Brian Behlendorf Date: Fri, 20 Jan 2012 15:02:57 -0800 Subject: [PATCH] Cleanup ZFS debug infrastructure Historically the internal zfs debug infrastructure has been scattered throughout the code. Since we expect to start making more use of this code this patch performs some cleanup. * Consolidate the zfs debug infrastructure in the zfs_debug.[ch] files. This includes moving the zfs_flags and zfs_recover variables, plus moving the zfs_panic_recover() function. * Remove the existing unused functionality in zfs_debug.c and replace it with code which correctly utilized the spl logging infrastructure. * Remove the __dprintf() function from zfs_ioctl.c. This is dead code, the dprintf() functionality in the kernel relies on the spl log support. * Remove dprintf() from hdr_recl(). This wasn't particularly useful and was missing the required format specifier anyway. * Subsequent patches should unify the dprintf() and zfs_dbgmsg() functions. Signed-off-by: Brian Behlendorf --- include/sys/zfs_context.h | 5 +- include/sys/zfs_debug.h | 58 +++++++++------------- lib/libzpool/kernel.c | 4 -- module/zfs/arc.c | 1 - module/zfs/spa_misc.c | 28 ----------- module/zfs/zfs_debug.c | 100 +++++++++++++++++--------------------- module/zfs/zfs_ioctl.c | 36 -------------- 7 files changed, 68 insertions(+), 164 deletions(-) diff --git a/include/sys/zfs_context.h b/include/sys/zfs_context.h index 4abafcc6f..e4af6fc37 100644 --- a/include/sys/zfs_context.h +++ b/include/sys/zfs_context.h @@ -134,10 +134,9 @@ extern int aok; * ZFS debugging */ -#ifdef ZFS_DEBUG extern void dprintf_setup(int *argc, char **argv); -#endif /* ZFS_DEBUG */ - +extern void __dprintf(const char *file, const char *func, + int line, const char *fmt, ...); extern void cmn_err(int, const char *, ...); extern void vcmn_err(int, const char *, __va_list); extern void panic(const char *, ...); diff --git a/include/sys/zfs_debug.h b/include/sys/zfs_debug.h index f08d7cd2b..e83b66147 100644 --- a/include/sys/zfs_debug.h +++ b/include/sys/zfs_debug.h @@ -25,10 +25,6 @@ #ifndef _SYS_ZFS_DEBUG_H #define _SYS_ZFS_DEBUG_H -#ifdef __cplusplus -extern "C" { -#endif - #ifndef TRUE #define TRUE 1 #endif @@ -38,14 +34,14 @@ extern "C" { #endif /* - * ZFS debugging + * ZFS debugging - Always enabled for user space builds. */ - #if defined(DEBUG) || !defined(_KERNEL) #define ZFS_DEBUG #endif extern int zfs_flags; +extern int zfs_recover; #define ZFS_DEBUG_DPRINTF 0x0001 #define ZFS_DEBUG_DBUF_VERIFY 0x0002 @@ -53,43 +49,33 @@ extern int zfs_flags; #define ZFS_DEBUG_SNAPNAMES 0x0008 #define ZFS_DEBUG_MODIFY 0x0010 -#ifdef ZFS_DEBUG -#if defined(_KERNEL) && defined(HAVE_SPL) /* - * Log ZFS debug messages as the spl SS_USER1 subsystem. + * Always log zfs debug messages to the spl debug subsystem as SS_USER1. + * When the SPL is configured with debugging enabled these messages will + * appear in the internal spl debug log, otherwise they are a no-op. */ +#if defined(_KERNEL) + #include +#define dprintf(...) \ + if (zfs_flags & ZFS_DEBUG_DPRINTF) \ + __SDEBUG(NULL, SS_USER1, SD_DPRINTF, __VA_ARGS__) -#ifdef SS_DEBUG_SUBSYS -#undef SS_DEBUG_SUBSYS -#endif -#define SS_DEBUG_SUBSYS SS_USER1 -#define dprintf(...) SDEBUG_LIMIT(SD_DPRINTF, __VA_ARGS__) +/* + * When zfs is running is user space the debugging is always enabled. + * The messages will be printed using the __dprintf() function and + * filtered based on the zfs_flags variable. + */ #else -extern void __dprintf(const char *file, const char *func, - int line, const char *fmt, ...); -#define dprintf(...) \ - if (zfs_flags & ZFS_DEBUG_DPRINTF) \ +#define dprintf(...) \ + if (zfs_flags & ZFS_DEBUG_DPRINTF) \ __dprintf(__FILE__, __func__, __LINE__, __VA_ARGS__) -#endif /* _KERNEL && HAVE_SPL */ -#else -#define dprintf(...) ((void)0) -#endif /* ZFS_DEBUG */ -extern void zfs_panic_recover(const char *fmt, ...); +#endif /* _KERNEL */ -typedef struct zfs_dbgmsg { - list_node_t zdm_node; - time_t zdm_timestamp; - char zdm_msg[1]; /* variable length allocation */ -} zfs_dbgmsg_t; - -extern void zfs_dbgmsg_init(void); -extern void zfs_dbgmsg_fini(void); -extern void zfs_dbgmsg(const char *fmt, ...); - -#ifdef __cplusplus -} -#endif +void zfs_panic_recover(const char *fmt, ...); +#define zfs_dbgmsg(...) dprintf(__VA_ARGS__) +void zfs_dbgmsg_init(void); +void zfs_dbgmsg_fini(void); #endif /* _SYS_ZFS_DEBUG_H */ diff --git a/lib/libzpool/kernel.c b/lib/libzpool/kernel.c index 002276a90..69fbd44cd 100644 --- a/lib/libzpool/kernel.c +++ b/lib/libzpool/kernel.c @@ -700,8 +700,6 @@ fop_getattr(vnode_t *vp, vattr_t *vap) return (0); } -#ifdef ZFS_DEBUG - /* * ========================================================================= * Figure out which debugging statements to print @@ -814,8 +812,6 @@ __dprintf(const char *file, const char *func, int line, const char *fmt, ...) } } -#endif /* ZFS_DEBUG */ - /* * ========================================================================= * cmn_err() and panic() diff --git a/module/zfs/arc.c b/module/zfs/arc.c index 95d14a9e7..2220c4d9d 100644 --- a/module/zfs/arc.c +++ b/module/zfs/arc.c @@ -885,7 +885,6 @@ buf_dest(void *vbuf, void *unused) static void hdr_recl(void *unused) { - dprintf("hdr_recl called\n"); /* * umem calls the reclaim func when we destroy the buf cache, * which is after we do arc_fini(). diff --git a/module/zfs/spa_misc.c b/module/zfs/spa_misc.c index e4e0c35f0..1016ac7be 100644 --- a/module/zfs/spa_misc.c +++ b/module/zfs/spa_misc.c @@ -234,21 +234,6 @@ static avl_tree_t spa_l2cache_avl; kmem_cache_t *spa_buffer_pool; int spa_mode_global; -#ifdef ZFS_DEBUG -/* Everything except dprintf is on by default in debug builds */ -int zfs_flags = ~ZFS_DEBUG_DPRINTF; -#else -int zfs_flags = 0; -#endif - -/* - * zfs_recover can be set to nonzero to attempt to recover from - * otherwise-fatal errors, typically caused by on-disk corruption. When - * set, calls to zfs_panic_recover() will turn into warning messages. - */ -int zfs_recover = 0; - - /* * ========================================================================== * SPA config locking @@ -1217,16 +1202,6 @@ spa_freeze(spa_t *spa) txg_wait_synced(spa_get_dsl(spa), freeze_txg); } -void -zfs_panic_recover(const char *fmt, ...) -{ - va_list adx; - - va_start(adx, fmt); - vcmn_err(zfs_recover ? CE_WARN : CE_PANIC, fmt, adx); - va_end(adx); -} - /* * This is a stripped-down version of strtoull, suitable only for converting * lowercase hexidecimal numbers that don't overflow. @@ -1765,7 +1740,4 @@ EXPORT_SYMBOL(spa_writeable); EXPORT_SYMBOL(spa_mode); EXPORT_SYMBOL(spa_namespace_lock); - -module_param(zfs_recover, int, 0644); -MODULE_PARM_DESC(zfs_recover, "Set to attempt to recover from fatal errors"); #endif diff --git a/module/zfs/zfs_debug.c b/module/zfs/zfs_debug.c index d0f411a99..f4b5e6fa1 100644 --- a/module/zfs/zfs_debug.c +++ b/module/zfs/zfs_debug.c @@ -24,72 +24,60 @@ #include -list_t zfs_dbgmsgs; -int zfs_dbgmsg_size; -kmutex_t zfs_dbgmsgs_lock; -int zfs_dbgmsg_maxsize = 1<<20; /* 1MB */ +/* + * Enable various debugging features. + */ +int zfs_flags = 0; +/* + * zfs_recover can be set to nonzero to attempt to recover from + * otherwise-fatal errors, typically caused by on-disk corruption. When + * set, calls to zfs_panic_recover() will turn into warning messages. + */ +int zfs_recover = 0; + + +void +zfs_panic_recover(const char *fmt, ...) +{ + va_list adx; + + va_start(adx, fmt); + vcmn_err(zfs_recover ? CE_WARN : CE_PANIC, fmt, adx); + va_end(adx); +} + +/* + * Debug logging is enabled by default for production kernel builds. + * The overhead for this is negligible and the logs can be valuable when + * debugging. For non-production user space builds all debugging except + * logging is enabled since performance is no longer a concern. + */ void zfs_dbgmsg_init(void) { - list_create(&zfs_dbgmsgs, sizeof (zfs_dbgmsg_t), - offsetof(zfs_dbgmsg_t, zdm_node)); - mutex_init(&zfs_dbgmsgs_lock, NULL, MUTEX_DEFAULT, NULL); + if (zfs_flags == 0) { +#if defined(_KERNEL) + zfs_flags = ZFS_DEBUG_DPRINTF; + spl_debug_mask |= SD_DPRINTF; + spl_debug_subsys |= SS_USER1; +#else + zfs_flags = ~ZFS_DEBUG_DPRINTF; +#endif /* _KERNEL */ + } } void zfs_dbgmsg_fini(void) { - zfs_dbgmsg_t *zdm; - - while ((zdm = list_remove_head(&zfs_dbgmsgs)) != NULL) { - int size = sizeof (zfs_dbgmsg_t) + strlen(zdm->zdm_msg); - kmem_free(zdm, size); - zfs_dbgmsg_size -= size; - } - mutex_destroy(&zfs_dbgmsgs_lock); - ASSERT3U(zfs_dbgmsg_size, ==, 0); + return; } -/* - * Print these messages by running: - * echo ::zfs_dbgmsg | mdb -k - * - * Monitor these messages by running: - * dtrace -q -n 'zfs-dbgmsg{printf("%s\n", stringof(arg0))}' - */ -void -zfs_dbgmsg(const char *fmt, ...) -{ - int size; - va_list adx; - zfs_dbgmsg_t *zdm; - va_start(adx, fmt); - size = vsnprintf(NULL, 0, fmt, adx); - va_end(adx); +#if defined(_KERNEL) +module_param(zfs_flags, int, 0644); +MODULE_PARM_DESC(zfs_flags, "Set additional debugging flags"); - /* - * There is one byte of string in sizeof (zfs_dbgmsg_t), used - * for the terminating null. - */ - zdm = kmem_alloc(sizeof (zfs_dbgmsg_t) + size, KM_SLEEP); - zdm->zdm_timestamp = gethrestime_sec(); - - va_start(adx, fmt); - (void) vsnprintf(zdm->zdm_msg, size + 1, fmt, adx); - va_end(adx); - - DTRACE_PROBE1(zfs__dbgmsg, char *, zdm->zdm_msg); - - mutex_enter(&zfs_dbgmsgs_lock); - list_insert_tail(&zfs_dbgmsgs, zdm); - zfs_dbgmsg_size += sizeof (zfs_dbgmsg_t) + size; - while (zfs_dbgmsg_size > zfs_dbgmsg_maxsize) { - zdm = list_remove_head(&zfs_dbgmsgs); - size = sizeof (zfs_dbgmsg_t) + strlen(zdm->zdm_msg); - kmem_free(zdm, size); - zfs_dbgmsg_size -= size; - } - mutex_exit(&zfs_dbgmsgs_lock); -} +module_param(zfs_recover, int, 0644); +MODULE_PARM_DESC(zfs_recover, "Set to attempt to recover from fatal errors"); +#endif /* _KERNEL */ diff --git a/module/zfs/zfs_ioctl.c b/module/zfs/zfs_ioctl.c index c8ff03595..532f17aa1 100644 --- a/module/zfs/zfs_ioctl.c +++ b/module/zfs/zfs_ioctl.c @@ -119,42 +119,6 @@ static int zfs_fill_zplprops_root(uint64_t, nvlist_t *, nvlist_t *, boolean_t *); int zfs_set_prop_nvlist(const char *, zprop_source_t, nvlist_t *, nvlist_t **); -/* _NOTE(PRINTFLIKE(4)) - this is printf-like, but lint is too whiney */ -void -__dprintf(const char *file, const char *func, int line, const char *fmt, ...) -{ - const char *newfile; - char buf[512]; - va_list adx; - - /* - * Get rid of annoying "../common/" prefix to filename. - */ - newfile = strrchr(file, '/'); - if (newfile != NULL) { - newfile = newfile + 1; /* Get rid of leading / */ - } else { - newfile = file; - } - - va_start(adx, fmt); - (void) vsnprintf(buf, sizeof (buf), fmt, adx); - va_end(adx); - - /* - * To get this data, use the zfs-dprintf probe as so: - * dtrace -q -n 'zfs-dprintf \ - * /stringof(arg0) == "dbuf.c"/ \ - * {printf("%s: %s", stringof(arg1), stringof(arg3))}' - * arg0 = file name - * arg1 = function name - * arg2 = line number - * arg3 = message - */ - DTRACE_PROBE4(zfs__dprintf, - char *, newfile, char *, func, int, line, char *, buf); -} - static void history_str_free(char *buf) {