diff --git a/NEWS.adoc b/NEWS.adoc index 2b470bbd24..d9de4084e0 100644 --- a/NEWS.adoc +++ b/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. diff --git a/clients/upsc.c b/clients/upsc.c index eaca4d834d..91a746612d 100644 --- a/clients/upsc.c +++ b/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); diff --git a/clients/upscmd.c b/clients/upscmd.c index 0206918595..05fc13d1d7 100644 --- a/clients/upscmd.c +++ b/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)); diff --git a/clients/upslog.c b/clients/upslog.c index b8561203d9..f7f879d570 100644 --- a/clients/upslog.c +++ b/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) { diff --git a/clients/upsrw.c b/clients/upsrw.c index c5ab5fa2ff..662e816036 100644 --- a/clients/upsrw.c +++ b/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)); diff --git a/common/common.c b/common/common.c index 35da0c6f99..7d97d14671 100644 --- a/common/common.c +++ b/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); } } diff --git a/conf/nut.conf.sample b/conf/nut.conf.sample index fd79043ff7..01a6cc02da 100644 --- a/conf/nut.conf.sample +++ b/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 diff --git a/docs/man/nut.conf.txt b/docs/man/nut.conf.txt index a183f761b3..94518dfc0a 100644 --- a/docs/man/nut.conf.txt +++ b/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 diff --git a/docs/nut.dict b/docs/nut.dict index 19e02ba4e0..1faf5c6983 100644 --- a/docs/nut.dict +++ b/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 diff --git a/drivers/main.c b/drivers/main.c index 847afc435e..88590117ad 100644 --- a/drivers/main.c +++ b/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) { diff --git a/scripts/systemd/README.adoc b/scripts/systemd/README.adoc index e164c2bc2a..ca473d87ff 100644 --- a/scripts/systemd/README.adoc +++ b/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. diff --git a/server/upsd.c b/server/upsd.c index 14b4ffec47..3a370193e2 100644 --- a/server/upsd.c +++ b/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; diff --git a/tests/NIT/nit.sh b/tests/NIT/nit.sh index eaedd5416d..ad59173ac9 100755 --- a/tests/NIT/nit.sh +++ b/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 diff --git a/tools/nut-scanner/Makefile.am b/tools/nut-scanner/Makefile.am index b25237b3b0..eac84193e4 100644 --- a/tools/nut-scanner/Makefile.am +++ b/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 \ diff --git a/tools/nut-scanner/nut-scanner.c b/tools/nut-scanner/nut-scanner.c index 322afe239a..f07bf99018 100644 --- a/tools/nut-scanner/nut-scanner.c +++ b/tools/nut-scanner/nut-scanner.c @@ -1230,6 +1230,8 @@ int main(int argc, char *argv[]) } #endif /* HAVE_PTHREAD && ( HAVE_PTHREAD_TRYJOIN || HAVE_SEMAPHORE_UNNAMED || HAVE_SEMAPHORE_NAMED ) && HAVE_SYS_RESOURCE_H */ + setproctag(progname); + memset(&snmp_sec, 0, sizeof(snmp_sec)); memset(&ipmi_sec, 0, sizeof(ipmi_sec)); memset(&xml_sec, 0, sizeof(xml_sec)); @@ -1255,8 +1257,11 @@ int main(int argc, char *argv[]) nut_debug_level++; } + setproctag("init-ip-ranges"); nutscan_init_ip_ranges(&ip_ranges_list); + setproctag("init-libnutscan"); nutscan_init(); + setproctag(progname); /* Default, see -Q/-N/-P below */ display_func = nutscan_display_ups_conf_with_sanity_check; @@ -1721,8 +1726,13 @@ int main(int argc, char *argv[]) } /* TODO/discuss : Should the #else...#endif code below for lack of pthreads - * during build also serve as a fallback for pthread failure at runtime? + * during build also serve as a fallback for pthread failure at runtime? + * Also consider a setproctag() variant for threads, where it would be most + * useful in troubleshooting. Currently it relies on a process-wide variable, + * and threads are all in same process space... */ + setproctag("scanning"); + if (allow_usb && nutscan_avail_usb) { upsdebugx(quiet, "Scanning USB bus."); #ifdef HAVE_PTHREAD @@ -1731,6 +1741,7 @@ int main(int argc, char *argv[]) nutscan_avail_usb = 0; } #else + setproctag("usb"); upsdebugx(1, "USB SCAN: no pthread support, starting nutscan_scan_usb..."); dev[TYPE_USB] = run_usb(&cli_link_detail_level); #endif /* HAVE_PTHREAD */ @@ -1752,6 +1763,7 @@ int main(int argc, char *argv[]) nutscan_avail_snmp = 0; } #else + setproctag("snmp"); upsdebugx(1, "SNMP SCAN: no pthread support, starting nutscan_scan_snmp..."); /* dev[TYPE_SNMP] = nutscan_scan_snmp(start_ip, end_ip, timeout, &snmp_sec); */ run_snmp(&snmp_sec); @@ -1776,6 +1788,7 @@ int main(int argc, char *argv[]) nutscan_avail_xml_http = 0; } #else + setproctag("netxml"); upsdebugx(1, "XML/HTTP SCAN: no pthread support, starting nutscan_scan_xml_http_range()..."); /* dev[TYPE_XML] = nutscan_scan_xml_http_range(start_ip, end_ip, timeout, &xml_sec); */ run_xml(&xml_sec); @@ -1798,6 +1811,7 @@ int main(int argc, char *argv[]) nutscan_avail_nut = 0; } #else + setproctag("oldnut"); upsdebugx(1, "NUT bus (old) SCAN: no pthread support, starting nutscan_scan_nut..."); /*dev[TYPE_NUT] = nutscan_scan_nut(start_ip, end_ip, port, timeout);*/ run_nut_old(NULL); @@ -1816,6 +1830,7 @@ int main(int argc, char *argv[]) nutscan_avail_nut_simulation = 0; } #else + setproctag("nut_simulation"); upsdebugx(1, "NUT simulation devices SCAN: no pthread support, starting nutscan_scan_nut_simulation..."); /* dev[TYPE_NUT_SIMULATION] = nutscan_scan_nut_simulation(); */ run_nut_simulation(NULL); @@ -1833,6 +1848,7 @@ int main(int argc, char *argv[]) nutscan_avail_avahi = 0; } #else + setproctag("avahi"); upsdebugx(1, "NUT bus (avahi) SCAN: no pthread support, starting nutscan_scan_avahi..."); /* dev[TYPE_AVAHI] = nutscan_scan_avahi(timeout); */ run_avahi(NULL); @@ -1855,6 +1871,7 @@ int main(int argc, char *argv[]) nutscan_avail_ipmi = 0; } #else + setproctag("ipmi"); upsdebugx(1, "IPMI SCAN: no pthread support, starting nutscan_scan_ipmi..."); /* dev[TYPE_IPMI] = nutscan_scan_ipmi(start_ip, end_ip, &ipmi_sec); */ run_ipmi(&ipmi_sec); @@ -1872,6 +1889,7 @@ int main(int argc, char *argv[]) nutscan_avail_upower = 0; } #else + setproctag("upower"); upsdebugx(1, "UPOWER SCAN: no pthread support, starting nutscan_scan_upower..."); run_upower(NULL); #endif /* HAVE_PTHREAD */ @@ -1889,6 +1907,7 @@ int main(int argc, char *argv[]) /* upsdebugx(1, "pthread_create returned an error; disabling this scan mode"); */ /* nutscan_avail_eaton_serial(?) = 0; */ #else + setproctag("serial"); upsdebugx(1, "SERIAL SCAN: no pthread support, starting nutscan_scan_eaton_serial..."); /* dev[TYPE_EATON_SERIAL] = nutscan_scan_eaton_serial (serial_ports); */ run_eaton_serial(serial_ports); @@ -1936,6 +1955,8 @@ int main(int argc, char *argv[]) } #endif /* HAVE_PTHREAD */ + setproctag("post-processing"); + upsdebugx(1, "SCANS DONE: display results"); upsdebugx(1, "SCANS DONE: display results: USB"); @@ -1983,6 +2004,7 @@ int main(int argc, char *argv[]) upsdebugx(1, "SCANS DONE: free resources: SERIAL"); nutscan_free_device(dev[TYPE_EATON_SERIAL]); + setproctag("cleanup"); #ifdef HAVE_PTHREAD # ifdef HAVE_SEMAPHORE_UNNAMED sem_destroy(nutscan_semaphore()); @@ -1999,6 +2021,10 @@ int main(int argc, char *argv[]) nutscan_free_ip_ranges(&ip_ranges_list); nutscan_free(); + /* Not a sub-process (do not let common::proctag_cleanup() mis-report us as such) */ + setproctag(progname); + upsdebugx(1, "SCANS DONE: EXIT_SUCCESS"); + return EXIT_SUCCESS; }