Обсуждение: Skip vacuum log report code in lazy_scan_heap() if possible

Hi,

When recently debugging a vacuum-related issue, I noticed that there
is some log-report processing/formatting code at the end of
lazy_scan_heap() that, unless the vacuum VERBOSE option is specified,
typically results in no log output (as the log-level is then DEBUG2).
I think it is worth skipping this code if ultimately nothing is going
to be logged (and I found that even for a tiny database, a VACUUM may
execute this code hundreds of times).
I have attached a simple patch for this.

Regards,
Greg Nancarrow
Fujitsu Australia

On 10/29/21, 3:54 AM, "Greg Nancarrow" <gregn4422@gmail.com> wrote:
> When recently debugging a vacuum-related issue, I noticed that there
> is some log-report processing/formatting code at the end of
> lazy_scan_heap() that, unless the vacuum VERBOSE option is specified,
> typically results in no log output (as the log-level is then DEBUG2).
> I think it is worth skipping this code if ultimately nothing is going
> to be logged (and I found that even for a tiny database, a VACUUM may
> execute this code hundreds of times).
> I have attached a simple patch for this.

I think this logging only happens once per table, so I'm not sure it's
really worth it to short-circuit here.  If it was per-page, IMO there
would be a much stronger case for it.  That being said, I don't think
the proposed patch would hurt anything.

Nathan

On 10/29/21, 10:49 AM, "Bossart, Nathan" <bossartn@amazon.com> wrote:
> On 10/29/21, 3:54 AM, "Greg Nancarrow" <gregn4422@gmail.com> wrote:
>> When recently debugging a vacuum-related issue, I noticed that there
>> is some log-report processing/formatting code at the end of
>> lazy_scan_heap() that, unless the vacuum VERBOSE option is specified,
>> typically results in no log output (as the log-level is then DEBUG2).
>> I think it is worth skipping this code if ultimately nothing is going
>> to be logged (and I found that even for a tiny database, a VACUUM may
>> execute this code hundreds of times).
>> I have attached a simple patch for this.
>
> I think this logging only happens once per table, so I'm not sure it's
> really worth it to short-circuit here.  If it was per-page, IMO there
> would be a much stronger case for it.  That being said, I don't think
> the proposed patch would hurt anything.

Since I have no further comments, I went ahead and marked this once as
ready-for-committer.

Nathan

On Thu, Dec 02, 2021 at 10:22:25PM +0000, Bossart, Nathan wrote:
> Since I have no further comments, I went ahead and marked this once as
> ready-for-committer.

Well, as you say, lazy_scan_heap() is only run once per relation, so
that's not a hot code path.  Looking at the callers of
message_level_is_interesting(), we apply that also in areas where a
lot of unnecessary work would be involved, like the drop of object
dependencies or ProcSleep() (I recall that there were profiles where
standby replies in walsender.c could show up).  And based on the
amount of unnecessary work done at the end of lazy_scan_heap(), I'd
say that this is worth skipping, so let's do it.

There is always the argument that one may blindly add some logic at
the end of lazy_scan_heap(), causing it to be skipped depending on the
configuration, but that's unlikely going to happen after the activity
is logged, so I am fine to apply what you have here.  Let's wait a bit
to see if others have any objections, first.
--
Michael

Hi,

On 2021-12-03 09:53:22 +0900, Michael Paquier wrote:
> On Thu, Dec 02, 2021 at 10:22:25PM +0000, Bossart, Nathan wrote:
> > Since I have no further comments, I went ahead and marked this once as
> > ready-for-committer.
>
> Well, as you say, lazy_scan_heap() is only run once per relation, so
> that's not a hot code path.

Yea, it seems like a premature optimization.


> Looking at the callers of
> message_level_is_interesting(), we apply that also in areas where a
> lot of unnecessary work would be involved, like the drop of object
> dependencies or ProcSleep() (I recall that there were profiles where
> standby replies in walsender.c could show up).  And based on the
> amount of unnecessary work done at the end of lazy_scan_heap(), I'd
> say that this is worth skipping, so let's do it.

I think this mostly reduces the coverage of the relevant code without any
measurable speed gain. -0.5 from here.

Greetings,

Andres Freund

On Fri, Dec 03, 2021 at 05:46:51PM +0000, Bossart, Nathan wrote:
> Perhaps this patch should be marked Rejected in favor of that one,
> then.

Let's do so, then.  I can also get behind the coverage argument for
this code path.
--
Michael