From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from mail.ozlabs.org (mail.ozlabs.org [IPv6:2404:9400:2221:ea00::3]) by passt.top (Postfix) with ESMTPS id 56BD15A004F for ; Fri, 21 Jun 2024 03:17:48 +0200 (CEST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gibson.dropbear.id.au; s=202312; t=1718932665; bh=MgkvVzBlLUkXfUUcw5VDjFqd897WgLWaQf1fP8C+ZNM=; h=Date:From:To:Cc:Subject:References:In-Reply-To:From; b=cFzcDA7LOfrPxYG5FUUqkdYKh0WyxOMgFoKjRJBqD5uFl2sRcVtXHrwEFKq6RRaWa wURvqvhmp5oFG90hUgx0C3Ax3+At1LM9ZDZ3kHSQRs+bne11XmFFzIaNTAala8FLK4 4E2Sjj6conAB++6SfWExcCLzzJPxoGUf6EYUO0sbhqwKUi7N2trfX9wQvEs5ga+LZ4 1Mg2rrx5WxG5FUm0GKQD+IvhVM0j2lzac3hyCl97OnSRctERhx0ZU6ATyZTiYRxKk4 m3IyQNPljTxSIGOwwmkJ4Nhum7XtjTajlyOtZOeR5A46IPs8Qaqy4DkHEN1nOzQH1M xwdQWfhefFBKg== Received: by gandalf.ozlabs.org (Postfix, from userid 1007) id 4W4zxP0TSFz4wc1; Fri, 21 Jun 2024 11:17:45 +1000 (AEST) Date: Fri, 21 Jun 2024 11:13:52 +1000 From: David Gibson To: Stefano Brivio Subject: Re: [PATCH v5 4/9] log, passt: Always print to stderr before initialisation is complete Message-ID: References: <20240620161518.142285-1-sbrivio@redhat.com> <20240620161518.142285-5-sbrivio@redhat.com> MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha256; protocol="application/pgp-signature"; boundary="ppOapEVde64rflYV" Content-Disposition: inline In-Reply-To: <20240620161518.142285-5-sbrivio@redhat.com> Message-ID-Hash: PRZUTMEU7ZVL34IBQ6EK73554IGAFNUP X-Message-ID-Hash: PRZUTMEU7ZVL34IBQ6EK73554IGAFNUP X-MailFrom: dgibson@gandalf.ozlabs.org X-Mailman-Rule-Misses: dmarc-mitigation; no-senders; approved; emergency; loop; banned-address; member-moderation; nonmember-moderation; administrivia; implicit-dest; max-recipients; max-size; news-moderation; no-subject; digests; suspicious-header CC: passt-dev@passt.top, Yalan Zhang X-Mailman-Version: 3.3.8 Precedence: list List-Id: Development discussion and patches for passt Archived-At: Archived-At: List-Archive: List-Archive: List-Help: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: --ppOapEVde64rflYV Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable 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. >=20 > 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. >=20 > 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. >=20 > 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. >=20 > If this flag is not set, make sure we always print to stderr, if the > log mask matches. >=20 > Reported-by: Yalan Zhang > Signed-off-by: Stefano Brivio Reviewed-by: David Gibson 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(-) >=20 > 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 =3D -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() */ > =20 > static int log_file =3D -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 */ > =20 > int log_trace; /* --trace mode enabled */ > bool log_conf_parsed; /* Logging options already parsed */ > +bool log_runtime; /* Daemonised, or ready in foreground */ > =20 > 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); > } > =20 > - 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)] !=3D '\n') > fprintf(stderr, "\n"); > @@ -108,13 +109,15 @@ void trace_init(int enable) > /** > * __openlog() - Non-optional openlog() implementation, for custom vsysl= og() > * @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; > =20 > + (void)option; > + > clock_gettime(CLOCK_REALTIME, &tp); > log_start =3D tp.tv_sec; > =20 > @@ -135,7 +138,6 @@ void __openlog(const char *ident, int option, int fac= ility) > =20 > log_mask |=3D facility; > strncpy(log_ident, ident, sizeof(log_ident) - 1); > - log_opt =3D option; > } > =20 > /** > @@ -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; > =20 > /* Send without timestamp, the system logger should add it */ > - n =3D prefix_len =3D snprintf(buf, BUFSIZ, "<%i> %s: ", pri, log_ident); > + n =3D snprintf(buf, BUFSIZ, "<%i> %s: ", pri, log_ident); > =20 > n +=3D vsnprintf(buf + n, BUFSIZ - n, format, ap); > =20 > if (format[strlen(format)] !=3D '\n') > n +=3D snprintf(buf + n, BUFSIZ - n, "\n"); > =20 > - if (log_opt & LOG_PERROR) > - fprintf(stderr, "%s", buf + prefix_len); > - > if (log_sock >=3D 0 && send(log_sock, buf, n, 0) !=3D 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, ...) > =20 > extern int log_trace; > extern bool log_conf_parsed; > +extern bool log_runtime; > =20 > 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 =3D -1; > + char argv0[PATH_MAX], *name; > struct ctx c =3D { 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 =3D basename(argv0); > if (strstr(name, "pasta")) { > - __openlog(log_name =3D "pasta", LOG_PERROR, LOG_DAEMON); > + __openlog("pasta", 0, LOG_DAEMON); > =20 > sa.sa_handler =3D pasta_child_handler; > if (sigaction(SIGCHLD, &sa, NULL)) { > @@ -240,7 +240,7 @@ int main(int argc, char **argv) > =20 > c.mode =3D MODE_PASTA; > } else if (strstr(name, "passt")) { > - __openlog(log_name =3D "passt", LOG_PERROR, LOG_DAEMON); > + __openlog("passt", 0, LOG_DAEMON); > =20 > c.mode =3D MODE_PASST; > } else { > @@ -302,14 +302,13 @@ int main(int argc, char **argv) > if (isolate_prefork(&c)) > die("Failed to sandbox process, exiting"); > =20 > - 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()); > =20 > + log_runtime =3D true; > + > if (pasta_child_pid) > kill(pasta_child_pid, SIGUSR1); > =20 --=20 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 --ppOapEVde64rflYV Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQIzBAEBCAAdFiEEO+dNsU4E3yXUXRK2zQJF27ox2GcFAmZ009AACgkQzQJF27ox 2GdIgg//XQe7AK3Reyy091oYXZkPu/irUEcSEcnn8bz1F1YoPd9TshKpCivNu2VQ SxQNUZ+b2fK/iaOl2HHtWGlRf2D5O+pLWw6y0YxmRMcWmrHr2zEQlb698JZJsDQs VAiY4kpyyN6MhNNvwl5TzjceTVSba7Iu9gDp/Gii39qMuD1OsfPP8xjT6A9Jr6eJ Plc2ZVp2lJpRTIwrQDrPWrQ/RYDjw3ESTKq2c4rNIg//tY+/5J5Trj5RpR9EWMNT ufrQJfFmTUUeogW5THnoIdVnGqur8apM8bLDhhrb2NtZwbQMiSHaLfMCJBVFJu0/ M/Zo/jRAxd+/NJe+6O9sP6E0lCfkKN152upHa8160ZQbPODNLB6MGF+J/3a9cClT geY9r3l35Y3D93VKn3CwCMvOxFdI39wd8J7Z25UuZ9VSr6rNB9x0seLcSa2HoXq1 i3QpHSXz1RwLC2OzjNIrW80tnHjWm9wKO3UpbSDCAsVmMtsZl4dmkK8RbLsu3fKb /wC7Yb9tdTvf3J6d3Cvto4dMlN7hJYe8zn+yvmaaKdZTWVoVHFFi1WnQ8JbpFLsU pK9gYcSTMiceBQgiOU4egKVwcgyGJg9VpJUOvlqHiqtb2fXSS7rDuo8a0sr19s54 tdJHL1I3ptcAHy3ljqa1RaXmhr+p0ecNBhjuV53+SsKzhTppinQ= =YSPc -----END PGP SIGNATURE----- --ppOapEVde64rflYV--