On Thu, Jun 20, 2024 at 06:15:13PM +0200, Stefano Brivio wrote:After commit 15001b39ef1d ("conf: set the log level much earlier"), we had a phase during initialisation when messages wouldn't be printed to standard error anymore. Commit f67238aa864d ("passt, log: Call __openlog() earlier, log to stderr until we detach") fixed that, but only for the case where no log files are given. If a log file is configured, vlogmsg() will not call passt_vsyslog(), but during initialisation, LOG_PERROR is set, so to avoid duplicated prints (which would result from passt_vsyslog() printing to stderr), we don't call fprintf() from vlogmsg() either. This is getting a bit too complicated. Instead of abusing LOG_PERROR, define an internal logging flag that clearly represents that we're not done with the initialisation phase yet. If this flag is not set, make sure we always print to stderr, if the log mask matches. Reported-by: Yalan Zhang <yalzhang(a)redhat.com> Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>Reviewed-by: David Gibson <david(a)gibson.dropbear.id.au> Modulo some concerns that I'll comment on for the series as a whole.--- log.c | 17 ++++++++--------- log.h | 1 + passt.c | 11 +++++------ 3 files changed, 14 insertions(+), 15 deletions(-) diff --git a/log.c b/log.c index 05b7f80..0199eb4 100644 --- a/log.c +++ b/log.c @@ -33,7 +33,6 @@ static int log_sock = -1; /* Optional socket to system logger */ static char log_ident[BUFSIZ]; /* Identifier string for openlog() */ static int log_mask; /* Current log priority mask */ -static int log_opt; /* Options for openlog() */ static int log_file = -1; /* Optional log file descriptor */ static size_t log_size; /* Maximum log file size in bytes */ @@ -45,6 +44,7 @@ static time_t log_start; /* Start timestamp */ int log_trace; /* --trace mode enabled */ bool log_conf_parsed; /* Logging options already parsed */ +bool log_runtime; /* Daemonised, or ready in foreground */ void vlogmsg(int pri, const char *format, va_list ap) { @@ -70,7 +70,8 @@ void vlogmsg(int pri, const char *format, va_list ap) va_end(ap2); } - if (debug_print || (!log_conf_parsed && !(log_opt & LOG_PERROR))) { + if (debug_print || !log_conf_parsed || + (!log_runtime && (log_mask & LOG_MASK(LOG_PRI(pri))))) { (void)vfprintf(stderr, format, ap); if (format[strlen(format)] != '\n') fprintf(stderr, "\n"); @@ -108,13 +109,15 @@ void trace_init(int enable) /** * __openlog() - Non-optional openlog() implementation, for custom vsyslog() * @ident: openlog() identity (program name) - * @option: openlog() options + * @option: openlog() options, unused * @facility: openlog() facility (LOG_DAEMON) */ void __openlog(const char *ident, int option, int facility) { struct timespec tp; + (void)option; + clock_gettime(CLOCK_REALTIME, &tp); log_start = tp.tv_sec; @@ -135,7 +138,6 @@ void __openlog(const char *ident, int option, int facility) log_mask |= facility; strncpy(log_ident, ident, sizeof(log_ident) - 1); - log_opt = option; } /** @@ -156,20 +158,17 @@ void __setlogmask(int mask) */ void passt_vsyslog(int pri, const char *format, va_list ap) { - int prefix_len, n; char buf[BUFSIZ]; + int n; /* Send without timestamp, the system logger should add it */ - n = prefix_len = snprintf(buf, BUFSIZ, "<%i> %s: ", pri, log_ident); + n = snprintf(buf, BUFSIZ, "<%i> %s: ", pri, log_ident); n += vsnprintf(buf + n, BUFSIZ - n, format, ap); if (format[strlen(format)] != '\n') n += snprintf(buf + n, BUFSIZ - n, "\n"); - if (log_opt & LOG_PERROR) - fprintf(stderr, "%s", buf + prefix_len); - if (log_sock >= 0 && send(log_sock, buf, n, 0) != n) fprintf(stderr, "Failed to send %i bytes to syslog\n", n); } diff --git a/log.h b/log.h index 3dab284..77d74a2 100644 --- a/log.h +++ b/log.h @@ -30,6 +30,7 @@ void logmsg(int pri, const char *format, ...) extern int log_trace; extern bool log_conf_parsed; +extern bool log_runtime; void trace_init(int enable); #define trace(...) \ diff --git a/passt.c b/passt.c index 19ecd68..e5cfd62 100644 --- a/passt.c +++ b/passt.c @@ -200,8 +200,8 @@ void exit_handler(int signal) int main(int argc, char **argv) { struct epoll_event events[EPOLL_EVENTS]; - char *log_name, argv0[PATH_MAX], *name; int nfds, i, devnull_fd = -1; + char argv0[PATH_MAX], *name; struct ctx c = { 0 }; struct rlimit limit; struct timespec now; @@ -225,7 +225,7 @@ int main(int argc, char **argv) strncpy(argv0, argv[0], PATH_MAX - 1); name = basename(argv0); if (strstr(name, "pasta")) { - __openlog(log_name = "pasta", LOG_PERROR, LOG_DAEMON); + __openlog("pasta", 0, LOG_DAEMON); sa.sa_handler = pasta_child_handler; if (sigaction(SIGCHLD, &sa, NULL)) { @@ -240,7 +240,7 @@ int main(int argc, char **argv) c.mode = MODE_PASTA; } else if (strstr(name, "passt")) { - __openlog(log_name = "passt", LOG_PERROR, LOG_DAEMON); + __openlog("passt", 0, LOG_DAEMON); c.mode = MODE_PASST; } else { @@ -302,14 +302,13 @@ int main(int argc, char **argv) if (isolate_prefork(&c)) die("Failed to sandbox process, exiting"); - if (!c.foreground) - __openlog(log_name, 0, LOG_DAEMON); - if (!c.foreground) __daemon(c.pidfile_fd, devnull_fd); else pidfile_write(c.pidfile_fd, getpid()); + log_runtime = true; + if (pasta_child_pid) kill(pasta_child_pid, SIGUSR1);-- David Gibson (he or they) | I'll have my music baroque, and my code david AT gibson.dropbear.id.au | minimalist, thank you, not the other way | around. http://www.ozlabs.org/~dgibson