diff options
Diffstat (limited to 'module/zfs/zfs_debug.c')
| -rw-r--r-- | module/zfs/zfs_debug.c | 223 |
1 files changed, 170 insertions, 53 deletions
diff --git a/module/zfs/zfs_debug.c b/module/zfs/zfs_debug.c index e835397e9..2770359c8 100644 --- a/module/zfs/zfs_debug.c +++ b/module/zfs/zfs_debug.c @@ -24,11 +24,91 @@ */ #include <sys/zfs_context.h> +#include <sys/kstat.h> list_t zfs_dbgmsgs; -int zfs_dbgmsg_size; +int zfs_dbgmsg_size = 0; kmutex_t zfs_dbgmsgs_lock; int zfs_dbgmsg_maxsize = 4<<20; /* 4MB */ +kstat_t *zfs_dbgmsg_kstat; + +/* + * By default only enable the internal ZFS debug messages when running + * in userspace (ztest). The kernel log must be manually enabled. + * + * # Enable the kernel debug message log. + * echo 1 > /sys/module/zfs/parameters/zfs_dbgmsg_enable + * + * # Clear the kernel debug message log. + * echo 0 >/proc/spl/kstat/zfs/dbgmsg + */ +#if defined(_KERNEL) +int zfs_dbgmsg_enable = 0; +#else +int zfs_dbgmsg_enable = 1; +#endif + +static int +zfs_dbgmsg_headers(char *buf, size_t size) +{ + (void) snprintf(buf, size, "%-12s %-8s\n", "timestamp", "message"); + + return (0); +} + +static int +zfs_dbgmsg_data(char *buf, size_t size, void *data) +{ + zfs_dbgmsg_t *zdm = (zfs_dbgmsg_t *)data; + + (void) snprintf(buf, size, "%-12llu %-s\n", + (u_longlong_t) zdm->zdm_timestamp, zdm->zdm_msg); + + return (0); +} + +static void * +zfs_dbgmsg_addr(kstat_t *ksp, loff_t n) +{ + zfs_dbgmsg_t *zdm = (zfs_dbgmsg_t *)ksp->ks_private; + + ASSERT(MUTEX_HELD(&zfs_dbgmsgs_lock)); + + if (n == 0) + ksp->ks_private = list_head(&zfs_dbgmsgs); + else if (zdm) + ksp->ks_private = list_next(&zfs_dbgmsgs, zdm); + + return (ksp->ks_private); +} + +static void +zfs_dbgmsg_purge(int max_size) +{ + zfs_dbgmsg_t *zdm; + int size; + + ASSERT(MUTEX_HELD(&zfs_dbgmsgs_lock)); + + while (zfs_dbgmsg_size > max_size) { + zdm = list_remove_head(&zfs_dbgmsgs); + if (zdm == NULL) + return; + + size = zdm->zdm_size; + kmem_free(zdm, size); + zfs_dbgmsg_size -= size; + } +} + +static int +zfs_dbgmsg_update(kstat_t *ksp, int rw) +{ + if (rw == KSTAT_WRITE) + zfs_dbgmsg_purge(0); + + return (0); +} void zfs_dbgmsg_init(void) @@ -36,87 +116,124 @@ 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); + + zfs_dbgmsg_kstat = kstat_create("zfs", 0, "dbgmsg", "misc", + KSTAT_TYPE_RAW, 0, KSTAT_FLAG_VIRTUAL); + if (zfs_dbgmsg_kstat) { + zfs_dbgmsg_kstat->ks_lock = &zfs_dbgmsgs_lock; + zfs_dbgmsg_kstat->ks_ndata = UINT32_MAX; + zfs_dbgmsg_kstat->ks_private = NULL; + zfs_dbgmsg_kstat->ks_update = zfs_dbgmsg_update; + kstat_set_raw_ops(zfs_dbgmsg_kstat, zfs_dbgmsg_headers, + zfs_dbgmsg_data, zfs_dbgmsg_addr); + kstat_install(zfs_dbgmsg_kstat); + } } void zfs_dbgmsg_fini(void) { - zfs_dbgmsg_t *zdm; + if (zfs_dbgmsg_kstat) + kstat_delete(zfs_dbgmsg_kstat); - 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_enter(&zfs_dbgmsgs_lock); + zfs_dbgmsg_purge(0); + mutex_exit(&zfs_dbgmsgs_lock); mutex_destroy(&zfs_dbgmsgs_lock); - ASSERT0(zfs_dbgmsg_size); } -/* - * To get this data enable the zfs__dbgmsg tracepoint as shown: - * - * # Enable zfs__dbgmsg tracepoint, clear the tracepoint ring buffer - * $ echo 1 > /sys/kernel/debug/tracing/events/zfs/enable - * $ echo 0 > /sys/kernel/debug/tracing/trace - * - * # Dump the ring buffer. - * $ cat /sys/kernel/debug/tracing/trace - */ void -zfs_dbgmsg(const char *fmt, ...) +__zfs_dbgmsg(char *buf) { + zfs_dbgmsg_t *zdm; int size; + + size = sizeof (zfs_dbgmsg_t) + strlen(buf); + zdm = kmem_zalloc(size, KM_SLEEP); + zdm->zdm_size = size; + zdm->zdm_timestamp = gethrestime_sec(); + strcpy(zdm->zdm_msg, buf); + + mutex_enter(&zfs_dbgmsgs_lock); + list_insert_tail(&zfs_dbgmsgs, zdm); + zfs_dbgmsg_size += size; + zfs_dbgmsg_purge(MAX(zfs_dbgmsg_maxsize, 0)); + mutex_exit(&zfs_dbgmsgs_lock); +} + +#ifdef _KERNEL +void +__dprintf(const char *file, const char *func, int line, const char *fmt, ...) +{ + const char *newfile; va_list adx; + size_t size; + char *buf; char *nl; - zfs_dbgmsg_t *zdm; - va_start(adx, fmt); - size = vsnprintf(NULL, 0, fmt, adx); - va_end(adx); + if (!zfs_dbgmsg_enable && !(zfs_flags & ZFS_DEBUG_DPRINTF)) + return; + + size = 1024; + buf = kmem_alloc(size, KM_SLEEP); /* - * There is one byte of string in sizeof (zfs_dbgmsg_t), used - * for the terminating null. + * Get rid of annoying prefix to filename. */ - zdm = kmem_alloc(sizeof (zfs_dbgmsg_t) + size, KM_SLEEP); - zdm->zdm_timestamp = gethrestime_sec(); + newfile = strrchr(file, '/'); + if (newfile != NULL) { + newfile = newfile + 1; /* Get rid of leading / */ + } else { + newfile = file; + } va_start(adx, fmt); - (void) vsnprintf(zdm->zdm_msg, size + 1, fmt, adx); + (void) vsnprintf(buf, size, fmt, adx); va_end(adx); /* * Get rid of trailing newline. */ - nl = strrchr(zdm->zdm_msg, '\n'); + nl = strrchr(buf, '\n'); if (nl != NULL) *nl = '\0'; - DTRACE_PROBE1(zfs__dbgmsg, char *, zdm->zdm_msg); + /* + * To get this data enable the zfs__dprintf trace point as shown: + * + * # Enable zfs__dprintf tracepoint, clear the tracepoint ring buffer + * $ echo 1 > /sys/module/zfs/parameters/zfs_flags + * $ echo 1 > /sys/kernel/debug/tracing/events/zfs/enable + * $ echo 0 > /sys/kernel/debug/tracing/trace + * + * # Dump the ring buffer. + * $ cat /sys/kernel/debug/tracing/trace + */ + if (zfs_flags & ZFS_DEBUG_DPRINTF) + DTRACE_PROBE4(zfs__dprintf, + char *, newfile, char *, func, int, line, char *, buf); - 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); + /* + * To get this data enable the zfs debug log as shown: + * + * # Set zfs_dbgmsg enable, clear the log buffer + * $ echo 1 > /sys/module/zfs/parameters/zfs_dbgmsg_enable + * $ echo 0 > /proc/spl/kstat/zfs/dbgmsg + * + * # Dump the log buffer. + * $ cat /proc/spl/kstat/zfs/dbgmsg + */ + if (zfs_dbgmsg_enable) + __zfs_dbgmsg(buf); + + kmem_free(buf, size); } +#endif /* _KERNEL */ -void -zfs_dbgmsg_print(const char *tag) -{ -#if !defined(_KERNEL) - zfs_dbgmsg_t *zdm; +#ifdef _KERNEL +module_param(zfs_dbgmsg_enable, int, 0644); +MODULE_PARM_DESC(zfs_dbgmsg_enable, "Enable ZFS debug message log"); - (void) printf("ZFS_DBGMSG(%s):\n", tag); - mutex_enter(&zfs_dbgmsgs_lock); - for (zdm = list_head(&zfs_dbgmsgs); zdm; - zdm = list_next(&zfs_dbgmsgs, zdm)) - (void) printf("%s\n", zdm->zdm_msg); - mutex_exit(&zfs_dbgmsgs_lock); -#endif /* !_KERNEL */ -} +module_param(zfs_dbgmsg_maxsize, int, 0644); +MODULE_PARM_DESC(zfs_dbgmsg_maxsize, "Maximum ZFS debug log size"); +#endif |