[PATCH] New debug backend "ringbuf"

Ralph Böhme slow at samba.org
Fri Jan 20 08:32:56 UTC 2017


On Thu, Jan 19, 2017 at 07:36:56PM +0100, Ralph Böhme wrote:
> On Thu, Jan 19, 2017 at 02:17:22PM +0100, Volker Lendecke wrote:
> > On Thu, Jan 19, 2017 at 11:36:07AM +0100, Ralph Böhme wrote:
> > > > ok, so here is a ringbuf only patchset. I'll post the pidl enum stuff in a new thread.
> > > 
> > > sorry, ENOPATCH, here it is.
> > 
> > The debug_get_ringbuf_size() API is a bit confusing. If I look at
> > debug_ringbuf_log(), you can send one byte more than
> > debug_get_ringbuf_size() returns. Not sure how to deal with that
> > properly, but from an API perspective it is a bit unexpected.
> 
> indeed. Updated patchset attached that also does additional sanity checks in
> debug_ringbuf_log() for overflows.

and here's another updated version with a set of fixups from Volker (received
privately) all squashed.

I found another place where debug_backend.option should be freed, in
debug_set_backends() which is called when we're reloading config. It's the
second commit and can be the first one can be fixuped with it.

Please review&push if ok. Thanks!

Cheerio!
-slow
-------------- next part --------------
From 375654d905c3a3c6d304a73064cfccdcb177f0ca 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/7] 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>
Reviewed-by: Volker Lendecke <vl at samba.org>
---
 lib/util/debug.c | 30 +++++++++++++++++++++---------
 1 file changed, 21 insertions(+), 9 deletions(-)

diff --git a/lib/util/debug.c b/lib/util/debug.c
index 37582db..d64e2eb 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;
 	}
@@ -508,6 +514,8 @@ static void debug_init(void);
 
 void gfree_debugsyms(void)
 {
+	unsigned i;
+
 	TALLOC_FREE(classname_table);
 
 	if ( DEBUGLEVEL_CLASS != debug_class_list_initial ) {
@@ -518,6 +526,10 @@ void gfree_debugsyms(void)
 	debug_num_classes = 0;
 
 	state.initialized = false;
+
+	for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
+		SAFE_FREE(debug_backends[i].option);
+	}
 }
 
 /****************************************************************************
-- 
2.7.4


From 0bc3a3bc60e8276a130ea2b6c2cb46130e179827 Mon Sep 17 00:00:00 2001
From: Ralph Boehme <slow at samba.org>
Date: Fri, 20 Jan 2017 09:26:06 +0100
Subject: [PATCH 2/7] fixup! debug: parse, store and pass backend option

free option when reloading config

debug_set_backends() is called when we're reloading config, make sure we
don't leak option.
---
 lib/util/debug.c | 1 +
 1 file changed, 1 insertion(+)

diff --git a/lib/util/debug.c b/lib/util/debug.c
index d64e2eb..12a9b1b 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -360,6 +360,7 @@ static void debug_set_backends(const char *param)
 	 * disabled
 	 */
 	for (i = 0; i < ARRAY_SIZE(debug_backends); i++) {
+		SAFE_FREE(debug_backends[i].option);
 		debug_backends[i].new_log_level = -1;
 	}
 
-- 
2.7.4


From f47ff3618e3ef110d463ab3d83eea6bb0ccbb249 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 3/7] 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                        | 83 +++++++++++++++++++++++++++++++++
 lib/util/debug.h                        |  3 ++
 3 files changed, 91 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 12a9b1b..08954c3 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -236,6 +236,84 @@ static void debug_gpfs_log(int msg_level,
 }
 #endif /* HAVE_GPFS */
 
+#define DEBUG_RINGBUF_SIZE (1024 * 1024)
+#define DEBUG_RINGBUF_SIZE_OPT "size="
+
+static char *debug_ringbuf;
+static size_t debug_ringbuf_size;
+static size_t debug_ringbuf_ofs;
+
+/* We ensure in debug_ringbuf_log() that this is always \0 terminated */
+char *debug_get_ringbuf(void)
+{
+	return debug_ringbuf;
+}
+
+/* Return the size of the ringbuf (including a \0 terminator) */
+size_t debug_get_ringbuf_size(void)
+{
+	return debug_ringbuf_size;
+}
+
+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;
+
+	SAFE_FREE(debug_ringbuf);
+
+	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, 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);
+	size_t allowed_size;
+
+	if (debug_ringbuf == NULL) {
+		return;
+	}
+
+	/* Ensure the buffer is always \0 terminated */
+	allowed_size = debug_ringbuf_size - 1;
+
+	if (msglen > allowed_size) {
+		return;
+	}
+
+	if ((debug_ringbuf_ofs + msglen) < debug_ringbuf_ofs) {
+		return;
+	}
+
+	if ((debug_ringbuf_ofs + msglen) > allowed_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 +356,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)
diff --git a/lib/util/debug.h b/lib/util/debug.h
index b50bf50..43c6aa0 100644
--- a/lib/util/debug.h
+++ b/lib/util/debug.h
@@ -287,4 +287,7 @@ typedef void (*debug_callback_fn)(void *private_ptr, int level, const char *msg)
  */
 void debug_set_callback(void *private_ptr, debug_callback_fn fn);
 
+char *debug_get_ringbuf(void);
+size_t debug_get_ringbuf_size(void);
+
 #endif /* _SAMBA_DEBUG_H */
-- 
2.7.4


From 4279e6d5a001480409ec9cef4dc521a7add9bc5d Mon Sep 17 00:00:00 2001
From: Ralph Boehme <slow at samba.org>
Date: Mon, 9 Jan 2017 22:35:17 +0100
Subject: [PATCH 4/7] messaging.idl: add ringbuf message types

Signed-off-by: Ralph Boehme <slow at samba.org>
Reviewed-by: Volker Lendecke <vl at samba.org>
---
 librpc/idl/messaging.idl | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/librpc/idl/messaging.idl b/librpc/idl/messaging.idl
index a54d13c..032f95e 100644
--- a/librpc/idl/messaging.idl
+++ b/librpc/idl/messaging.idl
@@ -45,6 +45,9 @@ interface messaging
 		MSG_PREFORK_CHILD_EVENT		= 0x0031,
 		MSG_PREFORK_PARENT_EVENT	= 0x0032,
 
+		MSG_REQ_RINGBUF_LOG		= 0x0033,
+		MSG_RINGBUF_LOG			= 0x0034,
+
 		/* nmbd messages */
 		MSG_FORCE_ELECTION		= 0x0101,
 		MSG_WINS_NEW_ENTRY		= 0x0102,
-- 
2.7.4


From 2547b0ed803d477a10de384b1c3126db7b438b26 Mon Sep 17 00:00:00 2001
From: Ralph Boehme <slow at samba.org>
Date: Sun, 8 Jan 2017 14:08:27 +0100
Subject: [PATCH 5/7] s3/debug: listen for MSG_REQ_RINGBUF_LOG

Signed-off-by: Ralph Boehme <slow at samba.org>
---
 lib/util/debug_s3.c | 21 +++++++++++++++++++++
 1 file changed, 21 insertions(+)

diff --git a/lib/util/debug_s3.c b/lib/util/debug_s3.c
index 98e7b00..72a6e2b 100644
--- a/lib/util/debug_s3.c
+++ b/lib/util/debug_s3.c
@@ -21,6 +21,7 @@
 #include "includes.h"
 #include "librpc/gen_ndr/messaging.h"
 #include "messages.h"
+#include "lib/util/memory.h"
 
 /* This is the Samba3-specific implementation of reopen_logs(), which
  * calls out to the s3 loadparm code, and means that we don't depend
@@ -98,9 +99,29 @@ static void debuglevel_message(struct messaging_context *msg_ctx,
 
 	TALLOC_FREE(message);
 }
+
+static void debug_ringbuf_log(struct messaging_context *msg_ctx,
+			      void *private_data,
+			      uint32_t msg_type,
+			      struct server_id src,
+			      DATA_BLOB *data)
+{
+	char *log = debug_get_ringbuf();
+	size_t logsize = debug_get_ringbuf_size();
+
+	if (log == NULL) {
+		log = discard_const_p(char, "*disabled*\n");
+		logsize = strlen(log) + 1;
+	}
+
+	messaging_send_buf(msg_ctx, src, MSG_RINGBUF_LOG, (uint8_t *)log, logsize);
+}
+
 void debug_register_msgs(struct messaging_context *msg_ctx)
 {
 	messaging_register(msg_ctx, NULL, MSG_DEBUG, debug_message);
 	messaging_register(msg_ctx, NULL, MSG_REQ_DEBUGLEVEL,
 			   debuglevel_message);
+	messaging_register(msg_ctx, NULL, MSG_REQ_RINGBUF_LOG,
+			   debug_ringbuf_log);
 }
-- 
2.7.4


From c4a0f56c7f3a80b487ec5e551a3b3561018395f0 Mon Sep 17 00:00:00 2001
From: Ralph Boehme <slow at samba.org>
Date: Mon, 9 Jan 2017 22:33:55 +0100
Subject: [PATCH 6/7] s4/messaging: register for MSG_REQ_RINGBUF_LOG

Signed-off-by: Ralph Boehme <slow at samba.org>
---
 source4/lib/messaging/messaging.c | 22 ++++++++++++++++++++++
 1 file changed, 22 insertions(+)

diff --git a/source4/lib/messaging/messaging.c b/source4/lib/messaging/messaging.c
index 6fca9b8..22d3ad8 100644
--- a/source4/lib/messaging/messaging.c
+++ b/source4/lib/messaging/messaging.c
@@ -114,6 +114,27 @@ static void pool_message(struct imessaging_context *msg, void *private_data,
 	talloc_free(report);
 }
 
+static void ringbuf_log_msg(struct imessaging_context *msg,
+			    void *private_data,
+			    uint32_t msg_type,
+			    struct server_id src,
+			    DATA_BLOB *data)
+{
+	char *log = debug_get_ringbuf();
+	size_t logsize = debug_get_ringbuf_size();
+	DATA_BLOB blob;
+
+	if (log == NULL) {
+		log = discard_const_p(char, "*disabled*\n");
+		logsize = strlen(log) + 1;
+	}
+
+	blob.data = (uint8_t *)log;
+	blob.length = logsize;
+
+	imessaging_send(msg, src, MSG_RINGBUF_LOG, &blob);
+}
+
 /*
   return uptime of messaging server via irpc
 */
@@ -408,6 +429,7 @@ struct imessaging_context *imessaging_init(TALLOC_CTX *mem_ctx,
 	imessaging_register(msg, NULL, MSG_PING, ping_message);
 	imessaging_register(msg, NULL, MSG_REQ_POOL_USAGE, pool_message);
 	imessaging_register(msg, NULL, MSG_IRPC, irpc_handler);
+	imessaging_register(msg, NULL, MSG_REQ_RINGBUF_LOG, ringbuf_log_msg);
 	IRPC_REGISTER(msg, irpc, IRPC_UPTIME, irpc_uptime, msg);
 
 	DLIST_ADD(msg_ctxs, msg);
-- 
2.7.4


From 3501c13c18c329b66be1fbfa100fed5d8f641645 Mon Sep 17 00:00:00 2001
From: Ralph Boehme <slow at samba.org>
Date: Sun, 8 Jan 2017 16:47:30 +0100
Subject: [PATCH 7/7] smbcontrol: add ringbuf-log

Signed-off-by: Ralph Boehme <slow at samba.org>
---
 docs-xml/manpages/smbcontrol.1.xml |  7 ++++++
 source3/utils/smbcontrol.c         | 44 ++++++++++++++++++++++++++++++++++++++
 2 files changed, 51 insertions(+)

diff --git a/docs-xml/manpages/smbcontrol.1.xml b/docs-xml/manpages/smbcontrol.1.xml
index 99f141d..127e919 100644
--- a/docs-xml/manpages/smbcontrol.1.xml
+++ b/docs-xml/manpages/smbcontrol.1.xml
@@ -257,6 +257,13 @@
 	</varlistentry>
 
 	<varlistentry>
+	<term>ringbuf-log</term>
+	<listitem><para>Fetch and print the ringbuf log. Requires
+	<parameter>logging = ringbuf</parameter>. Available for smbd, winbindd
+	and nmbd.</para></listitem>
+	</varlistentry>
+
+	<varlistentry>
 	<term>drvupgrade</term>
 	<listitem><para>Force clients of printers using specified driver 
 	to update their local version of the driver. Can only be 
diff --git a/source3/utils/smbcontrol.c b/source3/utils/smbcontrol.c
index ad602b3..df9b8ac 100644
--- a/source3/utils/smbcontrol.c
+++ b/source3/utils/smbcontrol.c
@@ -886,6 +886,49 @@ static bool do_poolusage(struct tevent_context *ev_ctx,
 	return num_replies;
 }
 
+/* Fetch and print the ringbuf log */
+
+static void print_ringbuf_log_cb(struct messaging_context *msg,
+				 void *private_data,
+				 uint32_t msg_type,
+				 struct server_id pid,
+				 DATA_BLOB *data)
+{
+	printf("%s", (const char *)data->data);
+	num_replies++;
+}
+
+static bool do_ringbuflog(struct tevent_context *ev_ctx,
+			  struct messaging_context *msg_ctx,
+			  const struct server_id pid,
+			  const int argc, const char **argv)
+{
+	if (argc != 1) {
+		fprintf(stderr, "Usage: smbcontrol <dest> ringbuf-log\n");
+		return false;
+	}
+
+	messaging_register(msg_ctx, NULL, MSG_RINGBUF_LOG, print_ringbuf_log_cb);
+
+	/* Send a message and register our interest in a reply */
+
+	if (!send_message(msg_ctx, pid, MSG_REQ_RINGBUF_LOG, NULL, 0)) {
+		return false;
+	}
+
+	wait_replies(ev_ctx, msg_ctx, procid_to_pid(&pid) == 0);
+
+	/* No replies were received within the timeout period */
+
+	if (num_replies == 0) {
+		printf("No replies received\n");
+	}
+
+	messaging_deregister(msg_ctx, MSG_RINGBUF_LOG, NULL);
+
+	return num_replies != 0;
+}
+
 /* Perform a dmalloc mark */
 
 static bool do_dmalloc_mark(struct tevent_context *ev_ctx,
@@ -1385,6 +1428,7 @@ static const struct {
 	{ "lockretry", do_lockretry, "Force a blocking lock retry" },
 	{ "brl-revalidate", do_brl_revalidate, "Revalidate all brl entries" },
 	{ "pool-usage", do_poolusage, "Display talloc memory usage" },
+	{ "ringbuf-log", do_ringbuflog, "Display ringbuf log" },
 	{ "dmalloc-mark", do_dmalloc_mark, "" },
 	{ "dmalloc-log-changed", do_dmalloc_changed, "" },
 	{ "shutdown", do_shutdown, "Shut down daemon" },
-- 
2.7.4



More information about the samba-technical mailing list