Skip to contentSkip to conversation

CLD: End-to-end verbosity

PATCH In review Pete Zaitcev 2 participants 5 messages Apr 1, 2010 – Apr 7, 2010 Library code

lore
Share & tools
lore
#0 lore raw

PATCH 1/3 CLD: End-to-end verbosity

It has been observed that it's not possible to enable the session-level verbose dump with -v switch of cldcli anymore (post XDR and ncld).

The main issue is that it is impossible to set the session verbosity by an application control. Secondary issue is that if application attempts to change the verbosity level, it cannot do so for newly-created sessions, because the session structure is allocated when session is created.

Contributing to the confusion is the desire not to enable excessive verbosity in the CLD sessions whenever debugging is requested.

To fix these issues, the patch does the following:

- Drops all commented-out inserts that assign additional verbosity from libraries. Permits top-level applications to specify verbosity (what cldcli -v was intended to do).

- Splits per-packet verbosity away from debugging messages.

- Establishes -v to mean "CLD protocol verbosity" across applications and the daemon. The existing -D now controls the program debugging only, and there is no bit mask. However in case of cld it continues to accept a numeric argument. It is compatible, does not hurt anything and may be used in the future.

Coincidentially this fixes the crash whenever there's a resolution failure for an SRV record.

---
 include/cldc.h       |    1 
 include/hail_log.h   |   24 +++++----
 include/ncld.h       |    2 
 lib/cldc.c           |  104 ++++++++++++++++++++++++-----------------
 server/server.c      |   26 +++++++---
 test/basic-io.c      |    4 -
 test/basic-session.c |    2 
 test/lock-file.c     |    2 
 tools/cldcli.c       |   14 +++--
 tools/cldfuse.c      |    2 
 10 files changed, 109 insertions(+), 72 deletions(-)

commit 433d6a8b6e3c5ecadf54b3142ce6f60e95b00b8a

Author: Master <[email protected]>
Date:   Wed Mar 31 18:07:21 2010 -0600

End-to-end verbosity.

include/cldc.h +0 -1
index b3e4f07..12acd32 100644
@@ -97,7 +97,6 @@ struct cldc_ops {
 				const void *buf, size_t buflen);
 	void		(*event)(void *private, struct cldc_session *,
 				 struct cldc_fh *, uint32_t);
-	void		(*errlog)(int prio, const char *fmt, ...);
 };
 
 /** a single CLD client session */
include/hail_log.h +15 -9
index 88074a3..53a6780 100644
@@ -10,31 +10,37 @@
 #endif
 
 struct hail_log {
-	void (*func)(int prio, const char *fmt, ...)
-		ATTR_PRINTF(2,3);
-	bool verbose;
+	void (*func)(int prio, const char *fmt, ...) ATTR_PRINTF(2,3);
+	bool debug;		/* unmutes HAIL_DEBUG */
+	bool verbose;		/* enables CLD session verbosity */
 };
 
-/** Print out a debug message if 'verbose' is enabled */
-#define HAIL_DEBUG(log, ...) \
+/** Print out a CLD session debug message if enabled */
+#define HAIL_VERBOSE(log, ...) \
 	if ((log)->verbose) { \
 		(log)->func(LOG_DEBUG, __VA_ARGS__); \
 	}
 
+/** Print out an application debug message if enabled */
+#define HAIL_DEBUG(log, ...) \
+	if ((log)->debug) { \
+		(log)->func(LOG_DEBUG, __VA_ARGS__); \
+	}
+
 /** Print out an informational log message */
 #define HAIL_INFO(log, ...) \
-	(log)->func(LOG_INFO, __VA_ARGS__);
+	(log)->func(LOG_INFO, __VA_ARGS__)
 
 /** Print out a warning message */
 #define HAIL_WARN(log, ...) \
-	(log)->func(LOG_WARNING, __VA_ARGS__);
+	(log)->func(LOG_WARNING, __VA_ARGS__)
 
 /** Print out an error message */
 #define HAIL_ERR(log, ...) \
-	(log)->func(LOG_ERR, __VA_ARGS__);
+	(log)->func(LOG_ERR, __VA_ARGS__)
 
 /** Print out a critical warning message */
 #define HAIL_CRIT(log, ...) \
-	(log)->func(LOG_CRIT, __VA_ARGS__);
+	(log)->func(LOG_CRIT, __VA_ARGS__)
 
 #endif /* __HAIL_LOG_H__ */
include/ncld.h +1 -1
index dbf126a..05f57a2 100644
@@ -72,7 +72,7 @@ struct ncld_read {
 
 extern struct ncld_sess *ncld_sess_open(const char *host, int port,
 	int *error, void (*event)(void *, unsigned int), void *ev_arg,
-	const char *cld_user, const char *cld_key);
+	const char *cld_user, const char *cld_key, struct hail_log *log);
 extern struct ncld_fh *ncld_open(struct ncld_sess *s, const char *fname,
 	unsigned int mode, int *error, unsigned int events,
 	void (*event)(void *, unsigned int), void *ev_arg);
lib/cldc.c +61 -43

215 lines not on this page · raw message

server/server.c +18 -8
index 3208e0f..2d68ee6 100644
@@ -55,7 +55,7 @@ static struct argp_option options[] = {
 	  "Store database environment in DIRECTORY.  Default: "
 	  CLD_DEF_DATADIR },
 	{ "debug", 'D', "LEVEL", 0,
-	  "Set debug output to LEVEL (0 = off, 2 = max)" },
+	  "Set debug output to LEVEL (0 = off, 1 = debugging)" },
 	{ "stderr", 'E', NULL, 0,
 	  "Switch the log to standard error" },
 	{ "foreground", 'F', NULL, 0,
@@ -64,6 +64,8 @@ static struct argp_option options[] = {
 	  "Bind to UDP port PORT.  Default: " CLD_DEF_PORT },
 	{ "pid", 'P', "FILE", 0,
 	  "Write daemon process id to FILE.  Default: " CLD_DEF_PIDFN },
+	{ "verbose", 'v', NULL, 0,
+	  "Enable the session-level verbosity" },
 	{ "strict-free", 1001, NULL, 0,
 	  "For memory-checker runs.  When shutting down server, free local "
 	  "heap, rather than simply exit(2)ing and letting OS clean up." },
@@ -117,7 +119,6 @@ static void applog(int prio, const char *fmt, ...)
 
 struct hail_log srv_log = {
 	.func = applog,
-	.verbose = 0,
 };
 
 int udp_tx(int sock_fd, struct sockaddr *addr, socklen_t addr_len,
@@ -918,9 +919,14 @@ static error_t parse_opt (int key, char *arg, struct argp_state *state)
 		cld_srv.data_dir = arg;
 		break;
 	case 'D':
-		if (atoi(arg) >= 0 && atoi(arg) <= 2)
-			srv_log.verbose = atoi(arg);
-		else {
+		switch (atoi(arg)) {
+		case 0:
+			srv_log.debug = false;
+			break;
+		case 1:
+			srv_log.debug = true;
+			break;
+		default:
 			fprintf(stderr, "invalid debug level: '%s'\n", arg);
 			argp_usage(state);
 		}
@@ -949,6 +955,9 @@ static error_t parse_opt (int key, char *arg, struct argp_state *state)
 	case 'P':
 		cld_srv.pid_file = arg;
 		break;
+	case 'v':
+		srv_log.verbose = true;
+		break;
 
 	case 1001:			/* --strict-free */
 		strict_free = true;
@@ -1120,9 +1129,10 @@ int main (int argc, char *argv[])
 	if (rc)
 		goto err_out_pid;
 
-	HAIL_INFO(&srv_log, "initialized: verbose %u%s",
-	       srv_log.verbose,
-	       strict_free ? ", strict-free" : "");
+	HAIL_INFO(&srv_log, "initialized: %s%s%s",
+		  srv_log.debug ? "debug" : "nodebug",
+		  srv_log.verbose ? ", verbose" : "",
+		  strict_free ? ", strict-free" : "");
 
 	/*
 	 * execute main loop
test/basic-io.c +2 -2
index 31bfcab..1741590 100644
@@ -40,7 +40,7 @@ static int test_write(int port)
 	int error;
 
 	nsess = ncld_sess_open(TEST_HOST, port, &error, NULL, NULL,
-			     TEST_USER, TEST_USER_KEY);
+			     TEST_USER, TEST_USER_KEY, NULL);
 	if (!nsess) {
 		fprintf(stderr, "ncld_sess_open(host %s port %u) failed: %d\n",
 			TEST_HOST, port, error);
@@ -74,7 +74,7 @@ static int test_read(int port)
 	int error;
 
 	nsess = ncld_sess_open(TEST_HOST, port, &error, NULL, NULL,
-			     TEST_USER, TEST_USER_KEY);
+			     TEST_USER, TEST_USER_KEY, NULL);
 	if (!nsess) {
 		fprintf(stderr, "ncld_sess_open(host %s port %u) failed: %d\n",
 			TEST_HOST, port, error);
test/basic-session.c +1 -1
index 6caf046..c3e2a98 100644
@@ -45,7 +45,7 @@ int main (int argc, char *argv[])
 		return -1;
 
 	nsess = ncld_sess_open(TEST_HOST, port, &error, NULL, NULL,
-			     TEST_USER, TEST_USER_KEY);
+			     TEST_USER, TEST_USER_KEY, NULL);
 	if (!nsess) {
 		fprintf(stderr, "ncld_sess_open(host %s port %u) failed: %d\n",
 			TEST_HOST, port, error);
test/lock-file.c +1 -1
index d0ea9c1..36cc62c 100644
@@ -50,7 +50,7 @@ int main (int argc, char *argv[])
 		return -1;
 
 	nsess = ncld_sess_open(TEST_HOST, port, &error, NULL, NULL,
-			     TEST_USER, TEST_USER_KEY);
+			     TEST_USER, TEST_USER_KEY, NULL);
 	if (!nsess) {
 		fprintf(stderr, "ncld_sess_open(host %s port %u) failed: %d\n",
 			TEST_HOST, port, error);
tools/cldcli.c +9 -5
index 2a2c82b..78887fc 100644
@@ -98,7 +98,6 @@ static void applog(int prio, const char *fmt, ...)
 
 static struct hail_log cli_log = {
 	.func = applog,
-	.verbose = 0,
 };
 
 static void sess_event(void *private, uint32_t what)
@@ -630,9 +629,14 @@ static error_t parse_opt (int key, char *arg, struct argp_state *state)
 {
 	switch(key) {
 	case 'D':
-		if (atoi(arg) >= 0 && atoi(arg) <= 2)
-			cli_log.verbose = atoi(arg);
-		else {
+		switch (atoi(arg)) {
+		case 0:
+			cli_log.debug = false;
+			break;
+		case 1:
+			cli_log.debug = true;
+			break;
+		default:
 			fprintf(stderr, TAG ": invalid debug level: '%s'\n",
 				arg);
 			argp_usage(state);
@@ -711,7 +715,7 @@ int main (int argc, char *argv[])
 	dr = host_list->data;
 
 	nsess = ncld_sess_open(dr->host, dr->port, &error, sess_event, NULL,
-			     "cldcli", "cldcli");
+			     "cldcli", "cldcli", &cli_log);
 	if (!nsess) {
 		if (error < 1000) {
 			fprintf(stderr, TAG ": cannot open CLD session: %s\n",
tools/cldfuse.c +1 -1
index f40ad75..2cba917 100644
@@ -375,7 +375,7 @@ int main(int argc, char *argv[])
 	dr = param.host_list->data;
 
 	sess = ncld_sess_open(dr->host, dr->port, &error, sess_event, NULL,
-			     "cldfuse", "cldfuse");
+			     "cldfuse", "cldfuse", &cldfuse_log);
 	if (!sess) {
 		if (error < 1000) {
 			fprintf(stderr, TAG ": cannot open CLD session: %s\n",
#1 lore raw
Quoted 14 lines · Pete Zaitcev
server/server.c +1 -1
index 3208e0f..2d68ee6 100644
@@ -55,7 +55,7 @@ static struct argp_option options[] = {
  	  "Store database environment in DIRECTORY.  Default: "
  	  CLD_DEF_DATADIR },
  	{ "debug", 'D', "LEVEL", 0,
-	  "Set debug output to LEVEL (0 = off, 2 = max)" },
+	  "Set debug output to LEVEL (0 = off, 1 = debugging)" },
  	{ "stderr", 'E', NULL, 0,
  	  "Switch the log to standard error" },
  	{ "foreground", 'F', NULL, 0,

server/server.c static struct argp_option options[] = { · line 71

Quoted 8 lines
server/server.c +2 -0
@@ -64,6 +64,8 @@ static struct argp_option options[] = {
  	  "Bind to UDP port PORT.  Default: " CLD_DEF_PORT },
  	{ "pid", 'P', "FILE", 0,
  	  "Write daemon process id to FILE.  Default: " CLD_DEF_PIDFN },
+	{ "verbose", 'v', NULL, 0,
+	  "Enable the session-level verbosity" },
  	{ "strict-free", 1001, NULL, 0,
  	  "For memory-checker runs.  When shutting down server, free local "
  	  "heap, rather than simply exit(2)ing and letting OS clean up." },

As is hinted by the current code's debugging switch being an integer 'level' value, the server [and client?] has increasing levels of verbosity. The debug levels are

0: key messages affecting server operation, only 1: debugging output enabled, sans per-packet output 2: debugging output enabled, including per-packet output

ie. clearly ordered by increasing value == increased verbosity.

As is clearly illustrated when I cut the patch down to the above snippet, the user interface you have created gives the user two "knobs" for log verbosity, and it is not clear to a casual user which knob controls which sets of messages. That makes for a -more- confusing user interface, because the user must constantly ask themselves the question "do I need debug? or verbose? I don't know!"

Additionally, this interface changes runs counter to other tools, which increase verbosity with added "-v" switches -- analagous to the existing integer-based debug level interface.

If it is truly your desire to permit fine-grained selection of certain classes of messages, then don't dick around! Go ahead and create a bitmap "log mask" which permits fine-grained selection of various messages, much like netif_msg_* and netif_msg_init() in the kernel's include/linux/netdevice.h.

Having two switches, -d and -v, for different, undocumented classes of message just increases confusion. Put yourself in the mind of a user trying to figure out which is which.

I readily admit the __internal implementation__ resulting from your patches is a useful cleanup, but at a macro level, it merely increases logging user interface confusion.

Jeff

#2 lore raw
Quoted 5 lines · On Tue, 06 Apr 2010 10:40:33 -0400 Jeff Garzik <[email protected]> wrote:

The debug levels are

0: key messages affecting server operation, only 1: debugging output enabled, sans per-packet output 2: debugging output enabled, including per-packet output

The previous patch did just that:

@@ -918,9 +917,17 @@ static error_t parse_opt (int key, char *arg, struct argp_state *state)
cld_srv.data_dir = arg;
break;
case 'D':
- if (atoi(arg) >= 0 && atoi(arg) <= 2)
- srv_log.verbose = atoi(arg);
- else {
+ switch (atoi(arg)) {
+ case 0:
+ break;
+ case 1:
+ srv_log.debug = true;
+ break;
+ case 2:
+ srv_log.debug = true;
+ srv_log.verbose = true;
+ break;
+ default:
fprintf(stderr, "invalid debug level: '%s'\n", arg); argp_usage(state);
}

Why did you reject it?

Quoted 1 line

... the user interface you have created gives the user two "knobs"

I was your idea, not mine. Do you want me to REMOVE -v from cldcli now?

-- Pete

#3 lore raw
Quoted 11 lines · Pete Zaitcev
Quoted 5 lines · On Tue, 06 Apr 2010 10:40:33 -0400 Jeff Garzik<[email protected]> wrote:

The debug levels are

0: key messages affecting server operation, only 1: debugging output enabled, sans per-packet output 2: debugging output enabled, including per-packet output

The previous patch did just that:
Why did you reject it?

That's a damned good question. I have no idea. Did I ever reply to that patch? It looks like I fscked up and missed it?

Jeff

#4 lore raw
Quoted 10 lines · On Wed, 07 Apr 2010 00:36:32 -0400 Jeff Garzik <[email protected]> wrote:
Quoted 9 lines · Pete Zaitcev
Quoted 5 lines · On Tue, 06 Apr 2010 10:40:33 -0400 Jeff Garzik<[email protected]> wrote:

The debug levels are

0: key messages affecting server operation, only 1: debugging output enabled, sans per-packet output 2: debugging output enabled, including per-packet output

Quoted 5 lines
Quoted 2 lines

The previous patch did just that:
Why did you reject it?

That's a damned good question. I have no idea. Did I ever reply to that patch? It looks like I fscked up and missed it?

Apparently no reply (by e-mail):
http://marc.info/?l=hail-devel&m=126575343714155&w=2

I recall you said that "users hate bitmasks" on IRC or in other thread, so I thought that -D and -v would be right (effectively a bitmask but no hexadecimal at least).

-- Pete