[PATCH 3/6] log, passt: Always print to stderr before initialisation is complete

[Stefano Brivio <sbrivio@redhat.com>]

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. Then, set LOG_PERROR only as we set this internal
flag, to make sure we don't duplicate messages.

Reported-by: Yalan Zhang <yalzhang@redhat.com>
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
---
 log.c   |  4 +++-
 log.h   |  1 +
 passt.1 |  3 ++-
 passt.c | 17 ++++++++++-------
 4 files changed, 16 insertions(+), 9 deletions(-)

diff --git a/log.c b/log.c
index 3b5a1c6..939bb93 100644
--- a/log.c
+++ b/log.c
@@ -49,6 +49,7 @@ int		log_trace;		/* --trace mode enabled */
 void vlogmsg(int pri, const char *format, va_list ap)
 {
 	bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
+	bool before_daemon = !(log_flags & LOG_FLAG_DAEMON_READY);
 	bool early_print = !(log_flags & LOG_FLAG_CONF_PARSED);
 	struct timespec tp;
 
@@ -71,7 +72,8 @@ void vlogmsg(int pri, const char *format, va_list ap)
 		va_end(ap2);
 	}
 
-	if (debug_print || (early_print && !(log_opt & LOG_PERROR))) {
+	if (debug_print || early_print ||
+	    (before_daemon && (log_mask & LOG_MASK(LOG_PRI(pri))))) {
 		(void)vfprintf(stderr, format, ap);
 		if (format[strlen(format)] != '\n')
 			fprintf(stderr, "\n");
diff --git a/log.h b/log.h
index 6a3224a..680baab 100644
--- a/log.h
+++ b/log.h
@@ -10,6 +10,7 @@
 #include <syslog.h>
 
 #define LOG_FLAG_CONF_PARSED	BIT(0)	/* We already parsed logging options */
+#define LOG_FLAG_DAEMON_READY	BIT(1)	/* Daemonised, or ready in foreground */
 
 #define LOGFILE_SIZE_DEFAULT		(1024 * 1024UL)
 #define LOGFILE_CUT_RATIO		30	/* When full, cut ~30% size */
diff --git a/passt.1 b/passt.1
index 3a23a43..31e528e 100644
--- a/passt.1
+++ b/passt.1
@@ -99,7 +99,8 @@ terminal, and to both system logger and standard error otherwise.
 
 .TP
 .BR \-l ", " \-\-log-file " " \fIPATH\fR
-Log to file \fIPATH\fR, not to standard error, and not to the system logger.
+Log to file \fIPATH\fR, not to standard error (once initialisation is complete),
+and not to the system logger.
 
 .TP
 .BR \-\-log-size " " \fISIZE\fR
diff --git a/passt.c b/passt.c
index aa9648a..fa86164 100644
--- a/passt.c
+++ b/passt.c
@@ -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(log_name = "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(log_name = "passt", 0, LOG_DAEMON);
 
 		c.mode = MODE_PASST;
 	} else {
@@ -302,13 +302,16 @@ int main(int argc, char **argv)
 	if (isolate_prefork(&c))
 		die("Failed to sandbox process, exiting");
 
-	if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
-		__openlog(log_name, 0, LOG_DAEMON);
-
-	if (!c.foreground)
+	if (!c.foreground) {
 		__daemon(c.pidfile_fd, devnull_fd);
-	else
+	} else {
+		if (c.force_stderr || isatty(fileno(stderr)))
+			__openlog(log_name, LOG_PERROR, LOG_DAEMON);
+
 		pidfile_write(c.pidfile_fd, getpid());
+	}
+
+	log_set_flag(LOG_FLAG_DAEMON_READY);
 
 	if (pasta_child_pid)
 		kill(pasta_child_pid, SIGUSR1);
-- 
@@ -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(log_name = "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(log_name = "passt", 0, LOG_DAEMON);
 
 		c.mode = MODE_PASST;
 	} else {
@@ -302,13 +302,16 @@ int main(int argc, char **argv)
 	if (isolate_prefork(&c))
 		die("Failed to sandbox process, exiting");
 
-	if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
-		__openlog(log_name, 0, LOG_DAEMON);
-
-	if (!c.foreground)
+	if (!c.foreground) {
 		__daemon(c.pidfile_fd, devnull_fd);
-	else
+	} else {
+		if (c.force_stderr || isatty(fileno(stderr)))
+			__openlog(log_name, LOG_PERROR, LOG_DAEMON);
+
 		pidfile_write(c.pidfile_fd, getpid());
+	}
+
+	log_set_flag(LOG_FLAG_DAEMON_READY);
 
 	if (pasta_child_pid)
 		kill(pasta_child_pid, SIGUSR1);
-- 
2.43.0