Get rid of redundant StringInfo accumulation

On Sun, Mar 29, 2026 at 11:26 PM Daniil Davydov <3danissimo@gmail.com> wrote:

Hi,

I have noticed that there are several places in the code where we are
creating StringInfo in order to log its content. But this work may be wasted
if the specified log level is not interesting both for client and server.
I.e. now we can allocate memory for StringInfo which will never be displayed.

I think that at first we should check whether log level is interesting and
only then start creating the StringInfo.

Please, see the attached patch that fixes it. I hope I have found all the
places where it would be appropriate.

Hi,

1.
@@ -108,6 +108,9 @@ ReportApplyConflict(EState *estate, ResultRelInfo
*relinfo, int elevel,
Relation localrel = relinfo->ri_RelationDesc;
StringInfoData err_detail;

+ if (!message_level_is_interesting(elevel))
+ return;
+

AFAICT, this change will also cause the
pgstat_report_subscription_conflict() to be skipped. But that call was
not associated with the log level.

======
Kind Regards,
Peter Smith.
Fujitsu Australia

Hi,

On Mon, Mar 30, 2026 at 4:52 AM Peter Smith <smithpb2250@gmail.com> wrote:

1.
@@ -108,6 +108,9 @@ ReportApplyConflict(EState *estate, ResultRelInfo
*relinfo, int elevel,
Relation localrel = relinfo->ri_RelationDesc;
StringInfoData err_detail;

+ if (!message_level_is_interesting(elevel))
+ return;
+

AFAICT, this change will also cause the
pgstat_report_subscription_conflict() to be skipped. But that call was
not associated with the log level.

Thank you for looking into it!

Yeah, now the report_subscription_conflict call may be mistakenly skipped.
Since it just adds pgstat pending entry and does not depend on the log level,
I'll move this call above the log level check. I think this is OK, because
pgstat accumulation has nothing common with logging that we are trying to skip.

Please, see the updated patch.

--
Best regards,
Daniil Davydov

Hi,

On 2026-03-29 19:26:11 +0700, Daniil Davydov wrote:

I have noticed that there are several places in the code where we are
creating StringInfo in order to log its content. But this work may be wasted
if the specified log level is not interesting both for client and server.
I.e. now we can allocate memory for StringInfo which will never be displayed.

I think that at first we should check whether log level is interesting and
only then start creating the StringInfo.

Please, see the attached patch that fixes it. I hope I have found all the
places where it would be appropriate.

I don't see when the overhead of creating an populating the string info ever
matters in these cases. This is optimizing something that never can matter for
real world performance. Even if it were worth optimizing them, I doubt that
the log level check is useful here, because most if not all of these are
logged with a level that's logged in nearly all installations.

Greetings,

Andres Freund

Hi,

On Mon, Mar 30, 2026 at 7:52 PM Andres Freund <andres@anarazel.de> wrote:

I don't see when the overhead of creating an populating the string info ever
matters in these cases. This is optimizing something that never can matter for
real world performance. Even if it were worth optimizing them, I doubt that
the log level check is useful here, because most if not all of these are
logged with a level that's logged in nearly all installations.

Thank you for the review!

I have a few arguments to defend this patch :
1)
It is normal practice in the code base to check log level before allocating
memory for StringInfo or some other structure. For example, I found the log
level check even before a very lightweight piece of code (see xlogutils.c)
and even if we are going to emit log with DEBUG3 level (see postmaster.c).
2)
Originally, I created this patch in order to avoid spending time during
acquiring LWLock before entering the GetLockHoldersAndWaiters function. The
log_lock_waits parameter is "true" by default, so even if log level is high,
we will *waste* time on the lock acquiring. I.e. this patch is not only about
getting rid of redundant memory allocation - it is also about reducing waiting
time on the locks. I think that it may be noticeable in conditions of a huge
number of parallel processes.
3)
I don't think that all other places (except lock.c and proc.c) where I have
added log level check are really matter for real world performance. This is
more about consistent approach : if we check log level in lock.c, then we
should check it everywhere (if it makes sense). Again, it is normal practice
for the postgres' code.

Am I missing something?

BTW, during writing it I noticed that I forgot to add log level check for
pretty important code path (proc.c). Please, see it in the v3 patch.

--
Best regards,
Daniil Davydov

On Tue, 31 Mar 2026 at 03:24, Daniil Davydov <3danissimo@gmail.com> wrote:

Am I missing something?

I have an opinion here too. It's similar to Andres', and I expect you
won't like it:

Looking at the other users of message_level_is_interesting(), every
one of them that's passing a const is using one of the DEBUG levels,
in which case the vast majority of the time we will take the
short-circuit path. All of the direct cases you're adding pass LOG.
Indirectly, I see some DEBUG3s being passed via
KnownAssignedXidsDisplay(), so maybe that's worth it. I don't know.
You've offered us nothing in terms of performance results from patched
vs unpatched. For me, when I see that, I just assume the person wrote
the patch because they can, not because they thought it was a good
idea. Since this place is rife with people using things like static
analysers and AI tools to give them patch ideas, and since those tools
have about zero context as to if the patch is a good idea or not, it's
very much not inspiring to commit any patch that comes with no proof
that it does what it's meant to do, especially one that has a
trade-off that is disadvantageous to people running the standard
logging levels.

If you still think this is a good idea, then you're going to need to
show benchmark results and scripts to prove that the extra overhead of
message_level_is_interesting() is low enough and the advantages of
skipping the extra StringInfo code is good enough to warrant doing
this. If you don't think that's worth your time, then why do you think
it's worth someone else's? It's your patch.

David

Hi,

On Tue, Mar 31, 2026 at 6:53 AM David Rowley <dgrowleyml@gmail.com> wrote:

Looking at the other users of message_level_is_interesting(), every
one of them that's passing a const is using one of the DEBUG levels,
in which case the vast majority of the time we will take the
short-circuit path. All of the direct cases you're adding pass LOG.
Indirectly, I see some DEBUG3s being passed via
KnownAssignedXidsDisplay(), so maybe that's worth it. I don't know.

OK, I see that you doubt that users will not set their min_messages above the
"LOG" log level. I asked a few people from my company who are well aware of
typical customer settings. They say that log_min_messages is set to WARNING
the vast majority of the time (hah, I like the phrase, as you can see).
With the client_min_messages parameter the situation is less unambiguous. It
is usually higher than NOTICE, but if postgres starts behaving "suspiciously",
users immediately lower the parameter value (up to DEBUG5). Pretty obvious use
case. Nobody wants to have huge log files, especially if we remember that the
most common error in the production-level systems is "no space left on device".

For me, when I see that, I just assume the person wrote
the patch because they can, not because they thought it was a good
idea. Since this place is rife with people using things like static
analysers and AI tools to give them patch ideas...

Wow. It sounds pretty unpleasant, but it's your right to write so.
Anyway, let's concentrate on the patch.

very much not inspiring to commit any patch that comes with no proof
that it does what it's meant to do, especially one that has a
trade-off that is disadvantageous to people running the standard
logging levels.

As I wrote above, the log level is typically high in the production-level
systems. Of course, I won't be able to provide evidence because these systems
are "secured". If you cannot agree with me here, I'm afraid we won't be able
to agree on most of the fixes in my patch. I am looking forward to getting
your feedback on this issue.

If you still think this is a good idea, then you're going to need to
show benchmark results and scripts to prove that the extra overhead of
message_level_is_interesting() is low enough and the advantages of
skipping the extra StringInfo code is good enough to warrant doing
this.

Most of the fixes cannot be noticeable in the flamegraphs. If the client uses
only WARNING log level in the production then the usefulness of the patch is
obvious for me. So, I think that at first we should consolidate on the issue
above.

--
Best regards,
Daniil Davydov

On Wed, 1 Apr 2026 at 02:10, Daniil Davydov <3danissimo@gmail.com> wrote:

Most of the fixes cannot be noticeable in the flamegraphs. If the client uses
only WARNING log level in the production then the usefulness of the patch is
obvious for me. So, I think that at first we should consolidate on the issue
above.

Do you mean that the new message_level_is_interesting() call isn't
noticeable? Or that the extra work to build the StringInfo can't be
noticed in an unpatched version? If it's the latter, then what's the
point?

Your opening email seems to indicate that you noticed the issue from
looking at the code. So, it appears that you didn't do this because
you noticed that there was an actual measurable overhead and you saw a
way to fix it. If that's the case then perhaps you've just assumed
this will make a meaningful difference. If I've misunderstood that,
please correct me and show us your test cases and the performance
results.

David

Hi,

On Tue, Mar 31, 2026 at 9:07 PM David Rowley <dgrowleyml@gmail.com> wrote:

Do you mean that the new message_level_is_interesting() call isn't
noticeable? Or that the extra work to build the StringInfo can't be
noticed in an unpatched version?

I think that both message_level_is_interesting call and StringInfo building
are taking negligibly little time compared to the time of the entire request.
Of course I can create some synthetic test : huge loop with (for example)
KnownAssignedXidsDisplay call. This test IIUC will show that my patch makes
things better. But I guess this is not what you expect from me.

If it's the latter, then what's the point?

TBH, I didn't notice that message_level_is_interesting is not considered for
the LOG level.. Anyway, I am still thinking about code consistency and possibly
noticeable changes related to lwlocks (see below).

Your opening email seems to indicate that you noticed the issue from
looking at the code. So, it appears that you didn't do this because
you noticed that there was an actual measurable overhead and you saw a
way to fix it. If that's the case then perhaps you've just assumed
this will make a meaningful difference. If I've misunderstood that,
please correct me and show us your test cases and the performance
results.

You're precisely right. I noticed this issue from looking at the code (while
working on some other feature). So I do not have any benchmarks, which I think
can be created only for the changes in lock.c and proc.c (since there is a
lock acquired there). I will try to create such a benchmark. I hope it won't
be as synthetic as I imagine it now.

Please note, that I don't have any information about the typical
log_lock_failures/log_lock_waits parameters configuration in a production.

--
Best regards,
Daniil Davydov