3b36f8319d
Internally ZFS keeps a small log to facilitate debugging. By default the log is disabled, to enable it set zfs_dbgmsg_enable=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. $ echo 1 >/sys/module/zfs/parameters/zfs_dbgmsg_enable $ echo 0 >/proc/spl/kstat/zfs/dbgmsg $ zpool import tank $ cat /proc/spl/kstat/zfs/dbgmsg 1 0 0x01 -1 0 2492357525542 2525836565501 timestamp message 1441141408 spa=tank async request task=1 1441141408 txg 70 open pool version 5000; software version 5000/5; ... 1441141409 spa=tank async request task=32 1441141409 txg 72 import pool version 5000; software version 5000/5; ... 1441141414 command: lt-zpool import tank Note the zfs_dbgmsg() and dprintf() functions are both now mapped to the same log. As mentioned above the kernel debug log can be accessed though the /proc/spl/kstat/zfs/dbgmsg kstat. For user space consumers log messages are immediately written to stdout after applying the ZFS_DEBUG environment variable. $ ZFS_DEBUG=on ./cmd/ztest/ztest -V Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov> Signed-off-by: Ned Bass <bass6@llnl.gov> Closes #3728
240 lines
5.6 KiB
C
240 lines
5.6 KiB
C
/*
|
|
* CDDL HEADER START
|
|
*
|
|
* The contents of this file are subject to the terms of the
|
|
* Common Development and Distribution License (the "License").
|
|
* You may not use this file except in compliance with the License.
|
|
*
|
|
* You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
|
|
* or http://www.opensolaris.org/os/licensing.
|
|
* See the License for the specific language governing permissions
|
|
* and limitations under the License.
|
|
*
|
|
* When distributing Covered Code, include this CDDL HEADER in each
|
|
* file and include the License file at usr/src/OPENSOLARIS.LICENSE.
|
|
* If applicable, add the following below this CDDL HEADER, with the
|
|
* fields enclosed by brackets "[]" replaced with your own identifying
|
|
* information: Portions Copyright [yyyy] [name of copyright owner]
|
|
*
|
|
* CDDL HEADER END
|
|
*/
|
|
/*
|
|
* Copyright (c) 2010, Oracle and/or its affiliates. All rights reserved.
|
|
* Copyright (c) 2012, 2014 by Delphix. All rights reserved.
|
|
*/
|
|
|
|
#include <sys/zfs_context.h>
|
|
#include <sys/kstat.h>
|
|
|
|
list_t zfs_dbgmsgs;
|
|
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)
|
|
{
|
|
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)
|
|
{
|
|
if (zfs_dbgmsg_kstat)
|
|
kstat_delete(zfs_dbgmsg_kstat);
|
|
|
|
mutex_enter(&zfs_dbgmsgs_lock);
|
|
zfs_dbgmsg_purge(0);
|
|
mutex_exit(&zfs_dbgmsgs_lock);
|
|
mutex_destroy(&zfs_dbgmsgs_lock);
|
|
}
|
|
|
|
void
|
|
__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;
|
|
|
|
if (!zfs_dbgmsg_enable && !(zfs_flags & ZFS_DEBUG_DPRINTF))
|
|
return;
|
|
|
|
size = 1024;
|
|
buf = kmem_alloc(size, KM_SLEEP);
|
|
|
|
/*
|
|
* 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
|
|
*/
|
|
if (zfs_flags & ZFS_DEBUG_DPRINTF)
|
|
DTRACE_PROBE4(zfs__dprintf,
|
|
char *, newfile, char *, func, int, line, char *, buf);
|
|
|
|
/*
|
|
* 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 */
|
|
|
|
#ifdef _KERNEL
|
|
module_param(zfs_dbgmsg_enable, int, 0644);
|
|
MODULE_PARM_DESC(zfs_dbgmsg_enable, "Enable ZFS debug message log");
|
|
|
|
module_param(zfs_dbgmsg_maxsize, int, 0644);
|
|
MODULE_PARM_DESC(zfs_dbgmsg_maxsize, "Maximum ZFS debug log size");
|
|
#endif
|