Feedback-ID: i0fe9450f:Fastmail
Date: Mon, 10 Mar 2025 09:23:50 +0900
From: Michael Paquier <michael@paquier.xyz>
To: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Cc: pgsql-hackers@lists.postgresql.org
Subject: Re: [BUG]: the walsender does not update its IO statistics until it
 exits
Message-ID: <Z84xFrbmnW7Knb1Q@paquier.xyz>
References: <Z73IsKBceoVd4t55@ip-10-97-1-34.eu-west-3.compute.internal>
 <Z762lusJXp_wNF_z@paquier.xyz>
 <Z77jgvhwOu9S0a5r@ip-10-97-1-34.eu-west-3.compute.internal>
 <Z8FMjlyNpNicucGa@paquier.xyz>
 <Z8GSY8mk+0qVHzsW@ip-10-97-1-34.eu-west-3.compute.internal>
 <Z8ULFzNY24_SMCdu@paquier.xyz>
 <Z8WYf1jyy4MwOveQ@ip-10-97-1-34.eu-west-3.compute.internal>
MIME-Version: 1.0
Content-Type: multipart/signed; micalg=pgp-sha512;
	protocol="application/pgp-signature"; boundary="TaFAQgBvCPQv0CQe"
Content-Disposition: inline
In-Reply-To: <Z8WYf1jyy4MwOveQ@ip-10-97-1-34.eu-west-3.compute.internal>
Archived-At: 
 <https://www.postgresql.org/message-id/Z84xFrbmnW7Knb1Q%40paquier.xyz>
Precedence: bulk


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

On Mon, Mar 03, 2025 at 11:54:39AM +0000, Bertrand Drouvot wrote:
> So it does not look like what we're adding here can be seen as a primary =
bottleneck
> but that is probably worth implementing the "have_iostats" optimization a=
ttached.
>=20
> Also, while I did not measure any noticeable extra lag, given the fact th=
at=20
> pgstat_flush_io() shows at about 5.5% and pgstat_flush_backend() at about=
 2.5%,
> that could still make sense to reduce the frequency of the flush calls, t=
houghts?

Okay.  The number of reports really worry me anyway as proposed in the
patch.  It's not really complicated to see dozens of pgstats calls in
a single millisecond in the WAL sender, even with some of the
regression tests.  That's more present in the logirep scenarios, it
seems..

For example, here are some numbers based on some elog() calls planted
in walreceiver.c, looking at the logs of the TAP tests.  Through a
single check-world, I am able to gather the following information:
- The location proposed by the patch leads to 680k stats reports,
in WalSndLoop() because the "Block if we have unsent data".  Some
tests show quite some contention.
- A different location, in WalSndLoop() just before WalSndWait() leads
to 59k calls.  And there's some contention in the logirep tests..
- I've spotted a third candidate which looks pretty solid, actually:
WalSndWaitForWal() before WalSndWait().  This leads to 2.9k reports in
the whole test suite, with much less contention in the reports.  These
can still be rather frequent, up to ~50 calls per seconds, but that's
really less than the two others.

Stats data is useful as long as it is possible to get an idea of how
the system behaves, particularly with a steady workload.  More
frequent reports are useful for spikey data detection, showing more
noise.  Still, too many reports may cause the part gathering the
reports to become a bottleneck, while we want it to offer hints about
bottlenecks.  So I would argue in favor of a more conservative choice
in the back branches than what the patch is proposing.  Choice 3 i'm
quoting above is tempting by design: not too much, still frequent
enough to offer enough relevant information in the stats.
--
Michael

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

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

iQIzBAABCgAdFiEEG72nH6vTowiyblFKnvQgOdbyQH0FAmfOMRYACgkQnvQgOdby
QH1U8xAAmi+8sU+0lZyCbi8OX/iAYMZDeG2MM2ID1Jjd1ZcboLCU7lYcO1SAeZ+j
qTi7vMB0+CL6m0lQ703m50wF7yLWOk94UNHZ+wYmvLrSKSqiw8acbvdAQ2DXkEbR
0SAdmF1y/xlZTj9br/C2EjxyMelwXmm08k5P9VXiseU+z+RPCGuHZfAhyRx52Lz7
aCvujKLiRuwCTHveP3wR4PrWQq93Er8Ns4V57Vw5wX367jr7twgetF0mHejzULGu
ADIVAlRYiJU+CvivluBvcxqKa7HCnHHISgsXCqvIK/Cb+jpWuLLoGMmB7cRIp6RM
gws3NVRL2wGp0/GgSKu1VGlJU/OOFtm1TD5hTOts7r2VmdYM1astMxZLTbx4Ijse
dmSmlq5IYX+aJLd6SKhe50At8cAXuywLep3aXyhOeDmyinse3PKU2csMH+KJ0Ube
PgEtdXdif3jAGmpkhIIziTzUF1w16xOpP3Jrbz+UZg0CeNFlmZ5WF8CYQYqhcr+j
PsLHEAAsFZnnzaRpPU/AP2ZXMktS2rG+ZGyM/rQA3JahaukRKvpTRvX3E7YkZEqD
a2X8HKM7yEUp464OkCLS76CMhyrzrLkLq2qHR6wwszmBgSIjB8sTbx2F3222QBx0
gv2G4eRLw7AzEsq5zv7GpOnER4o8TjhqLCMDdcqBcFTnJcU4AJg=
=MCO5
-----END PGP SIGNATURE-----

--TaFAQgBvCPQv0CQe--