Thread: Addition of %b/backend_type in log_line_prefix of TAP test logs
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
Attachment
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
> 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
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
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
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
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