[PATCH] New debug backend "ringbuf"

Ralph Böhme slow at samba.org
Thu Jan 19 18:36:56 UTC 2017


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.

Cheerio!
-slow
-------------- next part --------------
From ada0b9e057a22e3c066a8066f5e210c0823dfc56 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/6] 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 9521ff0be62bd4f03a19dd04fc296cf86dac263b 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/6] 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                        | 86 +++++++++++++++++++++++++++++++++
 lib/util/debug.h                        |  3 ++
 3 files changed, 94 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..219d086 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -236,6 +236,87 @@ 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;
+
+	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, 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 +359,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 a8225d954c55acf66281478be745b96de608918e 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 3/6] messaging.idl: add ringbuf message types

Signed-off-by: Ralph Boehme <slow 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 46b95cc826886ccf135d4f196b7fbcc0b18725a1 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 4/6] 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..4ed34df 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("*disabled*\n") + 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 9adc12d10d9d55f85373408d3caf803f15887cb6 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 5/6] 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..a50409b 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("*disabled*\n") + 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 f2ab00af00ef249847ddeebb7a64955835c647b3 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 6/6] smbcontrol: add ringbuf-log

Signed-off-by: Ralph Boehme <slow at samba.org>
---
 docs-xml/manpages/smbcontrol.1.xml |  7 +++++++
 source3/utils/smbcontrol.c         | 43 ++++++++++++++++++++++++++++++++++++++
 2 files changed, 50 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..595fffa 100644
--- a/source3/utils/smbcontrol.c
+++ b/source3/utils/smbcontrol.c
@@ -886,6 +886,48 @@ 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;
+}
+
 /* Perform a dmalloc mark */
 
 static bool do_dmalloc_mark(struct tevent_context *ev_ctx,
@@ -1385,6 +1427,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