src: add run-time statistics via `-s runtime'

This patch adds run-time statistics that you can check via
`conntrackd -s runtime'. This information is useful for
trouble-shooting.

This patch replaces several log messages that can be triggered in
runtime. The idea behind this patch is to avoid log message flooding
under errors.

Signed-off-by: Pablo Neira Ayuso <pablo@netfilter.org>

5 files changed, 137 insertions, 21 deletions

diff --git a/conntrackd.8 b/conntrackd.8
index 7d38740..cd1e2bd 100644
--- a/conntrackd.8
+++ b/conntrackd.8
@@ -44,10 +44,11 @@ option will not flush your internal and external cache).
 .BI "-k "
 Kill the daemon
 .TP
-.BI "-s " "[|network|cache]"
+.BI "-s " "[|network|cache|runtime]"
 Dump statistics. If no parameter is passed, it displays the general statistics.
 If "network" is passed as parameter it displays the networking statistics.
 If "cache" is passed as parameter, it shows the extended cache statistics.
+If "runtime" is passed as parameter, it shows the run-time statistics.
 .TP
 .BI "-R "
 Force a resync against the kernel connection tracking table
diff --git a/include/conntrackd.h b/include/conntrackd.h
index 98934ce..df36ec4 100644
--- a/include/conntrackd.h
+++ b/include/conntrackd.h
@@ -28,6 +28,7 @@
 #define DEBUG_INFO	27	/* show debug info (if any)		*/
 #define STATS_NETWORK	28	/* extended network stats		*/
 #define STATS_CACHE	29	/* extended cache stats			*/
+#define STATS_RUNTIME	30	/* extended runtime stats		*/
 
 #define DEFAULT_CONFIGFILE	"/etc/conntrackd/conntrackd.conf"
 #define DEFAULT_LOCKFILE	"/var/lock/conntrackd.lock"
@@ -111,8 +112,32 @@ struct ct_general_state {
 	struct fds			*fds;
 
 	/* statistics */
-	uint64_t 			bytes[NFCT_DIR_MAX];
-	uint64_t 			packets[NFCT_DIR_MAX];
+	struct {
+		uint64_t 		bytes[NFCT_DIR_MAX];
+		uint64_t 		packets[NFCT_DIR_MAX];
+
+		time_t			daemon_start_time;
+
+		uint64_t		nl_events_received;
+		uint64_t		nl_events_filtered;
+		uint32_t		nl_events_unknown_type;
+		uint32_t		nl_catch_event_failed;
+		uint32_t		nl_overrun;
+		uint32_t		nl_dump_unknown_type;
+		uint32_t		nl_kernel_table_flush;
+		uint32_t		nl_kernel_table_resync;
+
+		uint32_t		child_process_failed;
+		uint32_t		child_process_error_segfault;
+		uint32_t		child_process_error_term;
+
+		uint32_t		select_failed;
+		uint32_t		wait_failed;
+
+		uint32_t		local_read_failed;
+		uint32_t		local_unknown_request;
+
+	} stats;
 };
 
 #define STATE_SYNC(x) state.sync->x
diff --git a/src/main.c b/src/main.c
index f621a2e..ebd975b 100644
--- a/src/main.c
+++ b/src/main.c
@@ -43,7 +43,7 @@ static const char usage_client_commands[] =
 	"  -i, display content of the internal cache\n"
 	"  -e, display the content of the external cache\n"
 	"  -k, kill conntrack daemon\n"
-	"  -s  [|network|cache], dump statistics\n"
+	"  -s  [|network|cache|runtime], dump statistics\n"
 	"  -R, resync with kernel conntrack table\n"
 	"  -n, request resync with other node (only FT-FW and NOTRACK modes)\n"
 	"  -x, dump cache in XML format (requires -i or -e)"
@@ -165,6 +165,10 @@ int main(int argc, char *argv[])
 						 strlen(argv[i+1])) == 0) {
 					action = STATS_CACHE;
 					i++;
+				} else if (strncmp(argv[i+1], "runtime",
+						 strlen(argv[i+1])) == 0) {
+					action = STATS_RUNTIME;
+					i++;
 				} else {
 					fprintf(stderr, "ERROR: unknown "
 							"parameter `%s' for "
diff --git a/src/run.c b/src/run.c
index ee985f4..5b01dc7 100644
--- a/src/run.c
+++ b/src/run.c
@@ -32,6 +32,7 @@
 #include <unistd.h>
 #include <sys/wait.h>
 #include <string.h>
+#include <time.h>
 
 void killer(int foo)
 {
@@ -68,7 +69,7 @@ static void child(int foo)
 				continue;
 			if (errno == ECHILD)
 				break;
-			dlog(LOG_ERR, "wait has failed (%s)", strerror(errno));
+			STATE(stats).wait_failed++;
 			break;
 		}
 		if (!WIFSIGNALED(status))
@@ -78,6 +79,8 @@ static void child(int foo)
 		case SIGSEGV:
 			dlog(LOG_ERR, "child process (pid=%u) has aborted, "
 				      "received signal SIGSEGV (crashed)", ret);
+			STATE(stats).child_process_failed++;
+			STATE(stats).child_process_error_segfault++;
 			break;
 		case SIGINT:
 		case SIGTERM:
@@ -85,16 +88,87 @@ static void child(int foo)
 			dlog(LOG_ERR, "child process (pid=%u) has aborted, "
 				      "received termination signal (%u)",
 				      ret, WTERMSIG(status));
+			STATE(stats).child_process_failed++;
+			STATE(stats).child_process_error_term++;
 			break;
 		default:
 			dlog(LOG_NOTICE, "child process (pid=%u) "
 					 "received signal (%u)", 
 					 ret, WTERMSIG(status));
+			STATE(stats).child_process_failed++;
 			break;
 		}
 	}
 }
 
+static void uptime(char *buf, size_t bufsiz)
+{
+	time_t tmp;
+	int updays, upminutes, uphours;
+	size_t size = 0;
+
+	time(&tmp);
+	tmp = tmp - STATE(stats).daemon_start_time;
+	updays = (int) tmp / (60*60*24);
+	if (updays) {
+		size = snprintf(buf, bufsiz, "%d day%s ",
+				updays, (updays != 1) ? "s" : "");
+	}
+	upminutes = (int) tmp / 60;
+	uphours = (upminutes / 60) % 24;
+	upminutes %= 60;
+	if(uphours) {
+		snprintf(buf + size, bufsiz, "%d h %d min", uphours, upminutes);
+	} else {
+		snprintf(buf + size, bufsiz, "%d min", upminutes);
+	}
+}
+
+static void dump_stats_runtime(int fd)
+{
+	char buf[1024], uptime_string[512];
+	int size;
+
+	uptime(uptime_string, sizeof(uptime_string));
+	size = snprintf(buf, sizeof(buf),
+			"daemon uptime: %s\n\n"
+			"netlink stats:\n"
+			"\tevents received:\t%20llu\n"
+			"\tevents filtered:\t%20llu\n"
+			"\tevents unknown type:\t\t%12u\n"
+			"\tcatch event failed:\t\t%12u\n"
+			"\tdump unknown type:\t\t%12u\n"
+			"\tnetlink overrun:\t\t%12u\n"
+			"\tflush kernel table:\t\t%12u\n"
+			"\tresync with kernel table:\t%12u\n\n"
+			"runtime stats:\n"
+			"\tchild process failed:\t\t%12u\n"
+			"\t\tchild process segfault:\t%12u\n"
+			"\t\tchild process termsig:\t%12u\n"
+			"\tselect failed:\t\t\t%12u\n"
+			"\twait failed:\t\t\t%12u\n"
+			"\tlocal read failed:\t\t%12u\n"
+			"\tlocal unknown request:\t\t%12u\n\n",
+			uptime_string,
+			(unsigned long long)STATE(stats).nl_events_received,
+			(unsigned long long)STATE(stats).nl_events_filtered,
+			STATE(stats).nl_events_unknown_type,
+			STATE(stats).nl_catch_event_failed,
+			STATE(stats).nl_dump_unknown_type,
+			STATE(stats).nl_overrun,
+			STATE(stats).nl_kernel_table_flush,
+			STATE(stats).nl_kernel_table_resync,
+			STATE(stats).child_process_failed,
+			STATE(stats).child_process_error_segfault,
+			STATE(stats).child_process_error_term,
+			STATE(stats).select_failed,
+			STATE(stats).wait_failed,
+			STATE(stats).local_read_failed,
+			STATE(stats).local_unknown_request);
+
+	send(fd, buf, size, 0);
+}
+
 void local_handler(int fd, void *data)
 {
 	int ret;
@@ -102,7 +176,7 @@ void local_handler(int fd, void *data)
 
 	ret = read(fd, &type, sizeof(type));
 	if (ret == -1) {
-		dlog(LOG_ERR, "can't read from unix socket");
+		STATE(stats).local_read_failed++;
 		return;
 	}
 	if (ret == 0)
@@ -110,17 +184,22 @@ void local_handler(int fd, void *data)
 
 	switch(type) {
 	case FLUSH_MASTER:
+		STATE(stats).nl_kernel_table_flush++;
 		dlog(LOG_NOTICE, "flushing kernel conntrack table");
 		nl_flush_conntrack_table(STATE(request));
 		return;
 	case RESYNC_MASTER:
+		STATE(stats).nl_kernel_table_resync++;
 		dlog(LOG_NOTICE, "resync with master table");
 		nl_dump_conntrack_table(STATE(dump));
 		return;
+	case STATS_RUNTIME:
+		dump_stats_runtime(fd);
+		return;
 	}
 
 	if (!STATE(mode)->local(fd, type, data))
-		dlog(LOG_WARNING, "unknown local request %d", type);
+		STATE(stats).local_unknown_request++;
 }
 
 static void do_overrun_alarm(struct alarm_block *a, void *data)
@@ -133,9 +212,13 @@ static int event_handler(enum nf_conntrack_msg_type type,
 			 struct nf_conntrack *ct,
 			 void *data)
 {
+	STATE(stats).nl_events_received++;
+
 	/* skip user-space filtering if already do it in the kernel */
-	if (ct_filter_conntrack(ct, !CONFIG(filter_from_kernelspace)))
+	if (ct_filter_conntrack(ct, !CONFIG(filter_from_kernelspace))) {
+		STATE(stats).nl_events_filtered++;
 		return NFCT_CB_STOP;
+	}
 
 	switch(type) {
 	case NFCT_T_NEW:
@@ -149,7 +232,7 @@ static int event_handler(enum nf_conntrack_msg_type type,
 			update_traffic_stats(ct);
 		break;
 	default:
-		dlog(LOG_WARNING, "unknown msg from ctnetlink\n");
+		STATE(stats).nl_events_unknown_type++;
 		break;
 	}
 
@@ -168,7 +251,7 @@ static int dump_handler(enum nf_conntrack_msg_type type,
 		STATE(mode)->dump(ct);
 		break;
 	default:
-		dlog(LOG_WARNING, "unknown msg from ctnetlink");
+		STATE(stats).nl_dump_unknown_type++;
 		break;
 	}
 	return NFCT_CB_CONTINUE;
@@ -281,6 +364,8 @@ init(void)
 	if (signal(SIGCHLD, child) == SIG_ERR)
 		return -1;
 
+	time(&STATE(stats).daemon_start_time);
+
 	dlog(LOG_NOTICE, "initialization completed");
 
 	return 0;
@@ -297,7 +382,7 @@ static void __run(struct timeval *next_alarm)
 		if (errno == EINTR)
 			return;
 
-		dlog(LOG_WARNING, "select failed: %s", strerror(errno));
+		STATE(stats).select_failed++;
 		return;
 	}
 
@@ -323,6 +408,8 @@ static void __run(struct timeval *next_alarm)
 				nl_resize_socket_buffer(STATE(event));
 				nl_overrun_request_resync(STATE(overrun));
 				add_alarm(&STATE(overrun_alarm), 2, 0);
+				STATE(stats).nl_catch_event_failed++;
+				STATE(stats).nl_overrun++;
 				break;
 			case ENOENT:
 				/*
@@ -334,8 +421,7 @@ static void __run(struct timeval *next_alarm)
 			case EAGAIN:
 				break;
 			default:
-				dlog(LOG_WARNING,
-				     "event catch says: %s", strerror(errno));
+				STATE(stats).nl_catch_event_failed++;
 				break;
 			}
 		}
diff --git a/src/traffic_stats.c b/src/traffic_stats.c
index 9e40d53..52ca09a 100644
--- a/src/traffic_stats.c
+++ b/src/traffic_stats.c
@@ -21,13 +21,13 @@
 
 void update_traffic_stats(struct nf_conntrack *ct)
 {
-	STATE(bytes)[NFCT_DIR_ORIGINAL] +=
+	STATE(stats).bytes[NFCT_DIR_ORIGINAL] +=
 		nfct_get_attr_u32(ct, ATTR_ORIG_COUNTER_BYTES);
-	STATE(bytes)[NFCT_DIR_REPLY] +=
+	STATE(stats).bytes[NFCT_DIR_REPLY] +=
 		nfct_get_attr_u32(ct, ATTR_REPL_COUNTER_BYTES);
-	STATE(packets)[NFCT_DIR_ORIGINAL] += 
+	STATE(stats).packets[NFCT_DIR_ORIGINAL] += 
 		nfct_get_attr_u32(ct, ATTR_ORIG_COUNTER_PACKETS);
-	STATE(packets)[NFCT_DIR_REPLY] +=
+	STATE(stats).packets[NFCT_DIR_REPLY] +=
 		nfct_get_attr_u32(ct, ATTR_REPL_COUNTER_PACKETS);
 }
 
@@ -35,10 +35,10 @@ void dump_traffic_stats(int fd)
 {
 	char buf[512];
 	int size;
-	uint64_t bytes = STATE(bytes)[NFCT_DIR_ORIGINAL] +
-			  STATE(bytes)[NFCT_DIR_REPLY];
-	uint64_t packets = STATE(packets)[NFCT_DIR_ORIGINAL] +
-			    STATE(packets)[NFCT_DIR_REPLY];
+	uint64_t bytes = STATE(stats).bytes[NFCT_DIR_ORIGINAL] +
+			  STATE(stats).bytes[NFCT_DIR_REPLY];
+	uint64_t packets = STATE(stats).packets[NFCT_DIR_ORIGINAL] +
+			    STATE(stats).packets[NFCT_DIR_REPLY];
 
 	size = sprintf(buf, "traffic processed:\n");
 	size += sprintf(buf+size, "%20llu Bytes      ", (unsigned long long)bytes);