pgsql: Improve autovacuum logging for aggressive and anti-wraparound ru

On 2018-Sep-13, Michael Paquier wrote:

Improve autovacuum logging for aggressive and anti-wraparound runs

A log message was being generated when log_min_duration is reached for
autovacuum on a given relation to indicate if it was an aggressive run,
and missed the point of mentioning if it is doing an anti-wrapround
run. The log message generated is improved so as one, both or no extra
details are added depending on the option set.

Hmm, can a for-wraparound vacuum really not be aggressive? I think one
of those four cases is really dead code.

--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On Fri, Sep 14, 2018 at 12:35:54PM -0300, Alvaro Herrera wrote:

On 2018-Sep-13, Michael Paquier wrote:

Improve autovacuum logging for aggressive and anti-wraparound runs

A log message was being generated when log_min_duration is reached for
autovacuum on a given relation to indicate if it was an aggressive run,
and missed the point of mentioning if it is doing an anti-wrapround
run. The log message generated is improved so as one, both or no extra
details are added depending on the option set.

Hmm, can a for-wraparound vacuum really not be aggressive? I think one
of those four cases is really dead code.

Sure, at the same time it is a no-brainer to keep the code as is, and
seeing log messages where (!aggressive && wraparound) would be an
indication of surrounding bugs, no? There have been issues in this area
in the past.
--
Michael

On Fri, Sep 14, 2018 at 11:35 AM, Alvaro Herrera
<alvherre@2ndquadrant.com> wrote:

On 2018-Sep-13, Michael Paquier wrote:

Improve autovacuum logging for aggressive and anti-wraparound runs

A log message was being generated when log_min_duration is reached for
autovacuum on a given relation to indicate if it was an aggressive run,
and missed the point of mentioning if it is doing an anti-wrapround
run. The log message generated is improved so as one, both or no extra
details are added depending on the option set.

Hmm, can a for-wraparound vacuum really not be aggressive? I think one
of those four cases is really dead code.

My first question was whether TWO of them were dead code ... isn't an
aggressive vacuum to prevent wraparound, and a vacuum to prevent
wraparound aggressive?

I can't figure out what this is giving us that we didn't have before.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Hello, Robert

My first question was whether TWO of them were dead code ... isn't an
aggressive vacuum to prevent wraparound, and a vacuum to prevent
wraparound aggressive?

Maybe i am wrong, aggressive autovacuum was your commit.
Message split was in b55509332f50f998b6e8b3830a51c5b9d8f666aa
Aggressive autovacuum was in fd31cd265138019dcccc9b5fe53043670898bc9f

If aggressive really is wraparound without difference - i think we need refactor this code, it is difficult have two different flags for same purpose.

But as far i can see it is possible have aggressive non-wraparound vacuum. One important difference - regular and aggressive regular can be canceled by backend,.wraparound autovacuum can not. (by checking PROC_VACUUM_FOR_WRAPAROUND in src/backend/storage/lmgr/proc.c )

regards, Sergei

Hi,

On 2018-09-21 20:38:16 +0300, Sergei Kornilov wrote:

My first question was whether TWO of them were dead code ... isn't an
aggressive vacuum to prevent wraparound, and a vacuum to prevent
wraparound aggressive?

Maybe i am wrong, aggressive autovacuum was your commit.
Message split was in b55509332f50f998b6e8b3830a51c5b9d8f666aa
Aggressive autovacuum was in fd31cd265138019dcccc9b5fe53043670898bc9f

If aggressive really is wraparound without difference - i think we need refactor this code, it is difficult have two different flags for same purpose.

But as far i can see it is possible have aggressive non-wraparound vacuum. One important difference - regular and aggressive regular can be canceled by backend,.wraparound autovacuum can not. (by checking PROC_VACUUM_FOR_WRAPAROUND in src/backend/storage/lmgr/proc.c )

Yes, without checking the code, they should be different. Aggressive is
controlled by vacuum_freeze_table_age whereas anti-wrap is controlled by
autovacuum_freeze_max_age (but also implies aggressive).

Greetings,

Andres Freund

On Sep 21, 2018, at 12:43 PM, Andres Freund <andres@anarazel.de> wrote:

But as far i can see it is possible have aggressive non-wraparound vacuum. One important difference - regular and aggressive regular can be canceled by backend,.wraparound autovacuum can not. (by checking PROC_VACUUM_FOR_WRAPAROUND in src/backend/storage/lmgr/proc.c )

Yes, without checking the code, they should be different. Aggressive is
controlled by vacuum_freeze_table_age whereas anti-wrap is controlled by
autovacuum_freeze_max_age (but also implies aggressive).

Right, except that by the time you get into the vacuum code itself nothing should really care about that difference. AFAICT, the only thing is_wraparound is being used for is to set MyPgXact->vacuumFlags |= PROC_VACUUM_FOR_WRAPAROUND, which prevents the deadlock detector from killing an autovac process that’s trying to prevent a wraparound. I think it’d be clearer to remove is_wraparound and move the check from vacuum_rel() into lazy_vacuum_rel() (which is where the limits for HeapTupleSatisfiesVacuum get determined). Something like the attached.

On 2018-09-24 18:25:46 +0000, Nasby, Jim wrote:

On Sep 21, 2018, at 12:43 PM, Andres Freund <andres@anarazel.de> wrote:

But as far i can see it is possible have aggressive non-wraparound vacuum. One important difference - regular and aggressive regular can be canceled by backend,.wraparound autovacuum can not. (by checking PROC_VACUUM_FOR_WRAPAROUND in src/backend/storage/lmgr/proc.c )

Yes, without checking the code, they should be different. Aggressive is
controlled by vacuum_freeze_table_age whereas anti-wrap is controlled by
autovacuum_freeze_max_age (but also implies aggressive).

Right, except that by the time you get into the vacuum code itself nothing should really care about that difference. AFAICT, the only thing is_wraparound is being used for is to set MyPgXact->vacuumFlags |= PROC_VACUUM_FOR_WRAPAROUND, which prevents the deadlock detector from killing an autovac process that’s trying to prevent a wraparound. I think it’d be clearer to remove is_wraparound and move the check from vacuum_rel() into lazy_vacuum_rel() (which is where the limits for HeapTupleSatisfiesVacuum get determined). Something like the attached.

I'm very doubtful this is an improvement. Especially with the upcoming
pluggable storage work making vacuumlazy.c heap specific, while vacuum.c
stays generic. The concept of something like
PROC_VACUUM_FOR_WRAPAROUND, should imo not be pushed down that much
(even if criteria for it might).

Greetings,

Andres Freund

On Sep 24, 2018, at 1:29 PM, Andres Freund <andres@anarazel.de> wrote:

I'm very doubtful this is an improvement. Especially with the upcoming
pluggable storage work making vacuumlazy.c heap specific, while vacuum.c
stays generic. The concept of something like
PROC_VACUUM_FOR_WRAPAROUND, should imo not be pushed down that much
(even if criteria for it might).

That’s already a problem since vacuum logging is spread all over while autovac logging is not. Perhaps there needs to be some sort of vacuum_log() function that immediately provides output for manual vacuums, but aggregates output for autovac. AFAIK that’s the only real reason for autovac logging being a special case today.

Hi

An autovacuum can't be just aggressive; it's either anti-wraparound or normal.

But autovacuum _can_ be aggressive and not anti-wraparound.
I build current master and can see 3 different line types:
2018-09-24 23:47:31.500 MSK 27939 @ from [vxid:4/272032 txid:0] [] LOG: automatic aggressive vacuum of table "postgres.public.foo": index scans: 0
2018-09-24 23:49:27.892 MSK 28333 @ from [vxid:4/284297 txid:0] [] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.public.foo": index scans: 0
2018-09-24 23:49:29.093 MSK 28337 @ from [vxid:4/284412 txid:0] [] LOG: automatic vacuum of table "postgres.public.foo": index scans: 0

regards, Sergei

On 2018-Sep-24, Sergei Kornilov wrote:

Hi

An autovacuum can't be just aggressive; it's either anti-wraparound or normal.

But autovacuum _can_ be aggressive and not anti-wraparound.
I build current master and can see 3 different line types:
2018-09-24 23:47:31.500 MSK 27939 @ from [vxid:4/272032 txid:0] [] LOG: automatic aggressive vacuum of table "postgres.public.foo": index scans: 0
2018-09-24 23:49:27.892 MSK 28333 @ from [vxid:4/284297 txid:0] [] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.public.foo": index scans: 0
2018-09-24 23:49:29.093 MSK 28337 @ from [vxid:4/284412 txid:0] [] LOG: automatic vacuum of table "postgres.public.foo": index scans: 0

Exactly.

It cannot be anti-wraparound and not aggressive, which is the line type
not shown.

"Aggressive" means it scans all pages; "anti-wraparound" means it does
not let itself be cancelled because of another process waiting for a
lock on the table.

--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On Tue, Sep 25, 2018 at 6:11 AM Alvaro Herrera <alvherre@2ndquadrant.com> wrote:

On 2018-Sep-24, Sergei Kornilov wrote:

Hi

An autovacuum can't be just aggressive; it's either anti-wraparound or normal.

But autovacuum _can_ be aggressive and not anti-wraparound.
I build current master and can see 3 different line types:
2018-09-24 23:47:31.500 MSK 27939 @ from [vxid:4/272032 txid:0] [] LOG: automatic aggressive vacuum of table "postgres.public.foo": index scans: 0
2018-09-24 23:49:27.892 MSK 28333 @ from [vxid:4/284297 txid:0] [] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.public.foo": index scans: 0
2018-09-24 23:49:29.093 MSK 28337 @ from [vxid:4/284412 txid:0] [] LOG: automatic vacuum of table "postgres.public.foo": index scans: 0

Exactly.

It cannot be anti-wraparound and not aggressive, which is the line type
not shown.

"Aggressive" means it scans all pages; "anti-wraparound" means it does
not let itself be cancelled because of another process waiting for a
lock on the table.

I agree. Can we fix this simply by the attached patch?

Regards,

--
Masahiko Sawada
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center

On Fri, Sep 28, 2018 at 01:53:14PM +0900, Masahiko Sawada wrote:

I agree. Can we fix this simply by the attached patch?

Thanks for sending a patch.

+    /* autovacuum cannot be anti-wraparound and not aggressive vacuum */
+    Assert(aggressive);
+    msgfmt = _("automatic aggressive vacuum to prevent wraparound of table \"%s.%s.%s\": index scans: %d\n");

While adding this comment in lazy_vacuum_rel() is adapted, I think that
we ought to make the assertion check more aggressive by not having it
depend on if log_min_duration is set or not. So why not moving that to
a place a bit higher, where aggressive gets defined?
--
Michael

On Tue, Oct 2, 2018 at 9:11 AM Michael Paquier <michael@paquier.xyz> wrote:

On Fri, Sep 28, 2018 at 01:53:14PM +0900, Masahiko Sawada wrote:

I agree. Can we fix this simply by the attached patch?

Thanks for sending a patch.

+    /* autovacuum cannot be anti-wraparound and not aggressive vacuum */
+    Assert(aggressive);
+    msgfmt = _("automatic aggressive vacuum to prevent wraparound of table \"%s.%s.%s\": index scans: %d\n");

While adding this comment in lazy_vacuum_rel() is adapted, I think that
we ought to make the assertion check more aggressive by not having it
depend on if log_min_duration is set or not. So why not moving that to
a place a bit higher, where aggressive gets defined?

Since there is no place where checks params->is_wraparound we will
have to do something like;

if (params->is_wraparound)
Assert(aggressive);

Or you meant the following?

Assert(params->is_wraparound ? aggressive : true);

I'm not sure both styles would be appropriate style in the postgres
code so I would rather add elog(ERROR) instead. Thought?

Regards,

--
Masahiko Sawada
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center

On Tue, Oct 02, 2018 at 01:18:01PM +0900, Masahiko Sawada wrote:

I'm not sure both styles would be appropriate style in the postgres
code so I would rather add elog(ERROR) instead. Thought?

My brain is rather fried for the rest of the day... But we could just
be looking at using USE_ASSERT_CHECKING. Thoughts from other are
welcome.
--
Michael

Michael Paquier <michael@paquier.xyz> writes:

My brain is rather fried for the rest of the day... But we could just
be looking at using USE_ASSERT_CHECKING. Thoughts from other are
welcome.

I'd go with folding the condition into a plain Assert. Then it's
obvious that no code is added in a non-assert build. I can see that
some cases might be so complicated that that isn't nice, but this
case doesn't seem to qualify.

regards, tom lane

On Tue, Oct 2, 2018 at 11:15 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:

Michael Paquier <michael@paquier.xyz> writes:

My brain is rather fried for the rest of the day... But we could just
be looking at using USE_ASSERT_CHECKING. Thoughts from other are
welcome.

I'd go with folding the condition into a plain Assert. Then it's
obvious that no code is added in a non-assert build. I can see that
some cases might be so complicated that that isn't nice, but this
case doesn't seem to qualify.

Thank you for the comment. Attached the updated patch.

Regards,

--
Masahiko Sawada
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center

On Wed, Oct 03, 2018 at 04:37:29PM +0900, Masahiko Sawada wrote:

Thank you for the comment. Attached the updated patch.

Thanks for the patch. This looks clean to me at quick glance, not
tested though..
--
Michael

On Wed, Oct 03, 2018 at 04:37:29PM +0900, Masahiko Sawada wrote:

Thank you for the comment. Attached the updated patch.

So, I have come back to this stuff, and finished with the attached
instead, so as the assertion is in a single place. I find that
clearer. The comments have also been improved. Thoughts?
--
Michael

On Fri, Oct 5, 2018 at 12:16 PM Michael Paquier <michael@paquier.xyz> wrote:

On Wed, Oct 03, 2018 at 04:37:29PM +0900, Masahiko Sawada wrote:

Thank you for the comment. Attached the updated patch.

So, I have come back to this stuff, and finished with the attached
instead, so as the assertion is in a single place. I find that
clearer. The comments have also been improved. Thoughts?

Thank you! The patch looks good to me.

Regards,

--
Masahiko Sawada
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center