From mboxrd@z Thu Jan  1 00:00:00 1970
Received: from gandalf.ozlabs.org (mail.ozlabs.org [IPv6:2404:9400:2221:ea00::3])
	by passt.top (Postfix) with ESMTPS id 28B215A026D
	for <passt-dev@passt.top>; Fri,  2 Feb 2024 02:02:30 +0100 (CET)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
	d=gibson.dropbear.id.au; s=202312; t=1706835745;
	bh=FKtvgPFHE4G4CEvXFqaw8IlB4Hm7IVuX9s2cI4cGUhQ=;
	h=Date:From:To:Cc:Subject:References:In-Reply-To:From;
	b=mpWl902OMaSI2jWG2NzdFSWs+ANa1xMhAx1YyHfuwyDxVJQktTap8QpsQNWfxoXv8
	 6mbJKbTt1vhx3sLA18EQhKVnRi4lPmml5xMu7PBTDowNcCWLlAH3gCv6uXYu3IpVDV
	 7+HMgq92OkWbnBoDhWPuxjGAL8qqX43I3yweal6zj/uMwSUnnXQ1O9VXdQL+tcvqZs
	 J7x7pTPIR/wKWmRFurP8V/oUuc4YZy47SnCI5gYgcHEhcEhYRpH25l/g70JadBV+dF
	 Nfwg0ex6DEyWvZeOMS2G2jsiOtXRoWntLBwzVNAZEnu8zwuNmiBU96qy5IO0flIaWk
	 HR4Hfrxo86qPA==
Received: by gandalf.ozlabs.org (Postfix, from userid 1007)
	id 4TQyDK3cCsz4wcV; Fri,  2 Feb 2024 12:02:25 +1100 (AEDT)
Date: Fri, 2 Feb 2024 12:02:19 +1100
From: David Gibson <david@gibson.dropbear.id.au>
To: Stefano Brivio <sbrivio@redhat.com>
Subject: Re: [PATCH] log: setlogmask(0) can actually result in a system call,
 don't use it
Message-ID: <Zbw_G6NrHIF2zWFg@zatzit>
References: <20240201233257.2287025-1-sbrivio@redhat.com>
MIME-Version: 1.0
Content-Type: multipart/signed; micalg=pgp-sha256;
	protocol="application/pgp-signature"; boundary="iotE1ki/Ci8gV38p"
Content-Disposition: inline
In-Reply-To: <20240201233257.2287025-1-sbrivio@redhat.com>
Message-ID-Hash: GG4LZO4RQTU33CSKLWKUAHFCJEJDXFUH
X-Message-ID-Hash: GG4LZO4RQTU33CSKLWKUAHFCJEJDXFUH
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, Laurent Vivier <lvivier@redhat.com>
X-Mailman-Version: 3.3.8
Precedence: list
List-Id: Development discussion and patches for passt <passt-dev.passt.top>
Archived-At: <https://archives.passt.top/passt-dev/Zbw_G6NrHIF2zWFg@zatzit/>
Archived-At: <https://passt.top/hyperkitty/list/passt-dev@passt.top/message/GG4LZO4RQTU33CSKLWKUAHFCJEJDXFUH/>
List-Archive: <https://archives.passt.top/passt-dev/>
List-Archive: <https://passt.top/hyperkitty/list/passt-dev@passt.top/>
List-Help: <mailto:passt-dev-request@passt.top?subject=help>
List-Owner: <mailto:passt-dev-owner@passt.top>
List-Post: <mailto:passt-dev@passt.top>
List-Subscribe: <mailto:passt-dev-join@passt.top>
List-Unsubscribe: <mailto:passt-dev-leave@passt.top>


--iotE1ki/Ci8gV38p
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
Content-Transfer-Encoding: quoted-printable

On Fri, Feb 02, 2024 at 12:32:57AM +0100, Stefano Brivio wrote:
> Before commit 32d07f5e59f2 ("passt, pasta: Completely avoid dynamic
> memory allocation"), we didn't store the current log mask in a
> variable, and we fetched it using setlogmask(0) wherever needed.
>=20
> But after that commit, we can just use our log_mask copy instead. And
> we should: with recent glibc versions, setlogmask(0) actually results
> in a system call, which causes a substantial overhead with high
> transfer rates: we use setlogmask(0) even to decide we don't want to
> print debug messages.
>=20
> Signed-off-by: Stefano Brivio <sbrivio@redhat.com>

The basic idea looks fine to me, but there's a curly edge case.  At
present vlogmsg() works ok before __openlog(), sending the message to
stderr.  We rely on this because there are die() calls before our
__openlog(), which go via err() -> vlogmsg().

With this change, before the first __setlogmask(), which occurs right
after the __openlog() then log_mask is initialized to zero.  Which
means, AFAICT, that we'll suppress all error messages before that
point, which isn't great.

> ---
>  log.c | 10 +++++-----
>  1 file changed, 5 insertions(+), 5 deletions(-)
>=20
> diff --git a/log.c b/log.c
> index 4a70e29..a66ecb7 100644
> --- a/log.c
> +++ b/log.c
> @@ -45,33 +45,33 @@ static time_t	log_start;		/* Start timestamp */
>  int		log_trace;		/* --trace mode enabled */
>  int		log_to_stdout;		/* Print to stdout instead of stderr */
> =20
> -#define BEFORE_DAEMON		(setlogmask(0) =3D=3D LOG_MASK(LOG_EMERG))
> +#define BEFORE_DAEMON		(log_mask =3D=3D LOG_MASK(LOG_EMERG))
> =20
>  void vlogmsg(int pri, const char *format, va_list ap)
>  {
>  	FILE *out =3D log_to_stdout ? stdout : stderr;
>  	struct timespec tp;
> =20
> -	if (setlogmask(0) & LOG_MASK(LOG_DEBUG) && log_file =3D=3D -1) {
> +	if (log_mask & LOG_MASK(LOG_DEBUG) && log_file =3D=3D -1) {
>  		clock_gettime(CLOCK_REALTIME, &tp);
>  		fprintf(out, "%lli.%04lli: ",
>  			(long long int)tp.tv_sec - log_start,
>  			(long long int)tp.tv_nsec / (100L * 1000));
>  	}
> =20
> -	if ((LOG_MASK(LOG_PRI(pri)) & log_mask) || BEFORE_DAEMON) {
> +	if ((log_mask & LOG_MASK(LOG_PRI(pri))) || BEFORE_DAEMON) {
>  		va_list ap2;
> =20
>  		va_copy(ap2, ap); /* Don't clobber ap, we need it again */
>  		if (log_file !=3D -1)
>  			logfile_write(pri, format, ap2);
> -		else if (!(setlogmask(0) & LOG_MASK(LOG_DEBUG)))
> +		else if (!(log_mask & LOG_MASK(LOG_DEBUG)))
>  			passt_vsyslog(pri, format, ap2);
> =20
>  		va_end(ap2);
>  	}
> =20
> -	if ((setlogmask(0) & LOG_MASK(LOG_DEBUG) && log_file =3D=3D -1) ||
> +	if ((log_mask & LOG_MASK(LOG_DEBUG) && log_file =3D=3D -1) ||
>  	    (BEFORE_DAEMON && !(log_opt & LOG_PERROR))) {
>  		(void)vfprintf(out, format, ap);
>  		if (format[strlen(format)] !=3D '\n')

--=20
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

--iotE1ki/Ci8gV38p
Content-Type: application/pgp-signature; name="signature.asc"

-----BEGIN PGP SIGNATURE-----

iQIzBAEBCAAdFiEEO+dNsU4E3yXUXRK2zQJF27ox2GcFAmW8PwMACgkQzQJF27ox
2GcSfA//eMSsL7C9zH18MWATgGMF6hkiTKELmP6xmwkELY3hieRYDnmWzeLDTUSK
ByZZ1TCjkIxuHFjT/JTNcY81bSNFIQEjczSrta8qZr4zd+G0ACX9QmW7h5sVm9dJ
biGhvn9YmjPY7iwBplpeWKZwlqU7M6J3WT1ZaeEANz3gZ9NTsKLtXPixJ3BPHrd1
n44cWnfaxTTgI0yY0tJqYh7AVYbbPVDE+mS3+1xk/6luXGfVC8CsomlZgrPwjrSr
9LURAgwmvhNoHM/U0CPtFMY6NyOvH04YYFMRoCSapZjT5D4RLOELG6Q/5T96Wb3x
GGe4vq7azqoNAWsoh9nqVsaN2woEnCLZIPXL0HuH59BjZ0Tp/F94H4ZB9HaCjCiv
U4eAtU9fgzjhfuVoZvwRV3C1rUDemTdFhNP7hIDs29hx9km3fGbfbx+iXn88yMaE
fjDd++MoTuEDs9xbTW/eFzWP5HOX1rDypPZuct77JK6pzpxEAseCe3mYZHAfCNGy
s9EXJ0X1nm1TbZ7nZ6lhcsumFHveMQgm2R7dtuw8yla81UGggUVwy028l/k7DWYA
rWp487hfE+Zp74ioYQ2CdqpY8fZ/Cb5i/K6b6jtsYKgZ8fMNFfx4yA++Yt/Won7u
fCdmMZY6EAvsvXQNUntlEldBYuSBSPwbJ/j/gb9sdT6++yr0VAE=
=hb09
-----END PGP SIGNATURE-----

--iotE1ki/Ci8gV38p--