Message-ID: <82ffc7a2-b77d-437b-a684-4a79a32fd87b@dalibo.com>
Date: Fri, 3 Jan 2025 11:25:35 +0100
MIME-Version: 1.0
User-Agent: Mozilla Thunderbird
Subject: Re: Logging parallel worker draught
To: Sami Imseih <samimseih@gmail.com>, Tomas Vondra <tomas@vondra.me>
Cc: Guillaume Lelarge <guillaume@lelarge.info>,
 Alena Rybakina <a.rybakina@postgrespro.ru>,
 pgsql-hackers <pgsql-hackers@postgresql.org>,
 "Imseih (AWS), Sami" <simseih@amazon.com>,
 Alvaro Herrera <alvherre@alvh.no-ip.org>, Robert Haas
 <robertmhaas@gmail.com>, Amit Kapila <amit.kapila16@gmail.com>,
 Melanie Plageman <melanieplageman@gmail.com>,
 "Andrey M. Borodin" <x4mmm@yandex-team.ru>
References: <10D5C31A-A303-4440-BCA2-921440A9E1CC@amazon.com>
 <0d08b978-10cb-4512-bcef-ca1f192049ab@enterprisedb.com>
 <0b7ef57e-bf30-440b-9478-d8f587f2637c@dalibo.com>
 <2cccd814-d7b3-4c9a-a66a-6df4c45fd95e@enterprisedb.com>
 <17f9faf1-4edb-46d0-80ed-91bba16423a3@dalibo.com>
 <7ECC97AE-2670-4792-BC6F-FD91B23F8E8C@yandex-team.ru>
 <39ac8951-6b99-469b-b9f1-2791efe43fbd@dalibo.com>
 <8123423a-f041-4f4c-a771-bfd96ab235b0@dalibo.com>
 <2a8e9e1c-0f05-4ebd-9a4d-d023d26c0def@dalibo.com>
 <04e6d7e2-f67a-438c-bc11-9354ab64ef1f@dalibo.com>
 <fbf19680-ce74-4f27-a890-e427ab330411@dalibo.com>
 <d4825c9e-9fd0-440e-aa3a-411f0b92bfc9@postgrespro.ru>
 <c14381b1-1f7a-4677-8b94-baa4dead9bc5@postgrespro.ru>
 <63d182f8-1a65-4e34-a335-403f53b14ba7@dalibo.com>
 <fd9b82bc-c853-4143-ba8f-35a693ee439c@dalibo.com>
 <CAECtzeX+tqQ0gLAiK558MtqLHvBEQM60i2UGSNJ1-QjMRFNYZg@mail.gmail.com>
 <31dc1548-30dc-4423-b939-2842c469f129@dalibo.com>
 <CAA5RZ0tS=Fmgku9=qCp-U4EBC-dqVtj+v_EGrKV_NA=THnUDsQ@mail.gmail.com>
Content-Language: fr
From: =?UTF-8?Q?Benoit_Lobr=C3=A9au?= <benoit.lobreau@dalibo.com>
Autocrypt: addr=benoit.lobreau@dalibo.com; keydata=
 xsBNBF3FR7IBCADDvtR0p09SI9OvnbWw+VEvO5IXefBWFWefxrPd0H3Sf3gsBLiKbRdkSjvz
 2y+ksRgBUkhK1Kiqe/QuddgvuT9OUFBCrOtZxkBgJYRbxBNTOnIehhEoK9sdqjwvwNyxJUEX
 er1UgErP+MJTvwpW1J8Uq9oV+NbqgNQ7ca5G2D3x7DI2Tbbw0iu+lmCIdXQpTk7hacErGscC
 p/eaJQFd6EPAZPS7BQEgjuDDjGCy4RzTSiobtqn0ocaEj+w7365FVKKZD2LjEm1mfBK/4nml
 H/vlssXkKKpUGetaib6AVpZK3a0xBTMi04ft/V8iGGJuVhE45WjjKSckmeLafTZCGxN9ABEB
 AAHNK0Jlbm9pdCBMb2Jyw6lhdSA8YmVub2l0LmxvYnJlYXVAZGFsaWJvLmNvbT7CwJQEEwEI
 AD4CGwMFCwkIBwIGFQoJCAsCBBYCAwECHgECF4AWIQRkbHJAht3VPY+ptaDDJY+vq0O76wUC
 Za56QgUJC6uZkAAKCRDDJY+vq0O760ECCACDPj6p9VXaX4GF9p+3zhoDwxsUWh0xODwsK//h
 SBGsRmPaElApbOR5rs2WDFaPE95XG3Vdo2rno7i4mt0fASls7vq4P0BPJiPM4fKEr+kfXAxP
 2clqmkBMn2o+EEeUGDmnn3RAVzDDoyML6N/unpyOTHWfscxvvj6AKreUtxzQm0LVQRL+hIaG
 SAlcwpVWQBPhA6Roi1/7Uz9qm8nWjFOuV6vO5yVe0sfRrrO9AFkjBGFT/B06sSs33Os6Hjs5
 2ckLn5Gxlty8XgTpbaG0bJiV+GDTcXh5UV8XVKaMomOLJxWw8US6PSSqQxodWuJqsvlxXV93
 ae6cMIosHsriaUo5zsBNBF3FR7IBCADEWwsQar1qtLKdoAoqKThz+kQXu3UADQ0c8JCgsp+8
 a6hFDg+uIw0j852lkJOPHll414Qw+kLC1bUo7H6+mPHzko/aR3TFz6vvOrm0afwFP7sm9Vbe
 UbpeohnrXBBwb1PjNhDphaXeMVovJqSgRifhc/sAR6fXi+2OCrH+8CUYa0aHhwoecStgw/tm
 EDPZ8lCsg5IdyO5Er4ZMOl/EbaRuTOpl7U/GzJBQSYf7t4KHotIpEeuJVv4X/+nTW3ALG+dG
 pRA5GplNnlQNfsEymnT4W7RbfafDp7Q7nK6w7d55ZU8UyiS6N/1wh/DL1hntC65lQbHlmwNx
 RG132ecNOcqFABEBAAHCwHwEGAEIACYCGwwWIQRkbHJAht3VPY+ptaDDJY+vq0O76wUCZa56
 dQUJC6uZwwAKCRDDJY+vq0O76y9jB/0fVyz7D56D2A6MUGASNkh6IiuHCF/UgEfU0m5fC6pd
 38+fmyUMkGR3QwrtZP3SCLaBKT4LHxhVu7tEUWI+6WK7/s0Jsx5L8aIfDKY4zjqQ9InP+LkA
 azkKW4JpIb9Ny0FzRjUyf9gReU5nMy9sUNS4DhoHG6c/bQYqkj9uA5AokiDDCRg2dobfpaNP
 C6qQQIXD+wi0aZ4jR5r4rXMxmwFutandoaxDpPBj4EXlyRHhzyKfgb2c6TXdCVQ5YJUFUi9k
 gl7CXplN8vBpMuzN5y6NPd3Xekcp16D5XCQNBQ2drIsnFR4IbDPI1Mqd6OJYH0vum6g8FmoN
 s7ygc4oi12nU
In-Reply-To: 
 <CAA5RZ0tS=Fmgku9=qCp-U4EBC-dqVtj+v_EGrKV_NA=THnUDsQ@mail.gmail.com>
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 8bit
Archived-At: 
 <https://www.postgresql.org/message-id/82ffc7a2-b77d-437b-a684-4a79a32fd87b%40dalibo.com>
Precedence: bulk

Hi, thank you for the review and sorry for the delayed answer.

On 12/28/24 05:17, Sami Imseih wrote:> Thinking about this further, it 
seems to me this logging only makes sense
 > for parallel query and not maintenance commands. This is because
 > for the latter case, the commands are executed manually and a user 
can issue
 > VACUUM VERBOSE ( for the case of vacuum ). For CREATE INDEX, one
 > can enable DEBUG1. For example:
 >
 > postgres=# CREATE INDEX tbl_c1 ON tbl(c1);
 > DEBUG:  building index "tbl_c1" on table "tbl" with request for 1
 > parallel workers
 > DEBUG:  index "tbl_c1" can safely use deduplication
 > CREATE INDEX


In my opinion, it's useful:

* Centralization of logs: The maintenance operation can be planned in
cron jobs. In that context, it could certainly be logged separately via
the script. However, when I am doing an audit on a client database, I
think it's useful to have all the relevant information in PostgreSQL logs.

* Centralization of the configuration: If I am auditing the usage of
parallelism, I would like to have a single GUC to enable the logging
for all relevant information.

* Context: Maintenance workers are part of the global pool of workers.
To know why there is a shortage after the fact, having all the information
on what was using workers could be useful. I tied this argument when we
added the parallel worker info to pg_stat_database and wasn't successful.
It would be nice to have the info somewhere.

The logging for CREATE INDEX and VACUUM is in separate patches. If you
don't mind, I would like to keep it as long as possible.

 > 2/ For logging parallel query workers, the log line could be simpler.
 >
 > Instead of:
 >
 > + elog(LOG, "%i parallel nodes planned (%i obtained all their workers,
 > %i obtained none), "
 > + "%i workers planned to be launched (%i workers launched)",
 >
 > what about something like:
 >
 > "launched %d parallel workers (planned: %)"
 >
 > For example, if I have 2 gather nodes and they each plan and launch
 > 2 workers, the log line should be as simple as
 >
 > "launched 4 parallel workers (planned: 4)"
 >
 > This behavior in which workers planned and launched are aggregated in the
 > log can be described in the documentation.

"%i parallel nodes planned (%i obtained all their workers, %i obtained 
none),"

I added this part during my first reorganization. I was trying to extract
as much information as possible and thought that the special case where a
parallel node was planned but no workers were obtained was the worst-case
scenario, which might be interesting to log.

If you think it doesn't bring much value, we can strip it.

 > 3/ Also, log_parallel_query_workers as the name of the GUC will make 
more sense
 > if we go logging parallel query only.

I agree that log_parallel_query_workers would make more sense if we focus
on logging parallel queries only. Since the maintenance-related logging
was added later, I missed this point. Thank you for bringging this up.

If agreeable, I will rename the GUC to log_parallel_workers as long as
the argument regarding maintenance workers is unresolved. If we decide
to strip them, I will revert it to log_parallel_query_workers.

 >> I don't think "failure" is a good name for the setting as it's
 >> a bit too harsh. What we really have is a "shortage" of
 >> workers.

I agree that "failure" is too harsh. The term "shortage" better describes
the situation.

Note: I added Tomas Vondra to the recipients of the email since he advised
me on this topic initially and might have an opinion on this.

-- 
Benoit Lobréau
Consultant
http://dalibo.com