On Wed, 13 Mar 2024 11:23:56 +0100
Paul Holzinger <pholzing(a)redhat.com> wrote:

...
  Thanks for the quick patch.
 
 On 12/03/2024 23:34, 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, 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(a)redhat.com>
 Fixes: 15001b39ef1d ("conf: set the log level much earlier")
 Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com> 
 Tested-by: Paul Holzinger <pholzing(a)redhat.com> 
And thanks for the quick test.

...
 
  ---
   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..e4cb11e 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(stdout))) 
 I still have the feeling this should check the stderr fd instead of 
 stdout as it is logging to stderr. But I guess it shouldn't make a big 
 difference in real situations so not a big deal. 
Now that you mention this, I'm quite undecided: true, we're checking if
we want to print to standard error, but what we want to check here is
if we're running from an interactive terminal, for which testing if
stdout is a terminal is quite idiomatic.

On the other hand:

$ cat isatty.c
#include <stdio.h>
#include <unistd.h>

int main()
{
    return isatty(fileno(stdout));
}
$ gcc -o isatty isatty.c 
$ ./isatty >/dev/null; echo $?
0
$ ./isatty 2>/dev/null; echo $?
1

so we would (fail to) print to stderr if it's redirected to /dev/null,
but not print to stderr if stdout is redirected.

At this point I would have a slight preference toward changing it like
you suggested.

-- 
Stefano