[PATCH] New debug backend "ringbuf"

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


On Thu, Jan 19, 2017 at 11:31:04AM +0100, Ralph Böhme wrote:
> On Thu, Jan 19, 2017 at 10:10:06AM +0100, Ralph Böhme wrote:
> > On Thu, Jan 19, 2017 at 10:07:06AM +0100, Volker Lendecke wrote:
> > > On Thu, Jan 19, 2017 at 09:07:28AM +0100, Ralph Böhme wrote:
> > > > On Mon, Jan 09, 2017 at 10:45:01PM +0100, Ralph Böhme wrote:
> > > > > Hi!
> > > > > 
> > > > > On Mon, Jan 09, 2017 at 10:16:01PM +0100, Ralph Böhme wrote:
> > > > > > On Tue, Jan 10, 2017 at 10:09:31AM +1300, Andrew Bartlett wrote:
> > > > > > > Can you register it in source4/lib/messaging.c as well, so we can ask a
> > > > > > > 'samba' process the same question?
> > > > > > 
> > > > > > sure, updated patchset on the way...
> > > > > 
> > > > > here we go.
> > > > 
> > > > *ping*
> > > > 
> > > > Anyone time for a review? Thanks!
> > > 
> > > This mixes the messaging.idl changes with the pure debug ringbuf. I
> > > know that it's a bit hairy to get the messaging types right, but is
> > > there a strict reason why MSG_RINGBUF_LOG can't be assigned manually?
> > 
> > the only reason was that I hesitating finding a free slot and choosing a value.
> > 
> > I can surely split that up and assing manually. Afaict the only reason values
> > are acutally assigned manually is that pidl doesn't support mixing automatic
> > enumeration with direct assignment.
> 
> ok, so here is a ringbuf only patchset. I'll post the pidl enum stuff in a new thread.

sorry, ENOPATCH, here it is.

Cheerio!
-slow
-------------- next part --------------
From c5e5bf91ce0f501d00d83cf81a06c89df9c5c243 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 090ec23f7ce66fe86ed43931c82698d5db604abb 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                        | 73 +++++++++++++++++++++++++++++++++
 lib/util/debug.h                        |  3 ++
 3 files changed, 81 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..ee8b193 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -236,6 +236,74 @@ 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;
+
+char *debug_get_ringbuf(void)
+{
+	return debug_ringbuf;
+}
+
+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);
+		}
+	}
+
+	/* Ensure the buffer is always a 0 terminated string */
+	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 +346,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 49958cff802c51feddee2a531d20b5a1a74eec2b 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 a592b45158ff3e02440df9f1b9c835259a852bab 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..1367d16 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() + 1;
+
+	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 ccfe4af8fa6b6c2b6dd2514719455a63b568af9d 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..5b99890 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() + 1;
+	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 170360c954eac3e2fb2c8fc8f8c1fc82634503a3 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