enable zfs_dbgmsg() by default, without dprintf()

zfs_dbgmsg() should record a message by default.  As a general
principal, these messages shouldn't be too verbose.  Furthermore, the
amount of memory used is limited to 4MB (by default).

dprintf() should only record a message if this is a debug build, and
ZFS_DEBUG_DPRINTF is set in zfs_flags.  This flag is not set by default
(even on debug builds).  These messages are extremely verbose, and
sometimes nontrivial to compute.

SET_ERROR() should only record a message if ZFS_DEBUG_SET_ERROR is set
in zfs_flags.  This flag is not set by default (even on debug builds).

This brings our behavior in line with illumos.  Note that the message
format is unchanged (including file, line, and function, even though
these are not recorded on illumos).

Reviewed-by: Giuseppe Di Natale <dinatale2@llnl.gov>
Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov>
Reviewed-by: Prakash Surya <prakash.surya@delphix.com>
Signed-off-by: Matthew Ahrens <mahrens@delphix.com>
Closes #7314

diff --git a/include/sys/zfs_debug.h b/include/sys/zfs_debug.h
index 226aaa2b84ab59581b9d3c01cffaa18dd68b281e..7e05c2a35f83d3f5b79f0f1899394f4370e6f260 100644 (file)
--- a/include/sys/zfs_debug.h
+++ b/include/sys/zfs_debug.h
@@ -41,6 +41,7 @@ extern "C" {
 extern int zfs_flags;
 extern int zfs_recover;
 extern int zfs_free_leak_on_eio;
+extern int zfs_dbgmsg_enable;
 
 #define        ZFS_DEBUG_DPRINTF               (1 << 0)
 #define        ZFS_DEBUG_DBUF_VERIFY           (1 << 1)
@@ -55,10 +56,22 @@ extern int zfs_free_leak_on_eio;
 
 extern void __dprintf(const char *file, const char *func,
     int line, const char *fmt, ...);
-#define        dprintf(...) \
-       __dprintf(__FILE__, __func__, __LINE__, __VA_ARGS__)
 #define        zfs_dbgmsg(...) \
-       __dprintf(__FILE__, __func__, __LINE__, __VA_ARGS__)
+       if (zfs_dbgmsg_enable) \
+               __dprintf(__FILE__, __func__, __LINE__, __VA_ARGS__)
+
+#ifdef ZFS_DEBUG
+/*
+ * To enable this:
+ *
+ * $ echo 1 >/sys/module/zfs/parameters/zfs_flags
+ */
+#define        dprintf(...) \
+       if (zfs_flags & ZFS_DEBUG_DPRINTF) \
+               __dprintf(__FILE__, __func__, __LINE__, __VA_ARGS__)
+#else
+#define        dprintf(...) ((void)0)
+#endif /* ZFS_DEBUG */
 
 extern void zfs_panic_recover(const char *fmt, ...);
 

diff --git a/module/zfs/arc.c b/module/zfs/arc.c
index c6ff6171c1612c6d37178ff30694fbf5c3ae0796..9c0c5513d1212314dd4acdf260d321e61d085034 100644 (file)
--- a/module/zfs/arc.c
+++ b/module/zfs/arc.c
@@ -7138,6 +7138,7 @@ arc_tempreserve_space(uint64_t reserve, uint64_t txg)
 
        if (reserve + arc_tempreserve + anon_size > arc_c / 2 &&
            anon_size > arc_c / 4) {
+#ifdef ZFS_DEBUG
                uint64_t meta_esize =
                    refcount_count(&arc_anon->arcs_esize[ARC_BUFC_METADATA]);
                uint64_t data_esize =
@@ -7146,6 +7147,7 @@ arc_tempreserve_space(uint64_t reserve, uint64_t txg)
                    "anon_data=%lluK tempreserve=%lluK arc_c=%lluK\n",
                    arc_tempreserve >> 10, meta_esize >> 10,
                    data_esize >> 10, reserve >> 10, arc_c >> 10);
+#endif
                DMU_TX_STAT_BUMP(dmu_tx_dirty_throttle);
                return (SET_ERROR(ERESTART));
        }

diff --git a/module/zfs/dmu_send.c b/module/zfs/dmu_send.c
index d39ab1a9eafee8edbef88810f17629324862f2d2..36e412bdf32a1c8d218c962ad401ef5b27750412 100644 (file)
--- a/module/zfs/dmu_send.c
+++ b/module/zfs/dmu_send.c
@@ -3440,6 +3440,7 @@ receive_read_record(struct receive_arg *ra)
 static void
 dprintf_drr(struct receive_record_arg *rrd, int err)
 {
+#ifdef ZFS_DEBUG
        switch (rrd->header.drr_type) {
        case DRR_OBJECT:
        {
@@ -3520,6 +3521,7 @@ dprintf_drr(struct receive_record_arg *rrd, int err)
        default:
                return;
        }
+#endif
 }
 
 /*

diff --git a/module/zfs/spa_misc.c b/module/zfs/spa_misc.c
index d71468db3cc3155dfbb02b1d080add9a1b898848..5e2af24e3b6d7240e5ba16c15373b6f9a4b6069f 100644 (file)
--- a/module/zfs/spa_misc.c
+++ b/module/zfs/spa_misc.c
@@ -243,8 +243,7 @@ kmem_cache_t *spa_buffer_pool;
 int spa_mode_global;
 
 #ifdef ZFS_DEBUG
-/* Everything except dprintf and spa is on by default in debug builds */
-int zfs_flags = ~(ZFS_DEBUG_DPRINTF | ZFS_DEBUG_SPA);
+int zfs_flags = ~(ZFS_DEBUG_DPRINTF | ZFS_DEBUG_SET_ERROR | ZFS_DEBUG_SPA);
 #else
 int zfs_flags = 0;
 #endif

diff --git a/module/zfs/zfs_debug.c b/module/zfs/zfs_debug.c
index d1dba3f8f5747e8bacf56bb5c02cb322e4f4734c..e2aff28e1ffef31b5a9cf2ef3e06805c2efff76b 100644 (file)
--- a/module/zfs/zfs_debug.c
+++ b/module/zfs/zfs_debug.c
@@ -33,20 +33,18 @@ 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.
+ * Internal ZFS debug messages are enabled by default.
  *
- * # Enable the kernel debug message log.
- * echo 1 > /sys/module/zfs/parameters/zfs_dbgmsg_enable
+ * # Print debug messages
+ * cat /proc/spl/kstat/zfs/dbgmsg
+ *
+ * # Disable the kernel debug message log.
+ * echo 0 > /sys/module/zfs/parameters/zfs_dbgmsg_enable
  *
  * # Clear the kernel debug message log.
  * echo 0 >/proc/spl/kstat/zfs/dbgmsg
  */
-#if defined(_KERNEL) && !defined(ZFS_DEBUG)
-int zfs_dbgmsg_enable = 0;
-#else
 int zfs_dbgmsg_enable = 1;
-#endif
 
 static int
 zfs_dbgmsg_headers(char *buf, size_t size)
@@ -164,6 +162,11 @@ __zfs_dbgmsg(char *buf)
 void
 __set_error(const char *file, const char *func, int line, int err)
 {
+       /*
+        * To enable this:
+        *
+        * $ echo 512 >/sys/module/zfs/parameters/zfs_flags
+        */
        if (zfs_flags & ZFS_DEBUG_SET_ERROR)
                __dprintf(file, func, line, "error %lu", err);
 }
@@ -179,10 +182,6 @@ __dprintf(const char *file, const char *func, int line, const char *fmt, ...)
        char *nl;
        int i;
 
-       if (!zfs_dbgmsg_enable &&
-           !(zfs_flags & (ZFS_DEBUG_DPRINTF | ZFS_DEBUG_SET_ERROR)))
-               return;
-
        size = 1024;
        buf = kmem_alloc(size, KM_SLEEP);
 
@@ -215,28 +214,23 @@ __dprintf(const char *file, const char *func, int line, const char *fmt, ...)
         * 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 | ZFS_DEBUG_SET_ERROR))
-               DTRACE_PROBE1(zfs__dprintf, char *, buf);
+       DTRACE_PROBE1(zfs__dprintf, 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
+        * To get this data:
         *
-        * # Dump the log buffer.
         * $ cat /proc/spl/kstat/zfs/dbgmsg
+        *
+        * To clear the buffer:
+        * $ echo 0 > /proc/spl/kstat/zfs/dbgmsg
         */
-       if (zfs_dbgmsg_enable)
-               __zfs_dbgmsg(buf);
+       __zfs_dbgmsg(buf);
 
        kmem_free(buf, size);
 }