diff options
| -rw-r--r-- | cmd/ztest/ztest.c | 6 | ||||
| -rw-r--r-- | include/sys/trace_dbgmsg.h | 26 | ||||
| -rw-r--r-- | include/sys/zfs_debug.h | 12 | ||||
| -rw-r--r-- | man/man5/zfs-module-parameters.5 | 25 | ||||
| -rw-r--r-- | module/zfs/zfs_debug.c | 223 | ||||
| -rw-r--r-- | module/zfs/zfs_ioctl.c | 49 |
6 files changed, 199 insertions, 142 deletions
diff --git a/cmd/ztest/ztest.c b/cmd/ztest/ztest.c index f2ffcaf3e..afe6faab0 100644 --- a/cmd/ztest/ztest.c +++ b/cmd/ztest/ztest.c @@ -827,9 +827,6 @@ ztest_kill(ztest_shared_t *zs) spa_config_sync(ztest_spa, B_FALSE, B_FALSE); mutex_exit(&spa_namespace_lock); - if (ztest_opts.zo_verbose >= 3) - zfs_dbgmsg_print(FTAG); - (void) kill(getpid(), SIGKILL); } @@ -5894,9 +5891,6 @@ ztest_run(ztest_shared_t *zs) zs->zs_alloc = metaslab_class_get_alloc(spa_normal_class(spa)); zs->zs_space = metaslab_class_get_space(spa_normal_class(spa)); - if (ztest_opts.zo_verbose >= 3) - zfs_dbgmsg_print(FTAG); - umem_free(tid, ztest_opts.zo_threads * sizeof (kt_did_t)); /* Kill the resume thread */ diff --git a/include/sys/trace_dbgmsg.h b/include/sys/trace_dbgmsg.h index 24b34bcf3..e493a4580 100644 --- a/include/sys/trace_dbgmsg.h +++ b/include/sys/trace_dbgmsg.h @@ -37,32 +37,6 @@ */ /* - * Generic support for one argument tracepoints of the form: - * - * DTRACE_PROBE1(..., - * const char *, ...); - */ - -DECLARE_EVENT_CLASS(zfs_dbgmsg_class, - TP_PROTO(const char *msg), - TP_ARGS(msg), - TP_STRUCT__entry( - __string(msg, msg) - ), - TP_fast_assign( - __assign_str(msg, msg); - ), - TP_printk("%s", __get_str(msg)) -); - -#define DEFINE_DBGMSG_EVENT(name) \ -DEFINE_EVENT(zfs_dbgmsg_class, name, \ - TP_PROTO(const char *msg), \ - TP_ARGS(msg)) -DEFINE_DBGMSG_EVENT(zfs_zfs__dbgmsg); - - -/* * Generic support for four argument tracepoints of the form: * * DTRACE_PROBE4(..., diff --git a/include/sys/zfs_debug.h b/include/sys/zfs_debug.h index 1a7062408..2f0064ee0 100644 --- a/include/sys/zfs_debug.h +++ b/include/sys/zfs_debug.h @@ -51,28 +51,24 @@ extern int zfs_free_leak_on_eio; #define ZFS_DEBUG_ZIO_FREE (1<<6) #define ZFS_DEBUG_HISTOGRAM_VERIFY (1<<7) -#if defined(HAVE_DECLARE_EVENT_CLASS) || !defined(_KERNEL) extern void __dprintf(const char *file, const char *func, int line, const char *fmt, ...); #define dprintf(...) \ - if (zfs_flags & ZFS_DEBUG_DPRINTF) \ - __dprintf(__FILE__, __func__, __LINE__, __VA_ARGS__) -#else -#define dprintf(...) ((void)0) -#endif /* HAVE_DECLARE_EVENT_CLASS || !_KERNEL */ + __dprintf(__FILE__, __func__, __LINE__, __VA_ARGS__) +#define zfs_dbgmsg(...) \ + __dprintf(__FILE__, __func__, __LINE__, __VA_ARGS__) extern void zfs_panic_recover(const char *fmt, ...); typedef struct zfs_dbgmsg { list_node_t zdm_node; time_t zdm_timestamp; + int zdm_size; 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, ...); -extern void zfs_dbgmsg_print(const char *tag); #ifndef _KERNEL extern int dprintf_find_string(const char *string); diff --git a/man/man5/zfs-module-parameters.5 b/man/man5/zfs-module-parameters.5 index 27b5346e2..6d4a8c304 100644 --- a/man/man5/zfs-module-parameters.5 +++ b/man/man5/zfs-module-parameters.5 @@ -610,6 +610,31 @@ Use \fB1\fR for yes (default) and \fB0\fR for no. .sp .ne 2 .na +\fBzfs_dbgmsg_enable\fR (int) +.ad +.RS 12n +Internally ZFS keeps a small log to facilitate debugging. By default the log +is disabled, to enable it set this option to 1. The contents of the log can +be accessed by reading the /proc/spl/kstat/zfs/dbgmsg file. Writing 0 to +this proc file clears the log. +.sp +Default value: \fB0\fR. +.RE + +.sp +.ne 2 +.na +\fBzfs_dbgmsg_maxsize\fR (int) +.ad +.RS 12n +The maximum size in bytes of the internal ZFS debug log. +.sp +Default value: \fB4M\fR. +.RE + +.sp +.ne 2 +.na \fBzfs_dbuf_state_index\fR (int) .ad .RS 12n 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 diff --git a/module/zfs/zfs_ioctl.c b/module/zfs/zfs_ioctl.c index 06aae82a1..7ce19693e 100644 --- a/module/zfs/zfs_ioctl.c +++ b/module/zfs/zfs_ioctl.c @@ -247,55 +247,6 @@ static int zfs_fill_zplprops_root(uint64_t, nvlist_t *, nvlist_t *, int zfs_set_prop_nvlist(const char *, zprop_source_t, nvlist_t *, nvlist_t *); static int get_nvlist(uint64_t nvl, uint64_t size, int iflag, nvlist_t **nvp); -#if defined(HAVE_DECLARE_EVENT_CLASS) -void -__dprintf(const char *file, const char *func, int line, const char *fmt, ...) -{ - const char *newfile; - size_t size = 4096; - char *buf = kmem_alloc(size, KM_SLEEP); - char *nl; - va_list adx; - - /* - * Get rid of annoying 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, size, fmt, adx); - va_end(adx); - - /* - * Get rid of trailing newline. - */ - nl = strrchr(buf, '\n'); - if (nl != NULL) - *nl = '\0'; - - /* - * 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 - */ - DTRACE_PROBE4(zfs__dprintf, - char *, newfile, char *, func, int, line, char *, buf); - - kmem_free(buf, size); -} -#endif /* HAVE_DECLARE_EVENT_CLASS */ - static void history_str_free(char *buf) { |