Horton

Thread

Commits

  1. Align log_line_prefix in CI and TAP tests with pg_regress.c

  1. Addition of %b/backend_type in log_line_prefix of TAP test logs

    Michael Paquier <michael@paquier.xyz> — 2025-05-20T23:51:04Z

    Hi all,

While navigating through the logs in the CI, the buildfarm, or even my
own machine, I've found myself spending a lot of time looking at
very specific log entries to find out the PID of a specific process,
sometimes mistaking a normal backend vs a logical WAL sender while
looking for a PID, or just looking for an auxiliary process.

I'd like to suggest the following change in Cluster.pm:
-   print $conf "log_line_prefix = '%m [%p] %q%a '\n";
+   print $conf "log_line_prefix = '%m [%b,%p] %q%a '\n";

It is then possible to match a backend_type with a PID.  That
increases the quantity of the logs, of course, but I'm finding that
really helpful to have.  But perhaps it's only me?

Thanks,
--
Michael

  2. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Fujii Masao <masao.fujii@gmail.com> — 2025-05-21T02:41:18Z

    On Wed, May 21, 2025 at 8:51 AM Michael Paquier <michael@paquier.xyz> wrote:
>
> Hi all,
>
> While navigating through the logs in the CI, the buildfarm, or even my
> own machine, I've found myself spending a lot of time looking at
> very specific log entries to find out the PID of a specific process,
> sometimes mistaking a normal backend vs a logical WAL sender while
> looking for a PID, or just looking for an auxiliary process.
>
> I'd like to suggest the following change in Cluster.pm:
> -   print $conf "log_line_prefix = '%m [%p] %q%a '\n";
> +   print $conf "log_line_prefix = '%m [%b,%p] %q%a '\n";

+1 to this change.

Since pg_regress uses log_line_prefix = '%m %b[%p] %q%a ',
isn't it better to use the same setting in TAP tests as well?

Regards,

-- 
Fujii Masao

  3. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Michael Paquier <michael@paquier.xyz> — 2025-05-21T02:48:49Z

    On Wed, May 21, 2025 at 11:41:18AM +0900, Fujii Masao wrote:
> Since pg_regress uses log_line_prefix = '%m %b[%p] %q%a ',
> isn't it better to use the same setting in TAP tests as well?

Oh, right, good point.  I've managed to miss this part in
pg_regress.c.  Using the same value makes even more sense.
--
Michael

  4. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Daniel Gustafsson <daniel@yesql.se> — 2025-05-21T07:24:26Z

    > On 21 May 2025, at 04:48, Michael Paquier <michael@paquier.xyz> wrote:
> 
> On Wed, May 21, 2025 at 11:41:18AM +0900, Fujii Masao wrote:
>> Since pg_regress uses log_line_prefix = '%m %b[%p] %q%a ',
>> isn't it better to use the same setting in TAP tests as well?
> 
> Oh, right, good point.  I've managed to miss this part in
> pg_regress.c.  Using the same value makes even more sense.

Agreed, and +1 on the change in general.

--
Daniel Gustafsson

  5. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Michael Paquier <michael@paquier.xyz> — 2025-05-21T23:50:04Z

    On Wed, May 21, 2025 at 09:24:26AM +0200, Daniel Gustafsson wrote:
> Agreed, and +1 on the change in general.

Another point perhaps worth considering after a second look: how about
pg_ci_base.conf?  We have the following line there, exposing this
configuration with TEMP_CONFIG:
src/tools/ci/pg_ci_base.conf:log_line_prefix = '%m [%p][%b] %q[%a][%v:%x] '

The two other ones are:
src/test/perl/PostgreSQL/Test/Cluster.pm: '%m [%p] %q%a '
src/test/regress/pg_regress.c: '%m %b[%p] %q%a '

Perhaps it would be better to apply the same configuration as the CI
by default at the end?  The difference is that the CI exposes
[virtual] XIDs.  I've never used this information for debugging, but
that may be worth considering for consistency?  This would make easier
checks across the buildfarm, the CI or local machines when looking for
differences in the logs with the same tests.

(I was incorrect previously about CI not using backend_type upthread.) 
--
Michael

  6. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Tom Lane <tgl@sss.pgh.pa.us> — 2025-05-21T23:58:51Z

    Michael Paquier <michael@paquier.xyz> writes:
> On Wed, May 21, 2025 at 09:24:26AM +0200, Daniel Gustafsson wrote:
>> Agreed, and +1 on the change in general.

> Another point perhaps worth considering after a second look: how about
> pg_ci_base.conf?  We have the following line there, exposing this
> configuration with TEMP_CONFIG:
> src/tools/ci/pg_ci_base.conf:log_line_prefix = '%m [%p][%b] %q[%a][%v:%x] '

> The two other ones are:
> src/test/perl/PostgreSQL/Test/Cluster.pm: '%m [%p] %q%a '
> src/test/regress/pg_regress.c: '%m %b[%p] %q%a '

> Perhaps it would be better to apply the same configuration as the CI
> by default at the end?

I'd vote for standardizing on pg_regress.c's spelling, as that's got
the most usage history behind it.  I'm unexcited about bloating the
logs with [%v:%x] --- that's data I've very seldom needed.

			regards, tom lane

  7. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Fujii Masao <masao.fujii@oss.nttdata.com> — 2025-05-23T14:56:59Z

    
On 2025/05/22 8:58, Tom Lane wrote:
> Michael Paquier <michael@paquier.xyz> writes:
>> On Wed, May 21, 2025 at 09:24:26AM +0200, Daniel Gustafsson wrote:
>>> Agreed, and +1 on the change in general.
> 
>> Another point perhaps worth considering after a second look: how about
>> pg_ci_base.conf?  We have the following line there, exposing this
>> configuration with TEMP_CONFIG:
>> src/tools/ci/pg_ci_base.conf:log_line_prefix = '%m [%p][%b] %q[%a][%v:%x] '
> 
>> The two other ones are:
>> src/test/perl/PostgreSQL/Test/Cluster.pm: '%m [%p] %q%a '
>> src/test/regress/pg_regress.c: '%m %b[%p] %q%a '
> 
>> Perhaps it would be better to apply the same configuration as the CI
>> by default at the end?
> 
> I'd vote for standardizing on pg_regress.c's spelling, as that's got
> the most usage history behind it.  I'm unexcited about bloating the
> logs with [%v:%x] --- that's data I've very seldom needed.

+1

Regards,

-- 
Fujii Masao
NTT DATA Japan Corporation

  8. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Michael Paquier <michael@paquier.xyz> — 2025-05-24T00:09:36Z

    On Fri, May 23, 2025 at 11:56:59PM +0900, Fujii Masao wrote:
> On 2025/05/22 8:58, Tom Lane wrote:
>> Michael Paquier <michael@paquier.xyz> writes:
>>> Another point perhaps worth considering after a second look: how about
>>> pg_ci_base.conf?  We have the following line there, exposing this
>>> configuration with TEMP_CONFIG:
>>> src/tools/ci/pg_ci_base.conf:log_line_prefix = '%m [%p][%b] %q[%a][%v:%x] '
>> 
>>> The two other ones are:
>>> src/test/perl/PostgreSQL/Test/Cluster.pm: '%m [%p] %q%a '
>>> src/test/regress/pg_regress.c: '%m %b[%p] %q%a '
>> 
>>> Perhaps it would be better to apply the same configuration as the CI
>>> by default at the end?
>> 
>> I'd vote for standardizing on pg_regress.c's spelling, as that's got
>> the most usage history behind it.  I'm unexcited about bloating the
>> logs with [%v:%x] --- that's data I've very seldom needed.
> 
> +1

The %v:%x business in log_line_prefix has been introduced in
93d973494613 by Andres.  Adding him in CC for comments about the CI
part. 
--
Michael

  9. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Michael Paquier <michael@paquier.xyz> — 2025-06-20T07:20:21Z

    On Sat, May 24, 2025 at 09:09:36AM +0900, Michael Paquier wrote:
> On Fri, May 23, 2025 at 11:56:59PM +0900, Fujii Masao wrote:
>> On 2025/05/22 8:58, Tom Lane wrote:
>>> I'd vote for standardizing on pg_regress.c's spelling, as that's got
>>> the most usage history behind it.  I'm unexcited about bloating the
>>> logs with [%v:%x] --- that's data I've very seldom needed.
>> 
>> +1

Coming back to this thread as v19 is going to open up rather soon, the
suggestion from Tom seems to be the consensus reached, which is to use
the same value of log_line_prefix in the CI and the TAP as in
pg_regress.c.  Attached is a patch to do so, that I'd like to apply on
HEAD once v19 opens up.

If anybody would prefer a backpatch or if anybody has any comments,
please feel free.
--
Michael

  10. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Andres Freund <andres@anarazel.de> — 2025-06-20T14:21:21Z

    Hi,

On 2025-05-24 09:09:36 +0900, Michael Paquier wrote:
> On Fri, May 23, 2025 at 11:56:59PM +0900, Fujii Masao wrote:
> > On 2025/05/22 8:58, Tom Lane wrote:
> >> Michael Paquier <michael@paquier.xyz> writes:
> >>> Another point perhaps worth considering after a second look: how about
> >>> pg_ci_base.conf?  We have the following line there, exposing this
> >>> configuration with TEMP_CONFIG:
> >>> src/tools/ci/pg_ci_base.conf:log_line_prefix = '%m [%p][%b] %q[%a][%v:%x] '
> >>
> >>> The two other ones are:
> >>> src/test/perl/PostgreSQL/Test/Cluster.pm: '%m [%p] %q%a '
> >>> src/test/regress/pg_regress.c: '%m %b[%p] %q%a '
> >>
> >>> Perhaps it would be better to apply the same configuration as the CI
> >>> by default at the end?
> >>
> >> I'd vote for standardizing on pg_regress.c's spelling, as that's got
> >> the most usage history behind it.  I'm unexcited about bloating the
> >> logs with [%v:%x] --- that's data I've very seldom needed.
> >
> > +1
>
> The %v:%x business in log_line_prefix has been introduced in
> 93d973494613 by Andres.  Adding him in CC for comments about the CI
> part.

I'm fine with that.

I'm not a huge fan of "%b" instead of "[%b]", but it doesn't matter much.

Greetings,

Andres Freund

  11. Re: Addition of %b/backend_type in log_line_prefix of TAP test logs

    Michael Paquier <michael@paquier.xyz> — 2025-06-30T05:12:57Z

    On Fri, Jun 20, 2025 at 04:20:21PM +0900, Michael Paquier wrote:
> Coming back to this thread as v19 is going to open up rather soon, the
> suggestion from Tom seems to be the consensus reached, which is to use
> the same value of log_line_prefix in the CI and the TAP as in
> pg_regress.c.  Attached is a patch to do so, that I'd like to apply on
> HEAD once v19 opens up.

And done on HEAD, aka v19.
--
Michael