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 <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Reviewed-by: Prakash Surya <[email protected]>
Signed-off-by: Matthew Ahrens <[email protected]>
Closes #7314 

5 files changed, 38 insertions, 28 deletions

diff --git a/include/sys/zfs_debug.h b/include/sys/zfs_debug.h
index 226aaa2b8..7e05c2a35 100644
--- 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 c6ff6171c..9c0c5513d 100644
--- 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 d39ab1a9e..36e412bdf 100644
--- 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 d71468db3..5e2af24e3 100644
--- 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 d1dba3f8f..e2aff28e1 100644
--- 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);
 }