Use setproctag() more to aid troubleshooting; introduce NUT_DEBUG_PROCNAME envvar

NEWS.adoc

@@ -46,6 +46,11 @@ https://github.com/networkupstools/nut/milestone/12
  - common code:
    * Introduced `setproctag()` and `getproctag()` (see examples in `upsmon`)
      to help track the log messages from massively-forking NUT daemons. [#3084]
+   * Introduced `NUT_DEBUG_PROCNAME` environment variable support to optionally
+     log also the process name (or however the program chose to identify itself).
+     This may be useful when multiple NUT daemons log into the same file or
+     console, without syslog to prefix the name into each line (e.g. in tests,
+     single init script systems like Home Assistant, etc.) [PR 3368]
    * Extended with plural `checkprocnames()` and `compareprocnames()`,
      as well as `sendsignalpidaliases()` and `sendsignalfnaliases()`, for
      binaries that expect to have one of several names at the moment (e.g.

clients/upsc.c

@@ -380,6 +380,10 @@ static void clean_exit(void)
 	free(upsname);
 	free(hostname);
 	free(ups);
+
+	/* Not a sub-process (do not let common::proctag_cleanup() mis-report us as such) */
+	upsdebugx(1, "%s: finished, exiting", __func__);
+	setproctag(NULL);
 }
 
 int main(int argc, char **argv)
@@ -391,6 +395,7 @@ int main(int argc, char **argv)
 	const char	*net_connect_timeout = NULL;
 	char	*s = NULL;
 
+	setproctag(prog);
 	/* NOTE: Caller must `export NUT_DEBUG_LEVEL` to see debugs for upsc
 	 * and NUT methods called from it. This line aims to just initialize
 	 * the subsystem, and set initial timestamp. Debugging the client is
@@ -466,6 +471,7 @@ int main(int argc, char **argv)
 			fatalx_error_json_simple(0, "invalid UPS definition.\nRequired format: upsname[@hostname[:port]]");
 		}
 	}
+	setproctag(argv[0]);
 	upsdebugx(1, "upsname='%s' hostname='%s' port='%" PRIu16 "'",
 		NUT_STRARG(upsname), NUT_STRARG(hostname), port);
 

clients/upscmd.c

@@ -286,6 +286,10 @@ static void clean_exit(void)
 	free(upsname);
 	free(hostname);
 	free(ups);
+
+	/* Not a sub-process (do not let common::proctag_cleanup() mis-report us as such) */
+	upsdebugx(1, "%s: finished, exiting", __func__);
+	setproctag(NULL);
 }
 
 int main(int argc, char **argv)
@@ -298,6 +302,7 @@ int main(int argc, char **argv)
 	const char	*prog = xbasename(argv[0]);
 	const char	*net_connect_timeout = NULL;
 
+	setproctag(prog);
 	/* NOTE: Caller must `export NUT_DEBUG_LEVEL` to see debugs for upsc
 	 * and NUT methods called from it. This line aims to just initialize
 	 * the subsystem, and set initial timestamp. Debugging the client is
@@ -378,6 +383,7 @@ int main(int argc, char **argv)
 	if (upscli_splitname(argv[0], &upsname, &hostname, &port) != 0) {
 		fatalx(EXIT_FAILURE, "Error: invalid UPS definition.  Required format: upsname[@hostname[:port]]");
 	}
+	setproctag(argv[0]);
 
 	ups = (UPSCONN_t *)xcalloc(1, sizeof(*ups));
 

clients/upslog.c

@@ -526,6 +526,7 @@ int main(int argc, char **argv)
 	callback_upsconf_args = do_upsconf_args;
 #endif
 
+	setproctag(prog);
 	print_banner_once(prog, 0);
 
 	while ((i = getopt(argc, argv, "+hDs:l:i:d:Nf:u:Vp:FBm:W:")) != -1) {

clients/upsrw.c

@@ -89,6 +89,10 @@ static void clean_exit(void)
 	free(upsname);
 	free(hostname);
 	free(ups);
+
+	/* Not a sub-process (do not let common::proctag_cleanup() mis-report us as such) */
+	upsdebugx(1, "%s: finished, exiting", __func__);
+	setproctag(NULL);
 }
 
 #if (defined HAVE_PRAGMA_GCC_DIAGNOSTIC_PUSH_POP_BESIDEFUNC) && (!defined HAVE_PRAGMA_GCC_DIAGNOSTIC_PUSH_POP_INSIDEFUNC) && ( (defined HAVE_PRAGMA_GCC_DIAGNOSTIC_IGNORED_TYPE_LIMITS_BESIDEFUNC) || (defined HAVE_PRAGMA_GCC_DIAGNOSTIC_IGNORED_TAUTOLOGICAL_CONSTANT_OUT_OF_RANGE_COMPARE_BESIDEFUNC) )
@@ -656,6 +660,7 @@ int main(int argc, char **argv)
 	const char	*net_connect_timeout = NULL;
 	char	*password = NULL, *username = NULL, *setvar = NULL, *s = NULL;
 
+	setproctag(prog);
 	/* NOTE: Caller must `export NUT_DEBUG_LEVEL` to see debugs for upsc
 	 * and NUT methods called from it. This line aims to just initialize
 	 * the subsystem, and set initial timestamp. Debugging the client is
@@ -732,6 +737,7 @@ int main(int argc, char **argv)
 	if (upscli_splitname(argv[0], &upsname, &hostname, &port) != 0) {
 		fatalx(EXIT_FAILURE, "Error: invalid UPS definition.  Required format: upsname[@hostname[:port]]");
 	}
+	setproctag(argv[0]);
 
 	ups = (UPSCONN_t *)xcalloc(1, sizeof(*ups));
 

common/common.c

@@ -4248,9 +4248,40 @@ static char	*proctag = NULL, *proctag_for_upsdebug = NULL,
 static void proctag_cleanup(void)
 {
 	if (proctag) {
-		upsdebugx(2, "a %s sub-process (%s) is exiting now",
-			NUT_STRARG(getmyprocbasename()), getproctag());
+		char	*pn = xstrdup(getmyprocbasename());
+		char	*tn = xstrdup(proctag);
+
+		if (strlen(EXEEXT) > 0) {
+			/* TOTHINK: Generalize provided-if-missing strcasestr()? */
+			char	*s;
+			if (pn) {
+				s = strstr(pn, EXEEXT);
+				if (s) *s='\0';
+			}
+
+			if (tn) {
+				s = strstr(tn, EXEEXT);
+				if (s) *s='\0';
+			}
+		}
+
+		if (pn && tn && !strcmp(pn, tn)) {
+			/* Avoid reporting this line as misleading "sub-process"
+			 * after a plain singular setproctag(progname) call in
+			 * a NUT program: */
+			upsdebugx(2, "a process (%s) is exiting now", pn);
+		} else {
+			/* Some ptr not set, or strings not equal */
+			upsdebugx(2, "a %s sub-process (%s) is exiting now",
+				NUT_STRARG(pn), proctag);
+		}
+
+		if (pn)
+			free(pn);
+		if (tn)
+			free(tn);
 	}
+
 	setproctag(NULL);
 }
 
@@ -4292,7 +4323,50 @@ void setproctag(const char *tag)
 	proctag_for_upsdebug_buflen = strlen(tag) + 2;
 	proctag_for_upsdebug = (char *)xcalloc(proctag_for_upsdebug_buflen, sizeof(char));
 	if (proctag_for_upsdebug) {
-		snprintf(proctag_for_upsdebug, proctag_for_upsdebug_buflen, ":%s", tag);
+		char	*pn = xstrdup(getmyprocbasename());
+		char	*tn = xstrdup(tag);
+		int	tagged = 0;
+
+		if (strlen(EXEEXT) > 0) {
+			/* TOTHINK: Generalize provided-if-missing strcasestr()?
+			 *  One implementation is currently tucked away in
+			 *  libusb0.c because net-snmp may provide another...
+			 */
+			char	*s;
+			if (pn) {
+				s = strstr(pn, EXEEXT);
+				if (s) *s='\0';
+			}
+
+			if (tn) {
+				s = strstr(tn, EXEEXT);
+				if (s) *s='\0';
+			}
+		}
+
+		if (pn && tn && getenv("NUT_DEBUG_PROCNAME") != NULL && strcmp(pn, tn)) {
+			/* Only add the process name if asked for and substantially
+			 * different from tag value -- e.g. do not duplicate text
+			 * when callers initialize with settagname(progname) */
+			char	*s = NULL;
+			proctag_for_upsdebug_buflen += strlen(pn) + 1;
+			s = (char *)xcalloc(proctag_for_upsdebug_buflen, sizeof(char));
+			if (s) {
+				snprintf(s, proctag_for_upsdebug_buflen, ":%s:%s", pn, tag);
+				free(proctag_for_upsdebug);
+				proctag_for_upsdebug = s;
+				tagged = 1;
+			}
+		}
+
+		if (!tagged) {
+			snprintf(proctag_for_upsdebug, proctag_for_upsdebug_buflen, ":%s", tag);
+		}
+
+		if (pn)
+			free(pn);
+		if (tn)
+			free(tn);
 	}
 }
 

conf/nut.conf.sample

@@ -106,6 +106,13 @@ MODE=none
 #NUT_DEBUG_PID=true
 #export NUT_DEBUG_PID
 
+# Optionally log process name (or however the program chose to identify itself).
+# This may be useful when multiple NUT daemons log into the same file or console,
+# without syslog to prefix the name into each line (e.g. in tests, single init
+# script systems like Home Assistant, etc.).
+#NUT_DEBUG_PROCNAME=true
+#export NUT_DEBUG_PROCNAME
+
 # Normally NUT can (attempt to) use the syslog or Event Log (WIN32), but the
 # environment variable 'NUT_DEBUG_SYSLOG' allows to bypass it, and perhaps keep
 # the daemons logging to stderr (useful e.g. in NUT Integration Test suite to

docs/man/nut.conf.txt

@@ -139,6 +139,12 @@ Optionally add current process ID to tags with debug-level identifiers.
 This may be useful when many NUT daemons write to the same console or log
 file, such as in containers/plugins for Home Assistant, storage appliances...
 
+*NUT_DEBUG_PROCNAME*::
+Optionally log process name (or however the program chose to identify itself).
+This may be useful when multiple NUT daemons log into the same file or console,
+without syslog to prefix the name into each line (e.g. in tests, single init
+script systems like Home Assistant, etc.)
+
 *NUT_DEBUG_SYSLOG*::
 Optional, unset by default.
 Normally NUT can (attempt to) use the syslog or Event Log (WIN32), but the

docs/nut.dict

@@ -1,4 +1,4 @@
-personal_ws-1.1 en 3706 utf-8
+personal_ws-1.1 en 3707 utf-8
 AAC
 AAS
 ABI
@@ -963,6 +963,7 @@ PPP
 PR
 PR'ed
 PRIuSIZE
+PROCNAME
 PROGRA
 PROGS
 PROTVER

drivers/main.c

@@ -2004,6 +2004,10 @@ static void exit_cleanup(void)
 			free((char*)(prognames[i]));
 		}
 	}
+
+	/* Not a sub-process (do not let common::proctag_cleanup() mis-report us as such) */
+	upsdebugx(1, "%s: finished, exiting", __func__);
+	setproctag(NULL);
 }
 #endif /* DRIVERS_MAIN_WITHOUT_MAIN */
 
@@ -2506,6 +2510,7 @@ int main(int argc, char **argv)
 		fatalx(EXIT_FAILURE,
 			"Error: specifying '-a id' or '-s id' is now mandatory. Try -h for help.");
 	}
+	setproctag(upsname);
 
 	/* we need to get the port from somewhere, unless we are just sending a signal and exiting */
 	if (!device_path && !cmd) {

scripts/systemd/README.adoc

@@ -17,7 +17,8 @@ configuration files rather than editing the installed unit files directly
 ----
 # cat /etc/systemd/system/nut-monitor.service.d/debug.conf
 [Service]
-Environment="NUT_DEBUG_PID=yes"
+Environment="NUT_DEBUG_PID=true"
+#Environment="NUT_DEBUG_PROCNAME=true"
 ----
 ...followed up by `systemctl daemon-reload` and a restart of the unit itself.
 

server/upsd.c

@@ -2315,6 +2315,7 @@ int main(int argc, char **argv)
 	struct passwd	*new_uid = NULL;
 
 	progname = xbasename(argv[0]);
+	setproctag(progname);
 
 #if (defined ENABLE_SHARED_PRIVATE_LIBS) && ENABLE_SHARED_PRIVATE_LIBS
 	callback_upsconf_args = do_upsconf_args;

tests/NIT/nit.sh

@@ -98,6 +98,9 @@ export NUT_DEBUG_LEVEL
 NUT_DEBUG_PID="true"
 export NUT_DEBUG_PID
 
+NUT_DEBUG_PROCNAME="true"
+export NUT_DEBUG_PROCNAME
+
 # Just keep upsdrvctl quiet if used in test builds or with the sandbox
 NUT_QUIET_INIT_NDE_WARNING="true"
 export NUT_QUIET_INIT_NDE_WARNING

tools/nut-scanner/Makefile.am

@@ -151,7 +151,7 @@ libnutscan_la_LDFLAGS += -version-info 5:0:1
 # copies of "nut_debug_level" making fun of our debug-logging attempts.
 # One solution to tackle if needed for those cases would be to make some
 # dynamic/shared libnutcommon (etc.)
-libnutscan_la_LDFLAGS += -export-symbols-regex '^(nutscan_|nut_debug_level|s_upsdebug|fatalx|fatal_with_errno|xcalloc|xbasename|snprintfcat|snprintf_dynamic|max_threads|curr_threads|nut_report_config_flags|upsdebugx_report_search_paths|nut_prepare_search_paths|print_banner_once|suggest_doc_links)'
+libnutscan_la_LDFLAGS += -export-symbols-regex '^(nutscan_|nut_debug_level|s_upsdebug|fatalx|fatal_with_errno|setproctag|xcalloc|xbasename|snprintfcat|snprintf_dynamic|max_threads|curr_threads|nut_report_config_flags|upsdebugx_report_search_paths|nut_prepare_search_paths|print_banner_once|suggest_doc_links)'
 libnutscan_la_CFLAGS = \
 			-I$(top_builddir)/clients -I$(top_srcdir)/clients \
 			-I$(top_builddir)/include -I$(top_srcdir)/include \