lib: refactor memstats logging, fix ACTIVEATEXIT

Move the various destinations handling into lib/memory.c, include
"normal" logging as target, and make `ACTIVEATEXIT` properly non-error
as it was intended to be.

Signed-off-by: David Lamparter <equinox@opensourcerouting.org>

lib/libfrr.c

@@ -1245,10 +1245,6 @@ void frr_early_fini(void)
 
 void frr_fini(void)
 {
-	FILE *fp;
-	char filename[128];
-	int have_leftovers = 0;
-
 	hook_call(frr_fini);
 
 	vty_terminate();
@@ -1289,26 +1285,7 @@ void frr_fini(void)
 
 	frrmod_terminate();
 
-	/* also log memstats to stderr when stderr goes to a file*/
+	log_memstats(di->name, debug_memstats_at_exit);
-	if (debug_memstats_at_exit || !isatty(STDERR_FILENO))
-		have_leftovers = log_memstats(stderr, di->name);
-
-	/* in case we decide at runtime that we want exit-memstats for
-	 * a daemon
-	 * (only do this if we actually have something to print though)
-	 */
-	if (!debug_memstats_at_exit || !have_leftovers)
-		return;
-
-	snprintf(filename, sizeof(filename), "/tmp/frr-memstats-%s-%llu-%llu",
-		 di->name, (unsigned long long)getpid(),
-		 (unsigned long long)time(NULL));
-
-	fp = fopen(filename, "w");
-	if (fp) {
-		log_memstats(fp, di->name);
-		fclose(fp);
-	}
 }
 
 struct json_object *frr_daemon_state_load(void)

lib/log.c

@@ -306,7 +306,7 @@ void memory_oom(size_t size, const char *name)
 	     "out of memory: failed to allocate %zu bytes for %s object",
 	     size, name);
 	zlog_backtrace(LOG_CRIT);
-	log_memstats(stderr, "log");
+	log_memstats(zlog_progname, true);
 	abort();
 }
 

lib/memory.c

@@ -148,35 +148,108 @@ int qmem_walk(qmem_walk_fn *func, void *arg)
 }
 
 struct exit_dump_args {
-	FILE *fp;
+	const char *daemon_name;
-	const char *prefix;
+	bool do_log;
+	bool do_file;
+	bool do_stderr;
 	int error;
+	FILE *fp;
+	struct memgroup *last_mg;
 };
 
+static void qmem_exit_fopen(struct exit_dump_args *eda)
+{
+	char filename[128];
+
+	if (eda->fp || !eda->do_file || !eda->daemon_name)
+		return;
+
+	snprintf(filename, sizeof(filename), "/tmp/frr-memstats-%s-%llu-%llu", eda->daemon_name,
+		 (unsigned long long)getpid(), (unsigned long long)time(NULL));
+	eda->fp = fopen(filename, "w");
+
+	if (!eda->fp) {
+		zlog_err("failed to open memstats dump file %pSQq: %m", filename);
+		/* don't try opening file over and over again */
+		eda->do_file = false;
+	}
+}
+
 static int qmem_exit_walker(void *arg, struct memgroup *mg, struct memtype *mt)
 {
 	struct exit_dump_args *eda = arg;
+	const char *prefix = eda->daemon_name ?: "NONE";
+	char size[32];
 
-	if (!mt) {
+	if (!mt)
-		fprintf(eda->fp,
+		/* iterator calls mg=X, mt=NULL first */
-			"%s: showing active allocations in memory group %s\n",
+		return 0;
-			eda->prefix, mg->name);
 
-	} else if (mt->n_alloc) {
+	if (!mt->n_alloc)
-		char size[32];
+		return 0;
-		if (!mg->active_at_exit)
+
-			eda->error++;
+	if (mt->size != SIZE_VAR)
 		snprintf(size, sizeof(size), "%10zu", mt->size);
-		fprintf(eda->fp, "%s: memstats:  %-30s: %6zu * %s\n",
+	else
-			eda->prefix, mt->name, mt->n_alloc,
+		snprintf(size, sizeof(size), "(variably sized)");
-			mt->size == SIZE_VAR ? "(variably sized)" : size);
+
+	if (mg->active_at_exit) {
+		/* not an error - this memgroup has allocations remain active
+		 * at exit.  Only printed to zlog_debug.
+		 */
+		if (!eda->do_log)
+			return 0;
+
+		if (eda->last_mg != mg) {
+			zlog_debug("showing active allocations in memory group %s (not an error)",
+				   mg->name);
+			eda->last_mg = mg;
+		}
+		zlog_debug("memstats:  %-30s: %6zu * %s", mt->name, mt->n_alloc, size);
+		return 0;
 	}
+
+	eda->error++;
+	if (eda->do_file)
+		qmem_exit_fopen(eda);
+
+	if (eda->last_mg != mg) {
+		if (eda->do_log)
+			zlog_warn("showing active allocations in memory group %s", mg->name);
+		if (eda->do_stderr)
+			fprintf(stderr, "%s: showing active allocations in memory group %s\n",
+				prefix, mg->name);
+		if (eda->fp)
+			fprintf(eda->fp, "%s: showing active allocations in memory group %s\n",
+				prefix, mg->name);
+		eda->last_mg = mg;
+	}
+
+	if (eda->do_log)
+		zlog_warn("memstats:  %-30s: %6zu * %s", mt->name, mt->n_alloc, size);
+	if (eda->do_stderr)
+		fprintf(stderr, "%s: memstats:  %-30s: %6zu * %s\n", prefix, mt->name, mt->n_alloc,
+			size);
+	if (eda->fp)
+		fprintf(eda->fp, "%s: memstats:  %-30s: %6zu * %s\n", prefix, mt->name, mt->n_alloc,
+			size);
 	return 0;
 }
 
-int log_memstats(FILE *fp, const char *prefix)
+int log_memstats(const char *daemon_name, bool enabled)
 {
-	struct exit_dump_args eda = {.fp = fp, .prefix = prefix, .error = 0};
+	struct exit_dump_args eda = {
+		.daemon_name = daemon_name,
+		.do_log = enabled,
+		.do_file = enabled,
+		.do_stderr = enabled || !isatty(STDERR_FILENO),
+		.error = 0,
+	};
+
 	qmem_walk(qmem_exit_walker, &eda);
+	if (eda.fp)
+		fclose(eda.fp);
+	if (eda.error && eda.do_log)
+		zlog_warn("exiting with %d leaked MTYPEs", eda.error);
 	return eda.error;
 }

lib/memory.h

@@ -181,8 +181,7 @@ static inline size_t mtype_stats_alloc(struct memtype *mt)
  * last value from qmem_walk_fn. */
 typedef int qmem_walk_fn(void *arg, struct memgroup *mg, struct memtype *mt);
 extern int qmem_walk(qmem_walk_fn *func, void *arg);
-extern int log_memstats(FILE *fp, const char *);
+extern int log_memstats(const char *daemon_name, bool enabled);
-#define log_memstats_stderr(prefix) log_memstats(stderr, prefix)
 
 extern __attribute__((__noreturn__)) void memory_oom(size_t size,
 						     const char *name);

tests/isisd/test_fuzz_isis_tlv.c

@@ -22,7 +22,7 @@ static bool atexit_registered;
 
 static void show_meminfo_at_exit(void)
 {
-	log_memstats(stderr, "isis fuzztest");
+	log_memstats(NULL, true);
 }
 
 static int comp_line(const void *p1, const void *p2)

tests/isisd/test_isis_spf.c

@@ -475,7 +475,7 @@ static void vty_do_exit(int isexit)
 	yang_terminate();
 	event_master_free(master);
 
-	log_memstats(stderr, "test-isis-spf");
+	log_memstats(NULL, true);
 	if (!isexit)
 		exit(0);
 }

tests/lib/cli/common_cli.c

@@ -43,7 +43,7 @@ static void vty_do_exit(int isexit)
 	yang_terminate();
 	event_master_free(master);
 
-	log_memstats(stderr, "testcli");
+	log_memstats(NULL, true);
 	if (!isexit)
 		exit(0);
 }

tests/lib/northbound/test_oper_data.c

@@ -427,7 +427,7 @@ static void vty_do_exit(int isexit)
 	yang_terminate();
 	event_master_free(master);
 
-	log_memstats(stderr, "test-nb-oper-data");
+	log_memstats(NULL, true);
 	if (!isexit)
 		exit(0);
 }

tests/lib/test_typelist.c

@@ -156,6 +156,6 @@ int main(int argc, char **argv)
 	test_ATOMSORT_UNIQ();
 	test_ATOMSORT_NONUNIQ();
 
-	log_memstats_stderr("test: ");
+	log_memstats(NULL, true);
 	return 0;
 }

tests/lib/test_zmq.c

@@ -285,7 +285,7 @@ static void run_server(int syncfd)
 	zmq_close(zmqsock);
 	frrzmq_finish();
 	event_master_free(master);
-	log_memstats_stderr("test");
+	log_memstats(NULL, true);
 }
 
 int main(void)