[PATCH v2] passt, log: Call __openlog() earlier, log to stderr until we detach

[PATCH v2] passt, log: Call __openlog() earlier, log to stderr until we detach

[Stefano Brivio]

Paul reports that, with commit 15001b39ef1d ("conf: set the log level
much earlier"), early messages aren't reported to standard error
anymore.

The reason is that, once the log mask is changed from LOG_EARLY, we
don't force logging to stderr, and this mechanism was abused to have
early errors on stderr. Now that we drop LOG_EARLY earlier on, this
doesn't work anymore.

Call __openlog() as soon as we know the mode we're running as, using
LOG_PERROR. Then, once we detach, if we're not running from an
interactive terminal and logging to standard error is not forced,
drop LOG_PERROR from the options.

While at it, check if the standard error descriptor refers to a
terminal, instead of checking standard output: if the user redirects
standard output to /dev/null, they might still want to see messages
from standard error.

Further, make sure we don't print messages to standard error reporting
that we couldn't log to the system logger, if we didn't open a
connection yet. That's expected.

Reported-by: Paul Holzinger <pholzing@redhat.com>
Fixes: 15001b39ef1d ("conf: set the log level much earlier")
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
---
v2: Change the isatty() test to use stderr instead of stdout

 log.c   |  2 +-
 passt.c | 14 +++++++-------
 2 files changed, 8 insertions(+), 8 deletions(-)

diff --git a/log.c b/log.c
index eafaca2..bdd31b4 100644
--- a/log.c
+++ b/log.c
@@ -174,7 +174,7 @@ void passt_vsyslog(int pri, const char *format, va_list ap)
 	if (log_opt & LOG_PERROR)
 		fprintf(stderr, "%s", buf + prefix_len);
 
-	if (send(log_sock, buf, n, 0) != n)
+	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/passt.c b/passt.c
index f430648..59ab501 100644
--- a/passt.c
+++ b/passt.c
@@ -225,6 +225,8 @@ 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);
+
 		sa.sa_handler = pasta_child_handler;
 		if (sigaction(SIGCHLD, &sa, NULL)) {
 			die("Couldn't install signal handlers: %s",
@@ -237,18 +239,16 @@ int main(int argc, char **argv)
 		}
 
 		c.mode = MODE_PASTA;
-		log_name = "pasta";
 	} else if (strstr(name, "passt")) {
+		__openlog(log_name = "passt", LOG_PERROR, LOG_DAEMON);
+
 		c.mode = MODE_PASST;
-		log_name = "passt";
 	} else {
 		exit(EXIT_FAILURE);
 	}
 
 	madvise(pkt_buf, TAP_BUF_BYTES, MADV_HUGEPAGE);
 
-	__openlog(log_name, 0, LOG_DAEMON);
-
 	c.epollfd = epoll_create1(EPOLL_CLOEXEC);
 	if (c.epollfd == -1) {
 		perror("epoll_create1");
@@ -269,9 +269,6 @@ int main(int argc, char **argv)
 	conf(&c, argc, argv);
 	trace_init(c.trace);
 
-	if (c.force_stderr || isatty(fileno(stdout)))
-		__openlog(log_name, LOG_PERROR, LOG_DAEMON);
-
 	pasta_netns_quit_init(&c);
 
 	tap_sock_init(&c);
@@ -314,6 +311,9 @@ int main(int argc, char **argv)
 	if (isolate_prefork(&c))
 		die("Failed to sandbox process, exiting");
 
+	if (!c.force_stderr && !isatty(fileno(stderr)))
+		__openlog(log_name, 0, LOG_DAEMON);
+
 	if (!c.foreground)
 		__daemon(pidfile_fd, devnull_fd);
 	else
-- 
@@ -225,6 +225,8 @@ 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);
+
 		sa.sa_handler = pasta_child_handler;
 		if (sigaction(SIGCHLD, &sa, NULL)) {
 			die("Couldn't install signal handlers: %s",
@@ -237,18 +239,16 @@ int main(int argc, char **argv)
 		}
 
 		c.mode = MODE_PASTA;
-		log_name = "pasta";
 	} else if (strstr(name, "passt")) {
+		__openlog(log_name = "passt", LOG_PERROR, LOG_DAEMON);
+
 		c.mode = MODE_PASST;
-		log_name = "passt";
 	} else {
 		exit(EXIT_FAILURE);
 	}
 
 	madvise(pkt_buf, TAP_BUF_BYTES, MADV_HUGEPAGE);
 
-	__openlog(log_name, 0, LOG_DAEMON);
-
 	c.epollfd = epoll_create1(EPOLL_CLOEXEC);
 	if (c.epollfd == -1) {
 		perror("epoll_create1");
@@ -269,9 +269,6 @@ int main(int argc, char **argv)
 	conf(&c, argc, argv);
 	trace_init(c.trace);
 
-	if (c.force_stderr || isatty(fileno(stdout)))
-		__openlog(log_name, LOG_PERROR, LOG_DAEMON);
-
 	pasta_netns_quit_init(&c);
 
 	tap_sock_init(&c);
@@ -314,6 +311,9 @@ int main(int argc, char **argv)
 	if (isolate_prefork(&c))
 		die("Failed to sandbox process, exiting");
 
+	if (!c.force_stderr && !isatty(fileno(stderr)))
+		__openlog(log_name, 0, LOG_DAEMON);
+
 	if (!c.foreground)
 		__daemon(pidfile_fd, devnull_fd);
 	else
-- 
2.39.2

Re: [PATCH v2] passt, log: Call __openlog() earlier, log to stderr until we detach

[David Gibson]

[-- Attachment #1: Type: text/plain, Size: 3782 bytes --]

On Wed, Mar 13, 2024 at 12:58:10PM +0100, Stefano Brivio wrote:
> Paul reports that, with commit 15001b39ef1d ("conf: set the log level
> much earlier"), early messages aren't reported to standard error
> anymore.
> 
> The reason is that, once the log mask is changed from LOG_EARLY, we
> don't force logging to stderr, and this mechanism was abused to have
> early errors on stderr. Now that we drop LOG_EARLY earlier on, this
> doesn't work anymore.
> 
> Call __openlog() as soon as we know the mode we're running as, using
> LOG_PERROR. Then, once we detach, if we're not running from an
> interactive terminal and logging to standard error is not forced,
> drop LOG_PERROR from the options.
> 
> While at it, check if the standard error descriptor refers to a
> terminal, instead of checking standard output: if the user redirects
> standard output to /dev/null, they might still want to see messages
> from standard error.
> 
> Further, make sure we don't print messages to standard error reporting
> that we couldn't log to the system logger, if we didn't open a
> connection yet. That's expected.
> 
> Reported-by: Paul Holzinger <pholzing@redhat.com>
> Fixes: 15001b39ef1d ("conf: set the log level much earlier")
> Signed-off-by: Stefano Brivio <sbrivio@redhat.com>

Reviewed-by: David Gibson <david@gibson.dropbear.id.au>

> ---
> v2: Change the isatty() test to use stderr instead of stdout
> 
>  log.c   |  2 +-
>  passt.c | 14 +++++++-------
>  2 files changed, 8 insertions(+), 8 deletions(-)
> 
> diff --git a/log.c b/log.c
> index eafaca2..bdd31b4 100644
> --- a/log.c
> +++ b/log.c
> @@ -174,7 +174,7 @@ void passt_vsyslog(int pri, const char *format, va_list ap)
>  	if (log_opt & LOG_PERROR)
>  		fprintf(stderr, "%s", buf + prefix_len);
>  
> -	if (send(log_sock, buf, n, 0) != n)
> +	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/passt.c b/passt.c
> index f430648..59ab501 100644
> --- a/passt.c
> +++ b/passt.c
> @@ -225,6 +225,8 @@ 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);
> +
>  		sa.sa_handler = pasta_child_handler;
>  		if (sigaction(SIGCHLD, &sa, NULL)) {
>  			die("Couldn't install signal handlers: %s",
> @@ -237,18 +239,16 @@ int main(int argc, char **argv)
>  		}
>  
>  		c.mode = MODE_PASTA;
> -		log_name = "pasta";
>  	} else if (strstr(name, "passt")) {
> +		__openlog(log_name = "passt", LOG_PERROR, LOG_DAEMON);
> +
>  		c.mode = MODE_PASST;
> -		log_name = "passt";
>  	} else {
>  		exit(EXIT_FAILURE);
>  	}
>  
>  	madvise(pkt_buf, TAP_BUF_BYTES, MADV_HUGEPAGE);
>  
> -	__openlog(log_name, 0, LOG_DAEMON);
> -
>  	c.epollfd = epoll_create1(EPOLL_CLOEXEC);
>  	if (c.epollfd == -1) {
>  		perror("epoll_create1");
> @@ -269,9 +269,6 @@ int main(int argc, char **argv)
>  	conf(&c, argc, argv);
>  	trace_init(c.trace);
>  
> -	if (c.force_stderr || isatty(fileno(stdout)))
> -		__openlog(log_name, LOG_PERROR, LOG_DAEMON);
> -
>  	pasta_netns_quit_init(&c);
>  
>  	tap_sock_init(&c);
> @@ -314,6 +311,9 @@ int main(int argc, char **argv)
>  	if (isolate_prefork(&c))
>  		die("Failed to sandbox process, exiting");
>  
> +	if (!c.force_stderr && !isatty(fileno(stderr)))
> +		__openlog(log_name, 0, LOG_DAEMON);
> +
>  	if (!c.foreground)
>  		__daemon(pidfile_fd, devnull_fd);
>  	else

-- 
David Gibson			| 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

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]