From aa62c8af99ca0c4591b2c0f73c333585885f0f26 Mon Sep 17 00:00:00 2001
From: Steffen Vogel <stvogel@eonerc.rwth-aachen.de>
Date: Tue, 7 Mar 2017 07:13:27 -0400
Subject: [PATCH] reworked new logging facilities and added a unit test for it

---
 include/villas/log.h | 32 ++++++++--------
 lib/log.c            | 90 +++++++++++++++++++++++++++++---------------
 tests/log.c          | 50 ++++++++++++++++++++++++
 3 files changed, 126 insertions(+), 46 deletions(-)
 create mode 100644 tests/log.c

diff --git a/include/villas/log.h b/include/villas/log.h
index d9ae668bc..0189983ef 100644
--- a/include/villas/log.h
+++ b/include/villas/log.h
@@ -35,23 +35,27 @@ enum log_facilities {
 	LOG_CONFIG =	(1L << 10),
 	LOG_HOOK =	(1L << 11),
 	LOG_PATH =	(1L << 12),
-	LOG_MEM =	(1L << 13),
-	LOG_WEB =	(1L << 14),
-	LOG_API =	(1L << 15),
-	LOG_LOG =	(1L << 16),
-	LOG_KERNEL =	(1L << 17),
+	LOG_NODE =	(1L << 13),
+	LOG_MEM =	(1L << 14),
+	LOG_WEB =	(1L << 15),
+	LOG_API =	(1L << 16),
+	LOG_LOG =	(1L << 17),
+	LOG_VFIO =	(1L << 18),
+	LOG_PCI =	(1L << 19),
+	LOG_XIL =	(1L << 20),
 	
 	/* Node-types */
-	LOG_SOCKET =	(1L << 32),
-	LOG_FILE =	(1L << 33),
-	LOG_FPGA =	(1L << 34),
-	LOG_NGSI =	(1L << 35),
-	LOG_WEBSOCKET =	(1L << 36),
-	LOG_OPAL =	(1L << 37),
+	LOG_SOCKET =	(1L << 21),
+	LOG_FILE =	(1L << 22),
+	LOG_FPGA =	(1L << 23),
+	LOG_NGSI =	(1L << 24),
+	LOG_WEBSOCKET =	(1L << 25),
+	LOG_OPAL =	(1L << 26),
 	
 	/* Classes */
-	LOG_NODE =   (0xFFL << 32),
-	LOG_ALL =    ~0xFF 
+	LOG_NODES =	LOG_NODE | LOG_SOCKET | LOG_FILE | LOG_FPGA | LOG_NGSI | LOG_WEBSOCKET | LOG_OPAL,
+	LOG_KERNEL =	LOG_VFIO | LOG_PCI,
+	LOG_ALL =	~0xFF 
 };
 
 struct log {
@@ -104,8 +108,6 @@ int log_set_facility_expression(struct log *l, const char *expression);
 /** Parse logging configuration. */
 int log_parse(struct log *l, config_setting_t *cfg);
 
-int log_lookup_facility(const char *facility_name);
-
 /** Logs variadic messages to stdout.
  *
  * @param lvl The log level
diff --git a/lib/log.c b/lib/log.c
index df532aa56..892b59b51 100644
--- a/lib/log.c
+++ b/lib/log.c
@@ -5,6 +5,7 @@
  *********************************************************************************/
 
 #include <stdio.h>
+#include <stdbool.h>
 #include <string.h>
 #include <time.h>
 #include <errno.h>
@@ -31,9 +32,14 @@ static const char *facilities_strs[] = {
 	"config",	/* LOG_CONFIG */
 	"hook",		/* LOG_HOOK */
 	"path",		/* LOG_PATH */
+	"node",		/* LOG_NODE */
 	"mem",		/* LOG_MEM */
 	"web",		/* LOG_WEB */
 	"api",		/* LOG_API */
+	"log",		/* LOG_LOG */
+	"vfio",		/* LOG_VFIO */
+	"pci",		/* LOG_PCI */
+	"xil",		/* LOG_XIL */
 	
 	/* Node-types */	
 	"socket",	/* LOG_SOCKET */
@@ -41,7 +47,7 @@ static const char *facilities_strs[] = {
 	"fpga",		/* LOG_FPGA */
 	"ngsi",		/* LOG_NGSI */
 	"websocket",	/* LOG_WEBSOCKET */
-	"opal"		/* LOG_OPAL */
+	"opal",		/* LOG_OPAL */
 };
 
 #ifdef __GNUC__
@@ -63,41 +69,49 @@ void log_outdent(int *old)
 
 int log_set_facility_expression(struct log *l, const char *expression)
 {
-	char *copy, *facility_str;
+	bool negate;
+	char *copy, *token;
+	long mask = 0, facilities = 0;
 	
-	enum {
-		NORMAL,
-		NEGATE
-	} mode;
-	
-	if (strlen(expression) <= 0)
-		return -1;
-
-	if (expression[0] == '!') {
-		mode = NEGATE;
-		l->facilities = ~0xFF;
-	}
-	else {
-		mode = NORMAL;
-		l->facilities = 0;
-	}
-
 	copy = strdup(expression);
-	facility_str = strtok(copy, ",");
+	token = strtok(copy, ",");
 
-	while (facility_str != NULL) {
-		for (int i = 0; i < ARRAY_LEN(facilities_strs); i++) {
-			if (strcmp(facilities_strs[i], facility_str)) {
-				switch (mode) {
-					case NORMAL: l->facilities |=  (1 << (i+8));
-					case NEGATE: l->facilities &= ~(1 << (i+8));
+	while (token != NULL) {
+		if (token[0] == '!') {
+			token++;
+			negate = true;
+		}
+		else
+			negate = false;
+
+		/* Check for some classes */
+		if      (!strcmp(token, "all"))
+			mask = LOG_ALL;
+		else if (!strcmp(token, "nodes"))
+			mask = LOG_NODES;
+		else if (!strcmp(token, "kernel"))
+			mask = LOG_KERNEL;
+		else {
+			for (int ind = 0; ind < ARRAY_LEN(facilities_strs); ind++) {
+				if (!strcmp(token, facilities_strs[ind])) {
+					mask = (1 << (ind+8));
+					goto found;
 				}
 			}
+			
+			error("Invalid log class '%s'", token);
 		}
-		
-		facility_str = strtok(NULL, ",");
+
+found:		if (negate)
+			facilities &= ~mask;
+		else
+			facilities |= mask;
+
+		token = strtok(NULL, ",");
 	}
 	
+	l->facilities = facilities;
+	
 	free(copy);
 
 	return l->facilities;
@@ -112,7 +126,7 @@ int log_init(struct log *l, int level, long facilitites)
 	/* Register this log instance globally */
 	log = l;
 
-	debug(LOG_LOG, "Log sub-system intialized: level=%d, faciltities=%#lx", level, facilitites);
+	debug(LOG_LOG | 5, "Log sub-system intialized: level=%d, faciltities=%#lx", level, facilitites);
 
 	return 0;
 }
@@ -171,11 +185,11 @@ int log_parse(struct log *l, config_setting_t *cfg)
 	const char *facilities;
 	
 	if (!config_setting_is_group(cfg))
-		cerror(cfg, "Setting 'logging' must be a group.");
+		cerror(cfg, "Setting 'log' must be a group.");
 
 	config_setting_lookup_int(cfg, "level", &l->level);
 
-	if (config_setting_lookup_string(cfg, "facilties", &facilities))
+	if (config_setting_lookup_string(cfg, "facilities", &facilities))
 		log_set_facility_expression(l, facilities);
 
 	return 0;
@@ -195,6 +209,8 @@ void debug(long class, const char *fmt, ...)
 	
 	int lvl = class &  0xFF;
 	int fac = class & ~0xFF;
+	
+	assert(log);
 
 	if (((fac == 0) || (fac & log->facilities)) && (lvl <= log->level)) {
 		va_start(ap, fmt);
@@ -206,6 +222,8 @@ void debug(long class, const char *fmt, ...)
 void info(const char *fmt, ...)
 {
 	va_list ap;
+	
+	assert(log);
 
 	va_start(ap, fmt);
 	log_vprint(log, LOG_LVL_INFO, fmt, ap);
@@ -215,6 +233,8 @@ void info(const char *fmt, ...)
 void warn(const char *fmt, ...)
 {
 	va_list ap;
+	
+	assert(log);
 
 	va_start(ap, fmt);
 	log_vprint(log, LOG_LVL_WARN, fmt, ap);
@@ -225,6 +245,8 @@ void stats(const char *fmt, ...)
 {
 	va_list ap;
 
+	assert(log);
+
 	va_start(ap, fmt);
 	log_vprint(log, LOG_LVL_STATS, fmt, ap);
 	va_end(ap);
@@ -233,6 +255,8 @@ void stats(const char *fmt, ...)
 void error(const char *fmt, ...)
 {
 	va_list ap;
+	
+	assert(log);
 
 	va_start(ap, fmt);
 	log_vprint(log, LOG_LVL_ERROR, fmt, ap);
@@ -246,6 +270,8 @@ void serror(const char *fmt, ...)
 	va_list ap;
 	char *buf = NULL;
 
+	assert(log);
+
 	va_start(ap, fmt);
 	vstrcatf(&buf, fmt, ap);
 	va_end(ap);
@@ -261,6 +287,8 @@ void cerror(config_setting_t *cfg, const char *fmt, ...)
 	va_list ap;
 	char *buf = NULL;
 
+	assert(log);
+
 	va_start(ap, fmt);
 	vstrcatf(&buf, fmt, ap);
 	va_end(ap);
diff --git a/tests/log.c b/tests/log.c
new file mode 100644
index 000000000..5aee5af96
--- /dev/null
+++ b/tests/log.c
@@ -0,0 +1,50 @@
+/** Unit tests for log functions
+ *
+ * @author Steffen Vogel <stvogel@eonerc.rwth-aachen.de>
+ * @copyright 2017, Institute for Automation of Complex Power Systems, EONERC
+ *********************************************************************************/
+
+#include <criterion/criterion.h>
+#include <criterion/parameterized.h>
+
+#include "log.h"
+
+struct param {
+	char *expression;
+	long expected;
+};
+
+static struct log l;
+
+static void init()
+{
+	log_init(&l, V, LOG_ALL);
+}
+
+static void fini()
+{
+	log_destroy(&l);
+}
+
+ParameterizedTestParameters(log, facility_expression)
+{
+	static struct param params[] = {
+		{ "all,!pool",		LOG_ALL & ~LOG_POOL },
+		{ "pool,!pool",		LOG_POOL & ~LOG_POOL },
+		{ "pool,nodes,!socket",	(LOG_POOL | LOG_NODES) & ~LOG_SOCKET },
+		{ "kernel",		LOG_KERNEL },
+		{ "ngsi",		LOG_NGSI },
+		{ "all",		LOG_ALL },
+		{ "!all",		0 },
+		{ "",			0 }
+	};
+	
+	return cr_make_param_array(struct param, params, ARRAY_LEN(params));
+}
+
+ParameterizedTest(struct param *p, log, facility_expression, .init = init, .fini = fini)
+{
+	log_set_facility_expression(&l, p->expression);
+	
+	cr_assert_eq(l.facilities, p->expected, "log.faciltities is %#lx not %#lx", l.facilities, p->expected);
+}
\ No newline at end of file