all: unified framework for reporting errors/warnings/info messages to stderr/syslog

7 files changed, 167 insertions, 64 deletions

diff --git a/src/Makefile b/src/Makefile
index d7df654..8814b15 100644
--- a/src/Makefile
+++ b/src/Makefile
@@ -2,7 +2,7 @@ progs-y			+= squark-filter squark-auth-snmp squark-auth-ip
 shlibs-y		+= squarkdb.so
 scripts-y		+= sqdb-build.lua
 
-common-objs		+= filterdb.o authdb.o blob.o addr.o config.o
+common-objs		+= filterdb.o authdb.o blob.o addr.o config.o reporting.o
 
 squark-filter-objs	+= squark-filter.o $(common-objs)
 squark-auth-snmp-objs	+= squark-auth-snmp.o $(common-objs)
diff --git a/src/authdb.c b/src/authdb.c
index b9d38c8..a329d8b 100644
--- a/src/authdb.c
+++ b/src/authdb.c
@@ -319,8 +319,7 @@ static inline uint64_t to_category(struct sqdb *db, blob_t c)
 	if (category >= 0)
 		return 1ULL << category;
 
-	fprintf(stderr, "WARNING: unknown category '%.*s'\n",
-		c.len, c.ptr);
+	report_warning("Unknown category '%.*s'\n", c.len, c.ptr);
 	return 0;
 }
 
diff --git a/src/reporting.c b/src/reporting.c
new file mode 100644
index 0000000..329d850
--- /dev/null
+++ b/src/reporting.c
@@ -0,0 +1,69 @@
+#include <stdio.h>
+#include <stdarg.h>
+#include <unistd.h>
+#include <sys/types.h>
+#include <syslog.h>
+
+#include "reporting.h"
+
+int verbosity_level = REPORT_WARNING;
+static int syslog_flag = 0;
+/* for converting our own levels to syslog's levels: */
+static int log_levels[5] = { LOG_ALERT, LOG_ERR, LOG_WARNING, LOG_INFO, LOG_DEBUG };
+
+void reporting_init(const char *program_name)
+{
+	openlog(program_name, LOG_PID, LOG_USER);
+	/* reporting to syslog is on by default if stderr is not printed at a terminal */
+	if (!isatty(fileno(stderr)))
+		reporting_use_syslog(1);
+}
+
+void reporting_use_syslog(int flag)
+{
+	syslog_flag = flag;
+}
+
+void reporting_verbosity(int level)
+{
+	verbosity_level = level;
+}
+
+void report_message(int level, const char *format, ...)
+{
+	va_list args;
+	va_start(args, format);
+
+	if(syslog_flag || level == REPORT_ALERT) {
+		syslog(LOG_USER | log_levels[level], format, args);
+		/* va_list can only be used once */
+		va_end(args);
+		va_start(args, format);
+	}
+
+	vfprintf(stderr, format, args);
+	va_end(args);
+}
+
+/* For messages which contain sensitive information, and should not be shown to
+ * all users: */
+void report_private_message(int level, const char *format, ...)
+{
+	if(level <= verbosity_level)
+	{
+		va_list args;
+		va_start(args, format);
+
+		if(syslog_flag || level == REPORT_ALERT) {
+			syslog(LOG_AUTHPRIV | log_levels[level], format, args);
+			/* va_list can only be used once */
+			va_end(args);
+			va_start(args, format);
+		}
+
+		if (getuid() == 0) /* being run by root */
+			vfprintf(stderr, format, args);
+
+		va_end(args);
+	}
+}
\ No newline at end of file
diff --git a/src/reporting.h b/src/reporting.h
new file mode 100644
index 0000000..c4f1c60
--- /dev/null
+++ b/src/reporting.h
@@ -0,0 +1,28 @@
+#ifndef REPORTING_H
+#define REPORTING_H
+
+/* message severity levels */
+#define REPORT_ALERT   0
+#define REPORT_ERROR   1
+#define REPORT_WARNING 2
+#define REPORT_INFO    3
+#define REPORT_DEBUG   4
+
+extern int verbosity_level;
+
+void reporting_init(const char *program_name);
+void reporting_use_syslog(int flag);
+void reporting_verbosity(int level); /* setter */
+
+/* rather than using report_message directly, use one of the below macros */
+void report_message(int level, const char *format, ...);
+void report_private_message(int level, const char *format, ...);
+
+/* macros are used to minimize the performance impact of disabled (due to verbosity level) 'report' calls */
+#define report_alert(format, ...)   if(REPORT_ALERT <= verbosity_level)   report_message(REPORT_ALERT, format, ##__VA_ARGS__)
+#define report_error(format, ...)   if(REPORT_ERROR <= verbosity_level)   report_message(REPORT_ERROR, format, ##__VA_ARGS__)
+#define report_warning(format, ...) if(REPORT_WARNING <= verbosity_level) report_message(REPORT_WARNING, format, ##__VA_ARGS__)
+#define report_info(format, ...)    if(REPORT_INFO <= verbosity_level)    report_message(REPORT_INFO, format, ##__VA_ARGS__)
+#define report_debug(format, ...)   if(REPORT_DEBUG <= verbosity_level)   report_message(REPORT_DEBUG, format, ##__VA_ARGS__)
+
+#endif
\ No newline at end of file
diff --git a/src/squark-auth-ip.c b/src/squark-auth-ip.c
index 9b6ab15..677c008 100644
--- a/src/squark-auth-ip.c
+++ b/src/squark-auth-ip.c
@@ -18,6 +18,7 @@
 #include "blob.h"
 #include "authdb.h"
 #include "filterdb.h"
+#include "reporting.h"
 
 #define DO_LOGIN	-1
 #define DO_OVERRIDE	-2
@@ -120,7 +121,9 @@ int main(int argc, char **argv)
 	sockaddr_any ipaddr = { .any.sa_family = AF_UNSPEC };
 	blob_t ip = BLOB_NULL, username = BLOB_NULL;
 
-	while ((opt = getopt(argc, argv, "Vi:u:olpLr")) != -1) {
+	reporting_init("squark-auth-ip");
+
+	while ((opt = getopt(argc, argv, "Vi:u:olpLrsqv::")) != -1) {
 		switch (opt) {
 		case 'V':
 			fprintf(stderr, "squark-auth-ip %s\n", squark_version);
@@ -128,8 +131,7 @@ int main(int argc, char **argv)
 		case 'i':
 			ip = BLOB_STRLEN(optarg);
 			if (!addr_parse(ip, &ipaddr)) {
-				fprintf(stderr, "'%s' does not look like IP-address\n",
-					optarg);
+				report_error("'%s' does not look like IP-address\n", optarg);
 				return 1;
 			}
 			break;
@@ -151,17 +153,28 @@ int main(int argc, char **argv)
 		case 'r':
 			running = DO_REFRESH;
 			break;
+		case 's':
+			reporting_use_syslog(1);
+			break;
+		case 'q':
+			reporting_verbosity(REPORT_ALERT);
+			break;
+		case 'v':
+			if (optarg == 0)
+				reporting_verbosity(REPORT_INFO);
+			else if (*optarg == 'v')
+				reporting_verbosity(REPORT_DEBUG);
+			break;
 		}
 	}
 
 	now = time(NULL);
 	if (sqdb_open(&db, squark_dbname) < 0) {
-		fprintf(stderr, "%s: failed to open squarkdb\n",
-			squark_dbname);
+		report_error("%s: failed to open squarkdb\n", squark_dbname);
 		goto err_sqdb;
 	}
 	if (authdb_open(&adb, &adbc, &db) < 0) {
-		fprintf(stderr, "Failed to initialize authdb\n");
+		report_error("Failed to initialize authdb\n");
 		goto err_adb;
 	}
 
@@ -171,20 +184,20 @@ int main(int argc, char **argv)
 		void *token;
 
 		if (ipaddr.any.sa_family == AF_UNSPEC) {
-			fprintf(stderr, "IP-address not specified\n");
+			report_error("IP-address not specified\n");
 			return 2;
 		}
 
 		token = authdb_get(&adb, &ipaddr, &entry, 1);
 		if (token == NULL) {
-			fprintf(stderr, "Failed to get authdb record\n");
+			report_error("Failed to get authdb record\n");
 			return 3;
 		}
 
 		switch (running) {
 		case DO_LOGIN:
 			if (blob_is_null(username)) {
-				fprintf(stderr, "Username not specified\n");
+				report_error("Username not specified\n");
 				return 2;
 			}
 			authdb_clear_entry(&entry);
diff --git a/src/squark-auth-snmp.c b/src/squark-auth-snmp.c
index 9a35d33..05832d4 100644
--- a/src/squark-auth-snmp.c
+++ b/src/squark-auth-snmp.c
@@ -19,7 +19,6 @@
 
 #include <fcntl.h>
 #include <stdio.h>
-#include <syslog.h>
 #include <string.h>
 #include <unistd.h>
 
@@ -31,12 +30,7 @@
 #include "addr.h"
 #include "authdb.h"
 #include "filterdb.h"
-
-#if 0
-#define dbg_printf(args...) printf(args)
-#else
-#define dbg_printf(args...)
-#endif
+#include "reporting.h"
 
 /* Compile time configurables */
 #define SWITCH_HASH_SIZE		128
@@ -110,7 +104,6 @@ struct switch_info;
 static int num_queries = 0;
 static int running = TRUE;
 static int kick_out = FALSE;
-static int do_syslog = FALSE;
 
 static struct sqdb db;
 static struct authdb adb;
@@ -615,12 +608,7 @@ static void auth_completed(struct auth_context *auth)
 			authdb_commit_login(token, &entry, current_time, &adbc);
 		}
 
-		if (do_syslog) {
-			syslog(LOG_AUTHPRIV | LOG_INFO,
-				"%s authenticated as %.*s",
-				addr_print(&auth->addr),
-				uf.len, uf.ptr);
-		}
+		report_private_message(REPORT_INFO, "%s authenticated as %.*s", addr_print(&auth->addr), uf.len, uf.ptr);
 	} else {
 		if (token != NULL)
 			authdb_commit_logout(token);
@@ -629,12 +617,7 @@ static void auth_completed(struct auth_context *auth)
 		blob_push(&b, BLOB_STRLEN(auth->token));
 		blob_push(&b, BLOB_STR(" ERR\n"));
 
-		if (do_syslog) {
-			syslog(LOG_AUTHPRIV | LOG_WARNING,
-				"%s failed: %s",
-				addr_print(&auth->addr),
-				auth->status_msg);
-		}
+		report_private_message(REPORT_WARNING, "%s failed: %s", addr_print(&auth->addr), auth->status_msg);
 	}
 	b = blob_pushed(BLOB_BUF(tmp), b);
 	write(STDOUT_FILENO, b.ptr, b.len);
@@ -746,7 +729,7 @@ static int auth_handle_portinfo_reply(int oper, netsnmp_session *s, int reqid, n
 	snprintf(auth->status_msg, sizeof(auth->status_msg)-1,
 		 "required info missing: info_available=%08x",
 		 auth->info_available);
-	dbg_printf("%s\n", auth->status_msg);
+	report_debug("%s\n", auth->status_msg);
 
 done:
 	if (kick_out && auth_ok(auth))
@@ -798,7 +781,7 @@ static void auth_query_port_info(struct auth_context *auth)
 	snprintf(auth->status_msg, sizeof(auth->status_msg)-1,
 		 "%s: query port info (%d)",
 		 si->session->peername, auth->local_port);
-	dbg_printf("%s\n", auth->status_msg);
+	report_debug("%s\n", auth->status_msg);
 
 	auth_talk_snmp(auth, si->session, pdu, auth_handle_portinfo_reply);
 }
@@ -830,12 +813,12 @@ static int auth_handle_lldp_reply(int oper, netsnmp_session *s, int reqid, netsn
 			blob_pull_oid(&res);
 			blob_pull_iana_afn(&res, &spi->link_partner);
 
-			dbg_printf("%s: lldp neighbour is %s\n",
+			report_debug("%s: lldp neighbour is %s\n",
 				s->peername, addr_print(&spi->link_partner));
 
 			if (management_prefix != 0 &&
 			    addr_prefix_cmp(&spi->link_partner, &management_subnet, management_prefix) != 0) {
-				dbg_printf("%s: not matching %s/%d\n",
+				report_debug("%s: not matching %s/%d\n",
 					   s->peername, addr_print(&management_subnet), management_prefix);
 				addr_invalidate(&spi->link_partner);
 			}
@@ -917,7 +900,7 @@ static void auth_query_lldp(struct auth_context *auth, int root_query)
 		 "%s: query LLDP tables (%s, base port %d)",
 		 si->session->peername, root_query ? "link" : "lacp slaves",
 		 auth->lldp_port[0]);
-	dbg_printf("%s\n", auth->status_msg);
+	report_debug("%s\n", auth->status_msg);
 
 	cache_talk_snmp(&spi->cache_control, si->session, pdu, auth_handle_lldp_reply, auth);
 }
@@ -998,7 +981,7 @@ static void auth_query_fib(struct auth_context *auth)
 		 "%s: probe FIB (%sBRIDGE-MIB)",
 		 si->session->peername,
 		 si->q_vlan_fdb_id>=0 ? "Q-" : "");
-	dbg_printf("%s\n", auth->status_msg);
+	report_debug("%s\n", auth->status_msg);
 	auth_talk_snmp(auth, si->session, pdu, auth_handle_fib_reply);
 }
 
@@ -1059,7 +1042,7 @@ static void auth_query_switch_info(struct auth_context *auth)
 	snprintf(auth->status_msg, sizeof(auth->status_msg)-1,
 		 "%s: refresh switch information",
 		 si->session->peername);
-	dbg_printf("%s\n", auth->status_msg);
+	report_debug("%s\n", auth->status_msg);
 
 	if (!cache_refresh(&si->cache_control, auth, auth_query_fib))
 		return;
@@ -1067,7 +1050,7 @@ static void auth_query_switch_info(struct auth_context *auth)
 	snprintf(auth->status_msg, sizeof(auth->status_msg)-1,
 		 "%s: query switch information",
 		 si->session->peername);
-	dbg_printf("%s\n", auth->status_msg);
+	report_debug("%s\n", auth->status_msg);
 
 	pdu = snmp_pdu_create(SNMP_MSG_GET);
 	snmp_add_null_var(pdu, oid_const(SNMPv2_MIB_sysName));
@@ -1138,7 +1121,7 @@ void start_authentication(blob_t token, blob_t ip)
 		 "%s: map IP %s to MAC on VLAN %d",
 		 l3_root_dev->session->peername,
 		 addr_print(&auth->addr), l3_if_ndx);
-	dbg_printf("%s\n", auth->status_msg);
+	report_debug("%s\n", auth->status_msg);
 
 	auth_talk_snmp(auth, l3_root_dev->session, pdu, auth_handle_arp_reply);
 }
@@ -1218,11 +1201,12 @@ int main(int argc, char **argv)
 	fd_set fdset;
 	int opt, fds, block, i, rc = 1;
 
+	reporting_init("squark-auth-snmp");
+
 	setenv("MIBS", "", 1);
 	init_snmp("squark-auth-snmp");
-	openlog("squark-auth-snmp", LOG_PID, LOG_DAEMON);
 
-	while ((opt = getopt(argc, argv, "Vc:r:i:R:v:f:T:KsM:")) != -1) {
+	while ((opt = getopt(argc, argv, "Vc:r:i:R:v:f:T:KsM:sq")) != -1) {
 		switch (opt) {
 		case 'V':
 			fprintf(stderr, "squark-auth-snmp %s\n", squark_version);
@@ -1251,32 +1235,34 @@ int main(int argc, char **argv)
 		case 'K':
 			kick_out = TRUE;
 			break;
-		case 's':
-			do_syslog = TRUE;
-			break;
 		case 'M':
 			if (!addr_parse_prefix(BLOB_STRLEN(optarg), &management_subnet, &management_prefix)) {
-				fprintf(stderr, "'%s' is not a valid network prefix\n", optarg);
+				report_error("'%s' is not a valid network prefix\n", optarg);
 				return 1;
 			}
 			break;
+		case 's':
+			reporting_use_syslog(1);
+			break;
+		case 'q':
+			reporting_verbosity(REPORT_ALERT);
+			break;
 		}
 	}
 	argc -= optind;
 	argv += optind;
 
 	if (l3_root == NULL || l3_ifname == NULL || l2_vlan == NULL) {
-		fprintf(stderr, "Mandatory information missing\n");
+		report_error("Mandatory information missing\n");
 		return 1;
 	}
 
 	if (sqdb_open(&db, squark_dbname) < 0) {
-		fprintf(stderr, "%s: failed to open squarkdb\n",
-			squark_dbname);
+		report_error("%s: failed to open squarkdb\n", squark_dbname);
 		goto err_sqdb;
 	}
 	if (authdb_open(&adb, &adbc, &db) < 0) {
-		fprintf(stderr, "Failed to initialize authdb\n");
+		report_error("Failed to initialize authdb\n");
 		goto err_adb;
 	}
 
diff --git a/src/squark-filter.c b/src/squark-filter.c
index 1955a59..19c3583 100644
--- a/src/squark-filter.c
+++ b/src/squark-filter.c
@@ -23,12 +23,7 @@
 #include "addr.h"
 #include "filterdb.h"
 #include "authdb.h"
-
-#if 0
-#define dbg_printf(x...) fprintf(stderr, x)
-#else
-#define dbg_printf(x...)
-#endif
+#include "reporting.h"
 
 #define FILTER_OVERRIDE_TIMEOUT		(15*60)
 
@@ -244,7 +239,7 @@ static int url_classify(struct url_info *url, struct sqdb *db)
 			if (blob_is_null(got))
 				break;
 
-			dbg_printf("Trying '%.*s'\n", key.len, key.ptr);
+			report_debug("Trying '%.*s'\n", key.len, key.ptr);
 
 			previ = i;
 			i = cmph_search_packed(cmph, key.ptr, key.len);
@@ -282,7 +277,7 @@ static int url_classify(struct url_info *url, struct sqdb *db)
 	blob_push_urldecode(&keybuf, url->path);
 	keylimits = blob_pushed(BLOB_BUF(buffer), keybuf);
 
-	dbg_printf("Checking path components on '%.*s'\n", keylimits.len, keylimits.ptr);
+	report_debug("Checking path components on '%.*s'\n", keylimits.len, keylimits.ptr);
 
 	while (indx[i].has_paths) {
 		/* add one more path component */
@@ -290,7 +285,7 @@ static int url_classify(struct url_info *url, struct sqdb *db)
 		if (blob_is_null(got))
 			break;
 
-		dbg_printf("Trying with path '%.*s'\n", key.len, key.ptr);
+		report_debug("Trying with path '%.*s'\n", key.len, key.ptr);
 
 		previ = i;
 		i = cmph_search_packed(cmph, key.ptr, key.len);
@@ -459,21 +454,34 @@ int main(int argc, char **argv)
 {
 	int rc = 1, opt;
 
-	while ((opt = getopt(argc, argv, "V")) != -1) {
+	reporting_init("squark-filter");
+
+	while ((opt = getopt(argc, argv, "Vsqv::")) != -1) {
 		switch (opt) {
 		case 'V':
 			fprintf(stderr, "squark-filter %s\n", squark_version);
 			return 0;
+		case 's':
+			reporting_use_syslog(1);
+			break;
+		case 'q':
+			reporting_verbosity(REPORT_ALERT);
+			break;
+		case 'v':
+			if (optarg == 0)
+				reporting_verbosity(REPORT_INFO);
+			else if (*optarg == 'v')
+				reporting_verbosity(REPORT_DEBUG);
+			break;
 		}
 	}
 
 	if (sqdb_open(&db, squark_dbname) < 0) {
-		fprintf(stderr, "%s: failed to open squarkdb\n",
-			squark_dbname);
+		report_error("%s: failed to open squarkdb\n", squark_dbname);
 		goto err_sqdb;
 	}
 	if (authdb_open(&adb, &adbc, &db) < 0) {
-		fprintf(stderr, "Failed to initialize authdb\n");
+		report_error("Failed to initialize authdb\n");
 		goto err_adb;
 	}