log, passt: Always print to stderr before initialisation is complete

After commit 15001b39ef ("conf: set the log level much earlier"), we
had a phase during initialisation when messages wouldn't be printed to
standard error anymore.

Commit f67238aa86 ("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@redhat.com>
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
Reviewed-by: David Gibson <david@gibson.dropbear.id.au>
This commit is contained in:
Stefano Brivio 2024-06-14 22:47:51 +02:00
parent 8c2f24a560
commit afd9cdc9bb
3 changed files with 14 additions and 15 deletions

17
log.c
View file

@ -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);
}

1
log.h
View file

@ -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(...) \

11
passt.c
View file

@ -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);