Fixing the many DEBUG statements that have confusing info ...

Christof Schmitt cs at samba.org
Wed Oct 21 19:38:46 UTC 2015


On Mon, Oct 19, 2015 at 09:54:50AM -0700, Jeremy Allison wrote:
> On Mon, Oct 19, 2015 at 09:10:22AM +0200, Volker Lendecke wrote:
> > On Wed, Oct 14, 2015 at 11:27:04AM +1100, Martin Schwenke wrote:
> > > Unless I'm misunderstanding something, that means going through a lot of
> > > code and removing __func__ (or similar) in places where is has been
> > > explicitly added.
> > > 
> > > I'd suggest a variation of DEBUG() to include the location... but there
> > > are already a lot of variations.  :-)
> > 
> > What about adding it do Christofs new DBG_ style macros? We don't have
> > too many of those yet, so we could still do the sweeping change.
> > 
> > While there, we could deprecate DEBUG and add DBG_ as a recommendation
> > to README.Coding for future patches.
> 
> Sounds like a good plan to me !

I took a stab at this, see attached patches.

Christof
-------------- next part --------------
From 598754e6f4b602ce102b11b153787cbb20c1607f Mon Sep 17 00:00:00 2001
From: Christof Schmitt <cs at samba.org>
Date: Wed, 21 Oct 2015 11:07:35 -0700
Subject: [PATCH 1/3] debug: Prefix messages from DBG_* with function name

Signed-off-by: Christof Schmitt <cs at samba.org>
---
 lib/util/debug.h |   18 +++++++++++++-----
 1 files changed, 13 insertions(+), 5 deletions(-)

diff --git a/lib/util/debug.h b/lib/util/debug.h
index e399379..2a0a05c 100644
--- a/lib/util/debug.h
+++ b/lib/util/debug.h
@@ -204,6 +204,14 @@ extern int  *DEBUGLEVEL_CLASS;
 #define DEBUGSEP(level)\
 	DEBUG((level),("===============================================================\n"))
 
+/* Prefix messages with the function name */
+#define DBG_PREFIX(level, body ) \
+	(void)( ((level) <= MAX_DEBUG_LEVEL) &&			\
+		unlikely(DEBUGLEVEL_CLASS[ DBGC_CLASS ] >= (level))	\
+		&& (dbghdrclass(level, DBGC_CLASS, __location__, __func__ )) \
+		&& (dbgtext("%s: ", __func__))				\
+		&& (dbgtext body) )
+
 /*
  * Debug levels matching RFC 3164
  */
@@ -213,11 +221,11 @@ extern int  *DEBUGLEVEL_CLASS;
 #define DBGLVL_INFO	 5	/* informational message */
 #define DBGLVL_DEBUG	10	/* debug-level message */
 
-#define DBG_ERR(...)		DEBUG(DBGLVL_ERR,	(__VA_ARGS__))
-#define DBG_WARNING(...)	DEBUG(DBGLVL_WARNING,	(__VA_ARGS__))
-#define DBG_NOTICE(...)	DEBUG(DBGLVL_NOTICE,	(__VA_ARGS__))
-#define DBG_INFO(...)		DEBUG(DBGLVL_INFO,	(__VA_ARGS__))
-#define DBG_DEBUG(...)		DEBUG(DBGLVL_DEBUG,	(__VA_ARGS__))
+#define DBG_ERR(...)		DBG_PREFIX(DBGLVL_ERR,		(__VA_ARGS__))
+#define DBG_WARNING(...)	DBG_PREFIX(DBGLVL_WARNING,	(__VA_ARGS__))
+#define DBG_NOTICE(...)	DBG_PREFIX(DBGLVL_NOTICE,	(__VA_ARGS__))
+#define DBG_INFO(...)		DBG_PREFIX(DBGLVL_INFO,	(__VA_ARGS__))
+#define DBG_DEBUG(...)		DBG_PREFIX(DBGLVL_DEBUG,	(__VA_ARGS__))
 
 /* The following definitions come from lib/debug.c  */
 
-- 
1.7.1


From 66515e0332f58f9d4b4b7afed2dbba5297fc7ac5 Mon Sep 17 00:00:00 2001
From: Christof Schmitt <cs at samba.org>
Date: Wed, 21 Oct 2015 11:07:57 -0700
Subject: [PATCH 2/3] Remove function name from callers of DBG_*

It is now added automatically.

Signed-off-by: Christof Schmitt <cs at samba.org>
---
 lib/util/charset/util_str.c       |    4 ++--
 source3/lib/ctdbd_conn.c          |    2 +-
 source3/lib/dbwrap/dbwrap_ctdb.c  |    2 +-
 source3/lib/dbwrap/dbwrap_watch.c |   11 +++++------
 source3/lib/messages_dgm_ref.c    |   11 +++++------
 source3/lib/util.c                |    4 ++--
 6 files changed, 16 insertions(+), 18 deletions(-)

diff --git a/lib/util/charset/util_str.c b/lib/util/charset/util_str.c
index c1b81f1..ef8a82a 100644
--- a/lib/util/charset/util_str.c
+++ b/lib/util/charset/util_str.c
@@ -545,13 +545,13 @@ char *strstr_m(const char *src, const char *findstr)
 	frame = talloc_stackframe();
 
 	if (!push_ucs2_talloc(frame, &src_w, src, &converted_size)) {
-		DBG_WARNING("strstr_m: src malloc fail\n");
+		DBG_WARNING("src malloc fail\n");
 		TALLOC_FREE(frame);
 		return NULL;
 	}
 
 	if (!push_ucs2_talloc(frame, &find_w, findstr, &converted_size)) {
-		DBG_WARNING("strstr_m: find malloc fail\n");
+		DBG_WARNING("find malloc fail\n");
 		TALLOC_FREE(frame);
 		return NULL;
 	}
diff --git a/source3/lib/ctdbd_conn.c b/source3/lib/ctdbd_conn.c
index c7c6356..9187ee7 100644
--- a/source3/lib/ctdbd_conn.c
+++ b/source3/lib/ctdbd_conn.c
@@ -431,7 +431,7 @@ static int ctdbd_init_connection(TALLOC_CTX *mem_ctx,
 
 	conn->sockname = talloc_strdup(conn, sockname);
 	if (conn->sockname == NULL) {
-		DBG_ERR("%s: talloc failed\n", __func__);
+		DBG_ERR("talloc failed\n");
 		ret = ENOMEM;
 		goto fail;
 	}
diff --git a/source3/lib/dbwrap/dbwrap_ctdb.c b/source3/lib/dbwrap/dbwrap_ctdb.c
index 9066beb..457f427 100644
--- a/source3/lib/dbwrap/dbwrap_ctdb.c
+++ b/source3/lib/dbwrap/dbwrap_ctdb.c
@@ -1664,7 +1664,7 @@ struct db_context *db_open_ctdb(TALLOC_CTX *mem_ctx,
 		fd = tdb_fd(db_ctdb->wtdb->tdb);
 		ret = fchmod(fd, mode);
 		if (ret == -1) {
-			DBG_WARNING("%s: fchmod failed: %s\n", __func__,
+			DBG_WARNING("fchmod failed: %s\n",
 				    strerror(errno));
 			TALLOC_FREE(result);
 			return NULL;
diff --git a/source3/lib/dbwrap/dbwrap_watch.c b/source3/lib/dbwrap/dbwrap_watch.c
index 426fe77..09e67fb 100644
--- a/source3/lib/dbwrap/dbwrap_watch.c
+++ b/source3/lib/dbwrap/dbwrap_watch.c
@@ -295,8 +295,7 @@ static void dbwrap_watch_record_stored_fn(TDB_DATA key, TDB_DATA data,
 	size_t i, num_ids;
 
 	if ((data.dsize % sizeof(struct server_id)) != 0) {
-		DBG_WARNING("%s: Invalid data size: %zu\n", __func__,
-			    data.dsize);
+		DBG_WARNING("Invalid data size: %zu\n", data.dsize);
 		return;
 	}
 	num_ids = data.dsize / sizeof(struct server_id);
@@ -312,8 +311,8 @@ static void dbwrap_watch_record_stored_fn(TDB_DATA key, TDB_DATA data,
 					    key.dptr, key.dsize);
 		if (!NT_STATUS_IS_OK(status)) {
 			struct server_id_buf tmp;
-			DBG_WARNING("%s: messaging_send to %s failed: %s\n",
-				    __func__, server_id_str_buf(dst, &tmp),
+			DBG_WARNING("messaging_send to %s failed: %s\n",
+				    server_id_str_buf(dst, &tmp),
 				    nt_errstr(status));
 		}
 	}
@@ -346,8 +345,8 @@ static void dbwrap_watch_record_stored(struct db_context *db,
 		return;
 	}
 	if (!NT_STATUS_IS_OK(status)) {
-		DBG_WARNING("%s: dbwrap_parse_record failed: %s\n",
-			    __func__, nt_errstr(status));
+		DBG_WARNING("dbwrap_parse_record failed: %s\n",
+			    nt_errstr(status));
 	}
 }
 
diff --git a/source3/lib/messages_dgm_ref.c b/source3/lib/messages_dgm_ref.c
index e3b2d88..3ea8b9d 100644
--- a/source3/lib/messages_dgm_ref.c
+++ b/source3/lib/messages_dgm_ref.c
@@ -73,8 +73,7 @@ void *messaging_dgm_ref(TALLOC_CTX *mem_ctx, struct tevent_context *ev,
 
 		ret = messaging_dgm_init(ev, unique, socket_dir, lockfile_dir,
 					 msg_dgm_ref_recv, NULL);
-		DBG_DEBUG("%s: messaging_dgm_init returned %s\n", __func__,
-			  strerror(ret));
+		DBG_DEBUG("messaging_dgm_init returned %s\n", strerror(ret));
 		if (ret != 0) {
 			DEBUG(10, ("messaging_dgm_init failed: %s\n",
 				   strerror(ret)));
@@ -86,8 +85,8 @@ void *messaging_dgm_ref(TALLOC_CTX *mem_ctx, struct tevent_context *ev,
 	} else {
 		int ret;
 		ret = messaging_dgm_get_unique(getpid(), unique);
-		DBG_DEBUG("%s: messaging_dgm_get_unique returned %s\n",
-			  __func__, strerror(ret));
+		DBG_DEBUG("messaging_dgm_get_unique returned %s\n",
+			  strerror(ret));
 		if (ret != 0) {
 			TALLOC_FREE(result);
 			*err = ret;
@@ -103,7 +102,7 @@ void *messaging_dgm_ref(TALLOC_CTX *mem_ctx, struct tevent_context *ev,
 		}
 	}
 
-	DBG_DEBUG("%s: unique = %"PRIu64"\n", __func__, *unique);
+	DBG_DEBUG("unique = %"PRIu64"\n", *unique);
 
 	refs = tmp_refs;
 
@@ -140,7 +139,7 @@ static int msg_dgm_ref_destructor(struct msg_dgm_ref *r)
 
 	TALLOC_FREE(r->tevent_handle);
 
-	DBG_DEBUG("%s: refs=%p\n", __func__, refs);
+	DBG_DEBUG("refs=%p\n", refs);
 
 	if (refs == NULL) {
 		messaging_dgm_destroy();
diff --git a/source3/lib/util.c b/source3/lib/util.c
index 7c24f8a..3a8bc67 100644
--- a/source3/lib/util.c
+++ b/source3/lib/util.c
@@ -1967,8 +1967,8 @@ struct server_id pid_to_procid(pid_t pid)
 
 	ret = messaging_dgm_get_unique(pid, &unique);
 	if (ret != 0) {
-		DBG_WARNING("%s: messaging_dgm_get_unique failed: %s\n",
-			    __func__, strerror(ret));
+		DBG_WARNING("messaging_dgm_get_unique failed: %s\n",
+			    strerror(ret));
 	}
 
 	return (struct server_id) {
-- 
1.7.1


From aec5171031d96678a30b44d36d407f9b42dc64af Mon Sep 17 00:00:00 2001
From: Christof Schmitt <cs at samba.org>
Date: Wed, 21 Oct 2015 11:12:22 -0700
Subject: [PATCH 3/3] README.Coding: Update section about debug macros

Signed-off-by: Christof Schmitt <cs at samba.org>
---
 README.Coding |   24 +++++++++++++++---------
 1 files changed, 15 insertions(+), 9 deletions(-)

diff --git a/README.Coding b/README.Coding
index 9073b77..29bad1b 100644
--- a/README.Coding
+++ b/README.Coding
@@ -417,15 +417,21 @@ The only exception is the test code that depends repeated use of calls
 like CHECK_STATUS, CHECK_VAL and others.
 
 
-Function names in DEBUG statements
-----------------------------------
+DEBUG statements
+----------------
 
-Many DEBUG statements contain the name of the function they appear in. This is
-not a good idea, as this is prone to bitrot. Function names change, code
-moves, but the DEBUG statements are not adapted. Use %s and __func__ for this:
+Use these following macros instead of DEBUG:
 
-Bad Example:
-	DEBUG(0, ("strstr_m: src malloc fail\n"));
+DBG_ERR	log level 0		error conditions
+DBG_WARNING	log level 1		warning conditions
+DBG_NOTICE	log level 3		normal, but significant, condition
+DBG_INFO	log level 5		informational message
+DBG_DEBUG	log level 10		debug-level message
 
-Good Example:
-	DEBUG(0, ("%s: src malloc fail\n", __func__));
+Example usage:
+
+DBG_ERR("Memory allocation failed\n");
+DBG_DEBUG("Received %d bytes\n", count);
+
+The messages from these macros are automatically prefixed with the
+function name.
-- 
1.7.1



More information about the samba-technical mailing list