module/zfs/zfs_debug.c

   1 /*
   2  * CDDL HEADER START
   3  *
   4  * The contents of this file are subject to the terms of the
   5  * Common Development and Distribution License (the "License").
   6  * You may not use this file except in compliance with the License.
   7  *
   8  * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
   9  * or http://www.opensolaris.org/os/licensing.
  10  * See the License for the specific language governing permissions
  11  * and limitations under the License.
  12  *
  13  * When distributing Covered Code, include this CDDL HEADER in each
  14  * file and include the License file at usr/src/OPENSOLARIS.LICENSE.
  15  * If applicable, add the following below this CDDL HEADER, with the
  16  * fields enclosed by brackets "[]" replaced with your own identifying
  17  * information: Portions Copyright [yyyy] [name of copyright owner]
  18  *
  19  * CDDL HEADER END
  20  */
  21 /*
  22  * Copyright (c) 2010, Oracle and/or its affiliates. All rights reserved.
  23  * Copyright (c) 2012, 2014 by Delphix. All rights reserved.
  24  */
  25
  26 #include <sys/zfs_context.h>
  27 #include <sys/kstat.h>
  28
  29 list_t zfs_dbgmsgs;
  30 int zfs_dbgmsg_size = 0;
  31 kmutex_t zfs_dbgmsgs_lock;
  32 int zfs_dbgmsg_maxsize = 4<<20; /* 4MB */
  33 kstat_t *zfs_dbgmsg_kstat;
  34
  35 /*
  36  * By default only enable the internal ZFS debug messages when running
  37  * in userspace (ztest).  The kernel log must be manually enabled.
  38  *
  39  * # Enable the kernel debug message log.
  40  * echo 1 > /sys/module/zfs/parameters/zfs_dbgmsg_enable
  41  *
  42  * # Clear the kernel debug message log.
  43  * echo 0 >/proc/spl/kstat/zfs/dbgmsg
  44  */
  45 #if defined(_KERNEL) && !defined(ZFS_DEBUG)
  46 int zfs_dbgmsg_enable = 0;
  47 #else
  48 int zfs_dbgmsg_enable = 1;
  49 #endif
  50
  51 static int
  52 zfs_dbgmsg_headers(char *buf, size_t size)
  53 {
  54         (void) snprintf(buf, size, "%-12s %-8s\n", "timestamp", "message");
  55
  56         return (0);
  57 }
  58
  59 static int
  60 zfs_dbgmsg_data(char *buf, size_t size, void *data)
  61 {
  62         zfs_dbgmsg_t *zdm = (zfs_dbgmsg_t *)data;
  63
  64         (void) snprintf(buf, size, "%-12llu %-s\n",
  65             (u_longlong_t)zdm->zdm_timestamp, zdm->zdm_msg);
  66
  67         return (0);
  68 }
  69
  70 static void *
  71 zfs_dbgmsg_addr(kstat_t *ksp, loff_t n)
  72 {
  73         zfs_dbgmsg_t *zdm = (zfs_dbgmsg_t *)ksp->ks_private;
  74
  75         ASSERT(MUTEX_HELD(&zfs_dbgmsgs_lock));
  76
  77         if (n == 0)
  78                 ksp->ks_private = list_head(&zfs_dbgmsgs);
  79         else if (zdm)
  80                 ksp->ks_private = list_next(&zfs_dbgmsgs, zdm);
  81
  82         return (ksp->ks_private);
  83 }
  84
  85 static void
  86 zfs_dbgmsg_purge(int max_size)
  87 {
  88         zfs_dbgmsg_t *zdm;
  89         int size;
  90
  91         ASSERT(MUTEX_HELD(&zfs_dbgmsgs_lock));
  92
  93         while (zfs_dbgmsg_size > max_size) {
  94                 zdm = list_remove_head(&zfs_dbgmsgs);
  95                 if (zdm == NULL)
  96                         return;
  97
  98                 size = zdm->zdm_size;
  99                 kmem_free(zdm, size);
 100                 zfs_dbgmsg_size -= size;
 101         }
 102 }
 103
 104 static int
 105 zfs_dbgmsg_update(kstat_t *ksp, int rw)
 106 {
 107         if (rw == KSTAT_WRITE)
 108                 zfs_dbgmsg_purge(0);
 109
 110         return (0);
 111 }
 112
 113 void
 114 zfs_dbgmsg_init(void)
 115 {
 116         list_create(&zfs_dbgmsgs, sizeof (zfs_dbgmsg_t),
 117             offsetof(zfs_dbgmsg_t, zdm_node));
 118         mutex_init(&zfs_dbgmsgs_lock, NULL, MUTEX_DEFAULT, NULL);
 119
 120         zfs_dbgmsg_kstat = kstat_create("zfs", 0, "dbgmsg", "misc",
 121             KSTAT_TYPE_RAW, 0, KSTAT_FLAG_VIRTUAL);
 122         if (zfs_dbgmsg_kstat) {
 123                 zfs_dbgmsg_kstat->ks_lock = &zfs_dbgmsgs_lock;
 124                 zfs_dbgmsg_kstat->ks_ndata = UINT32_MAX;
 125                 zfs_dbgmsg_kstat->ks_private = NULL;
 126                 zfs_dbgmsg_kstat->ks_update = zfs_dbgmsg_update;
 127                 kstat_set_raw_ops(zfs_dbgmsg_kstat, zfs_dbgmsg_headers,
 128                     zfs_dbgmsg_data, zfs_dbgmsg_addr);
 129                 kstat_install(zfs_dbgmsg_kstat);
 130         }
 131 }
 132
 133 void
 134 zfs_dbgmsg_fini(void)
 135 {
 136         if (zfs_dbgmsg_kstat)
 137                 kstat_delete(zfs_dbgmsg_kstat);
 138
 139         mutex_enter(&zfs_dbgmsgs_lock);
 140         zfs_dbgmsg_purge(0);
 141         mutex_exit(&zfs_dbgmsgs_lock);
 142         mutex_destroy(&zfs_dbgmsgs_lock);
 143 }
 144
 145 void
 146 __zfs_dbgmsg(char *buf)
 147 {
 148         zfs_dbgmsg_t *zdm;
 149         int size;
 150
 151         size = sizeof (zfs_dbgmsg_t) + strlen(buf);
 152         zdm = kmem_zalloc(size, KM_SLEEP);
 153         zdm->zdm_size = size;
 154         zdm->zdm_timestamp = gethrestime_sec();
 155         strcpy(zdm->zdm_msg, buf);
 156
 157         mutex_enter(&zfs_dbgmsgs_lock);
 158         list_insert_tail(&zfs_dbgmsgs, zdm);
 159         zfs_dbgmsg_size += size;
 160         zfs_dbgmsg_purge(MAX(zfs_dbgmsg_maxsize, 0));
 161         mutex_exit(&zfs_dbgmsgs_lock);
 162 }
 163
 164 void
 165 __set_error(const char *file, const char *func, int line, int err)
 166 {
 167         if (zfs_flags & ZFS_DEBUG_SET_ERROR)
 168                 __dprintf(file, func, line, "error %lu", err);
 169 }
 170
 171 #ifdef _KERNEL
 172 void
 173 __dprintf(const char *file, const char *func, int line, const char *fmt, ...)
 174 {
 175         const char *newfile;
 176         va_list adx;
 177         size_t size;
 178         char *buf;
 179         char *nl;
 180         int i;
 181
 182         if (!zfs_dbgmsg_enable &&
 183             !(zfs_flags & (ZFS_DEBUG_DPRINTF | ZFS_DEBUG_SET_ERROR)))
 184                 return;
 185
 186         size = 1024;
 187         buf = kmem_alloc(size, KM_SLEEP);
 188
 189         /*
 190          * Get rid of annoying prefix to filename.
 191          */
 192         newfile = strrchr(file, '/');
 193         if (newfile != NULL) {
 194                 newfile = newfile + 1; /* Get rid of leading / */
 195         } else {
 196                 newfile = file;
 197         }
 198
 199         i = snprintf(buf, size, "%s:%d:%s(): ", newfile, line, func);
 200
 201         if (i < size) {
 202                 va_start(adx, fmt);
 203                 (void) vsnprintf(buf + i, size - i, fmt, adx);
 204                 va_end(adx);
 205         }
 206
 207         /*
 208          * Get rid of trailing newline.
 209          */
 210         nl = strrchr(buf, '\n');
 211         if (nl != NULL)
 212                 *nl = '\0';
 213
 214         /*
 215          * To get this data enable the zfs__dprintf trace point as shown:
 216          *
 217          * # Enable zfs__dprintf tracepoint, clear the tracepoint ring buffer
 218          * $ echo 1 > /sys/module/zfs/parameters/zfs_flags
 219          * $ echo 1 > /sys/kernel/debug/tracing/events/zfs/enable
 220          * $ echo 0 > /sys/kernel/debug/tracing/trace
 221          *
 222          * # Dump the ring buffer.
 223          * $ cat /sys/kernel/debug/tracing/trace
 224          */
 225         if (zfs_flags & (ZFS_DEBUG_DPRINTF | ZFS_DEBUG_SET_ERROR))
 226                 DTRACE_PROBE1(zfs__dprintf, char *, buf);
 227
 228         /*
 229          * To get this data enable the zfs debug log as shown:
 230          *
 231          * # Set zfs_dbgmsg enable, clear the log buffer
 232          * $ echo 1 > /sys/module/zfs/parameters/zfs_dbgmsg_enable
 233          * $ echo 0 > /proc/spl/kstat/zfs/dbgmsg
 234          *
 235          * # Dump the log buffer.
 236          * $ cat /proc/spl/kstat/zfs/dbgmsg
 237          */
 238         if (zfs_dbgmsg_enable)
 239                 __zfs_dbgmsg(buf);
 240
 241         kmem_free(buf, size);
 242 }
 243
 244 #else
 245
 246 void
 247 zfs_dbgmsg_print(const char *tag)
 248 {
 249         zfs_dbgmsg_t *zdm;
 250
 251         (void) printf("ZFS_DBGMSG(%s):\n", tag);
 252         mutex_enter(&zfs_dbgmsgs_lock);
 253         for (zdm = list_head(&zfs_dbgmsgs); zdm;
 254             zdm = list_next(&zfs_dbgmsgs, zdm))
 255                 (void) printf("%s\n", zdm->zdm_msg);
 256         mutex_exit(&zfs_dbgmsgs_lock);
 257 }
 258 #endif /* _KERNEL */
 259
 260 #ifdef _KERNEL
 261 module_param(zfs_dbgmsg_enable, int, 0644);
 262 MODULE_PARM_DESC(zfs_dbgmsg_enable, "Enable ZFS debug message log");
 263
 264 module_param(zfs_dbgmsg_maxsize, int, 0644);
 265 MODULE_PARM_DESC(zfs_dbgmsg_maxsize, "Maximum ZFS debug log size");
 266 #endif