[PATCH] New debug backend "ringbuf"

Ralph Böhme slow at samba.org
Sun Jan 8 09:08:53 UTC 2017


Hi!

This one made my day when trying to fix a subtle bug in some asyc code in
ctdbd_conn.c I'm currently working on. The bug was subject to timing effects, I
could easily reproduce it at log level 1, but as soon as I cranked up log level
it hid away. Arg.

I tried moving the logfile to a memdisk, but even with that, timings were
different enough so I still couldn't reproduce it. Ahhhhhh...

That's when I thought of adding a new logging backend that simply writes all log
messages into a memory buffer, et voila, with this I was able to reproduce the
issue at log level 10. Bug found and fixed. :)

To make use of it when hunting for a bug, you must be able to identify a place
in the codepath where you know things are gone south and you can cause a
panic. You then attach with gdb to the panicked (and in developer mode sleeping
process, otherwise grab the corefile) and run:

(gdb) dump binary memory samba.log debug_ringbuf debug_ringbuf+SIZE

The default size is 1 MB, but this can be changed by a backend option:

 logging = ringbuf:size=NBYTES

Fwiw, the ringbuffer is of course only allocated if the backend is used.

Please review & push if ok.

Cheerio!
-slow
-------------- next part --------------
From e306ae3099b66f34509d94f2dee2501a4f36186c Mon Sep 17 00:00:00 2001
From: Ralph Boehme <slow at samba.org>
Date: Sat, 7 Jan 2017 19:34:46 +0100
Subject: [PATCH 1/2] debug: parse, store and pass backend option

Will be used in the next commit by new "ringbuf" backend.

Signed-off-by: Ralph Boehme <slow at samba.org>
---
 lib/util/debug.c | 24 +++++++++++++++---------
 1 file changed, 15 insertions(+), 9 deletions(-)

diff --git a/lib/util/debug.c b/lib/util/debug.c
index 37582db..5ce3325 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -149,7 +149,7 @@ static void debug_file_log(int msg_level,
 
 #ifdef WITH_SYSLOG
 static void debug_syslog_reload(bool enabled, bool previously_enabled,
-				const char *prog_name)
+				const char *prog_name, char *option)
 {
 	if (enabled && !previously_enabled) {
 #ifdef LOG_DAEMON
@@ -207,7 +207,7 @@ static void debug_lttng_log(int msg_level,
 #ifdef HAVE_GPFS
 #include "gpfswrap.h"
 static void debug_gpfs_reload(bool enabled, bool previously_enabled,
-			      const char *prog_name)
+			      const char *prog_name, char *option)
 {
 	gpfswrap_init();
 
@@ -240,8 +240,10 @@ static struct debug_backend {
 	const char *name;
 	int log_level;
 	int new_log_level;
-	void (*reload)(bool enabled, bool prev_enabled, const char *prog_name);
+	void (*reload)(bool enabled, bool prev_enabled,
+		       const char *prog_name, char *option);
 	void (*log)(int msg_level, const char *msg, const char *msg_no_nl);
+	char *option;
 } debug_backends[] = {
 	{
 		.name = "file",
@@ -297,6 +299,7 @@ static struct debug_backend *debug_find_backend(const char *name)
 static void debug_backend_parse_token(char *tok)
 {
 	char *backend_name_option, *backend_name,*backend_level, *saveptr;
+	char *backend_option;
 	struct debug_backend *b;
 
 	/*
@@ -317,12 +320,7 @@ static void debug_backend_parse_token(char *tok)
 		return;
 	}
 
-	/*
-	 * No backend is using the option yet.
-	 */
-#if 0
 	backend_option = strtok_r(NULL, "\0", &saveptr);
-#endif
 
 	/*
 	 * Find and update backend
@@ -337,6 +335,13 @@ static void debug_backend_parse_token(char *tok)
 	} else {
 		b->new_log_level = atoi(backend_level);
 	}
+
+	if (backend_option != NULL) {
+		b->option = strdup(backend_option);
+		if (b->option == NULL) {
+			return;
+		}
+	}
 }
 
 /*
@@ -380,7 +385,8 @@ static void debug_set_backends(const char *param)
 			bool enabled = b->new_log_level > -1;
 			bool previously_enabled = b->log_level > -1;
 
-			b->reload(enabled, previously_enabled, state.prog_name);
+			b->reload(enabled, previously_enabled, state.prog_name,
+				  b->option);
 		}
 		b->log_level = b->new_log_level;
 	}
-- 
2.7.4


From 5352cb6afaa0b6d6628638d0149b7399bea06c47 Mon Sep 17 00:00:00 2001
From: Ralph Boehme <slow at samba.org>
Date: Sat, 7 Jan 2017 14:36:24 +0100
Subject: [PATCH 2/2] debug: add "ringbuf" backend logging to a ringbuffer

This is useful for debugging bugs that involve timing effects and are
not reproducible when logging at higher debug levels with the file
backend.

The log can be dumped to a file with gdb:

(gdb) dump binary memory samba.log debug_ringbuf debug_ringbuf+SIZE

Signed-off-by: Ralph Boehme <slow at samba.org>
---
 docs-xml/smbdotconf/logging/logging.xml |  5 +++
 lib/util/debug.c                        | 62 +++++++++++++++++++++++++++++++++
 2 files changed, 67 insertions(+)

diff --git a/docs-xml/smbdotconf/logging/logging.xml b/docs-xml/smbdotconf/logging/logging.xml
index 8524884..b152d0c 100644
--- a/docs-xml/smbdotconf/logging/logging.xml
+++ b/docs-xml/smbdotconf/logging/logging.xml
@@ -31,8 +31,13 @@
     <listitem><para><parameter moreinfo="none">systemd</parameter></para></listitem>
     <listitem><para><parameter moreinfo="none">lttng</parameter></para></listitem>
     <listitem><para><parameter moreinfo="none">gpfs</parameter></para></listitem>
+    <listitem><para><parameter moreinfo="none">ringbuf</parameter></para></listitem>
   </itemizedlist>
 
+  <para>The <parameter moreinfo="none">ringbuf</parameter> backend supports an
+  optional size argument to change the buffer size used, the default is 1 MB:
+  <parameter moreinfo="none">ringbuf:size=NBYTES</parameter></para>
+
 </description>
 <value type="default"></value>
 <value type="example">syslog at 1 file</value>
diff --git a/lib/util/debug.c b/lib/util/debug.c
index 5ce3325..b843e1a 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -236,6 +236,63 @@ static void debug_gpfs_log(int msg_level,
 }
 #endif /* HAVE_GPFS */
 
+#define DEBUG_RINGBUF_SIZE (1024 * 1024)
+#define DEBUG_RINGBUF_SIZE_OPT "size="
+
+char *debug_ringbuf;
+static size_t debug_ringbuf_size;
+static size_t debug_ringbuf_ofs;
+
+static void debug_ringbuf_reload(bool enabled, bool previously_enabled,
+				 const char *prog_name, char *option)
+{
+	bool cmp;
+	size_t optlen = strlen(DEBUG_RINGBUF_SIZE_OPT);
+
+	debug_ringbuf_size = DEBUG_RINGBUF_SIZE;
+	debug_ringbuf_ofs = 0;
+
+	if (debug_ringbuf != NULL) {
+		free(debug_ringbuf);
+		debug_ringbuf = NULL;
+	}
+
+	if (!enabled) {
+		return;
+	}
+
+	if (option != NULL) {
+		cmp = strncmp(option, DEBUG_RINGBUF_SIZE_OPT, optlen);
+		if (cmp == 0) {
+			debug_ringbuf_size = (size_t)strtoull(
+				option + optlen, NULL, 10);
+		}
+	}
+
+	debug_ringbuf = calloc(debug_ringbuf_size + 1, sizeof(char));
+	if (debug_ringbuf == NULL) {
+		return;
+	}
+}
+
+static void debug_ringbuf_log(int msg_level,
+			      const char *msg,
+			      const char *msg_no_nl)
+{
+	size_t msglen = strlen(msg);
+
+	if (debug_ringbuf == NULL) {
+		return;
+	}
+
+	if (msglen + debug_ringbuf_ofs >= debug_ringbuf_size) {
+		debug_ringbuf_ofs = 0;
+	}
+
+	memcpy(debug_ringbuf + debug_ringbuf_ofs, msg, msglen);
+	debug_ringbuf_ofs += msglen;
+}
+
 static struct debug_backend {
 	const char *name;
 	int log_level;
@@ -278,6 +335,11 @@ static struct debug_backend {
 		.log = debug_gpfs_log,
 	},
 #endif
+	{
+		.name = "ringbuf",
+		.log = debug_ringbuf_log,
+		.reload = debug_ringbuf_reload,
+	},
 };
 
 static struct debug_backend *debug_find_backend(const char *name)
-- 
2.7.4



More information about the samba-technical mailing list