Logging idle checkpoints

Started by Vik Fearingover 8 years ago53 messageshackers
Jump to latest
#1Vik Fearing
vik@postgresfriends.org

I recently had a sad because I noticed that checkpoint counts were
increasing in pg_stat_bgwriter, but weren't accounted for in my logs
with log_checkpoints enabled.

After some searching, I found that it was the idle checkpoints that
weren't being logged. I think this is a missed trick in 6ef2eba3f57.

Attached is a one-liner fix. I realize how imminent we are from
releasing v10 but I hope there is still time for such a minor issue as this.
--
Vik Fearing +33 6 46 75 15 36
http://2ndQuadrant.fr PostgreSQL : Expertise, Formation et Support

Attachments:

log-idle-checkpoints.patchtext/x-patch; name=log-idle-checkpoints.patchDownload+1-1
#2Andres Freund
andres@anarazel.de
In reply to: Vik Fearing (#1)
Re: Logging idle checkpoints

Hi,

On 2017-10-02 00:19:33 +0200, Vik Fearing wrote:

I recently had a sad because I noticed that checkpoint counts were
increasing in pg_stat_bgwriter, but weren't accounted for in my logs
with log_checkpoints enabled.

After some searching, I found that it was the idle checkpoints that
weren't being logged. I think this is a missed trick in 6ef2eba3f57.

Attached is a one-liner fix. I realize how imminent we are from
releasing v10 but I hope there is still time for such a minor issue as this.

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index dd028a12a4..75f6bd4cc1 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -8724,7 +8724,7 @@ CreateCheckPoint(int flags)
WALInsertLockRelease();
LWLockRelease(CheckpointLock);
END_CRIT_SECTION();
-			ereport(DEBUG1,
+			ereport(log_checkpoints ? LOG : DEBUG1,
(errmsg("checkpoint skipped because system is idle")));
return;
}

I'd be ok with applying this now, or in 10.1 - but I do think we should
fix this before 11. If nobody protests I'll push later today, so we can
get some bf cycles for the very remote case that this causes problems.

Greetings,

Andres Freund

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#3Michael Paquier
michael@paquier.xyz
In reply to: Andres Freund (#2)
Re: Logging idle checkpoints

On Mon, Oct 2, 2017 at 7:27 AM, Andres Freund <andres@anarazel.de> wrote:

On 2017-10-02 00:19:33 +0200, Vik Fearing wrote:
I'd be ok with applying this now, or in 10.1 - but I do think we should
fix this before 11. If nobody protests I'll push later today, so we can
get some bf cycles for the very remote case that this causes problems.

This point has been discussed during review and removed from the patch
(adding Stephen in the loop here):
/messages/by-id/CAOuzzgq8pHneMHy6JiNiG6Xm5V=cm+K2wCd2W-SCtpJDg7Xn3g@mail.gmail.com
Actually, shouldn't we make BgWriterStats a bit smarter? We could add
a counter for skipped checkpoints in v11 (too late for v10).
--
Michael

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#4Andres Freund
andres@anarazel.de
In reply to: Michael Paquier (#3)
Re: Logging idle checkpoints

On 2017-10-02 07:39:18 +0900, Michael Paquier wrote:

On Mon, Oct 2, 2017 at 7:27 AM, Andres Freund <andres@anarazel.de> wrote:

On 2017-10-02 00:19:33 +0200, Vik Fearing wrote:
I'd be ok with applying this now, or in 10.1 - but I do think we should
fix this before 11. If nobody protests I'll push later today, so we can
get some bf cycles for the very remote case that this causes problems.

This point has been discussed during review and removed from the patch
(adding Stephen in the loop here):
/messages/by-id/CAOuzzgq8pHneMHy6JiNiG6Xm5V=cm+K2wCd2W-SCtpJDg7Xn3g@mail.gmail.com

I find that reasoning unconvincing. log_checkpoints is enabled after
all. And we're not talking about 10 log messages a second. There's
plenty systems that analyze the logs that'd possibly be affected by
this.

Actually, shouldn't we make BgWriterStats a bit smarter? We could add
a counter for skipped checkpoints in v11 (too late for v10).

Wouldn't hurt, but seems orthogonal.

Greetings,

Andres Freund

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#5Michael Paquier
michael@paquier.xyz
In reply to: Andres Freund (#4)
Re: Logging idle checkpoints

On Mon, Oct 2, 2017 at 7:41 AM, Andres Freund <andres@anarazel.de> wrote:

On 2017-10-02 07:39:18 +0900, Michael Paquier wrote:

On Mon, Oct 2, 2017 at 7:27 AM, Andres Freund <andres@anarazel.de> wrote:

On 2017-10-02 00:19:33 +0200, Vik Fearing wrote:
I'd be ok with applying this now, or in 10.1 - but I do think we should
fix this before 11. If nobody protests I'll push later today, so we can
get some bf cycles for the very remote case that this causes problems.

This point has been discussed during review and removed from the patch
(adding Stephen in the loop here):
/messages/by-id/CAOuzzgq8pHneMHy6JiNiG6Xm5V=cm+K2wCd2W-SCtpJDg7Xn3g@mail.gmail.com

I find that reasoning unconvincing. log_checkpoints is enabled after
all. And we're not talking about 10 log messages a second. There's
plenty systems that analyze the logs that'd possibly be affected by
this.

No real objections from here, actually.

Actually, shouldn't we make BgWriterStats a bit smarter? We could add
a counter for skipped checkpoints in v11 (too late for v10).

Wouldn't hurt, but seems orthogonal.

Sure.
--
Michael

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#6Andres Freund
andres@anarazel.de
In reply to: Michael Paquier (#5)
Re: Logging idle checkpoints

On 2017-10-02 07:43:31 +0900, Michael Paquier wrote:

On Mon, Oct 2, 2017 at 7:41 AM, Andres Freund <andres@anarazel.de> wrote:

On 2017-10-02 07:39:18 +0900, Michael Paquier wrote:

On Mon, Oct 2, 2017 at 7:27 AM, Andres Freund <andres@anarazel.de> wrote:

On 2017-10-02 00:19:33 +0200, Vik Fearing wrote:
I'd be ok with applying this now, or in 10.1 - but I do think we should
fix this before 11. If nobody protests I'll push later today, so we can
get some bf cycles for the very remote case that this causes problems.

This point has been discussed during review and removed from the patch
(adding Stephen in the loop here):
/messages/by-id/CAOuzzgq8pHneMHy6JiNiG6Xm5V=cm+K2wCd2W-SCtpJDg7Xn3g@mail.gmail.com

I find that reasoning unconvincing. log_checkpoints is enabled after
all. And we're not talking about 10 log messages a second. There's
plenty systems that analyze the logs that'd possibly be affected by
this.

No real objections from here, actually.

Vik, because there was some, even though mild, objections, I'd rather
not push this right now. Stephen deserves a chance to reply. So this'll
have to wait for 10.1, sorry :(

- Andres

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#7Stephen Frost
sfrost@snowman.net
In reply to: Vik Fearing (#1)
Re: Logging idle checkpoints

Vik, all,

* Vik Fearing (vik.fearing@2ndquadrant.com) wrote:

I recently had a sad because I noticed that checkpoint counts were
increasing in pg_stat_bgwriter, but weren't accounted for in my logs
with log_checkpoints enabled.

After some searching, I found that it was the idle checkpoints that
weren't being logged. I think this is a missed trick in 6ef2eba3f57.

Attached is a one-liner fix. I realize how imminent we are from
releasing v10 but I hope there is still time for such a minor issue as this.

Idle checkpoints aren't, well, really checkpoints though. If anything,
seems like we shouldn't be including skipped checkpoints in the
pg_stat_bgwriter count because we aren't actually doing a checkpoint.

I certainly don't care for the idea of adding log messages saying we
aren't doing anything just to match a count that's incorrectly claiming
that checkpoints are happening when they aren't.

The down-thread suggestion of keeping track of skipped checkpoints might
be interesting, but I'm not entirely convinced it really is. We have
time to debate that, of course, but I don't really see how that's
helpful. At the moment, it seems like the suggestion to add that column
is based on the assumption that we're going to start logging skipped
checkpoints and having that column would allow us to match up the count
between the new column and the "skipped checkpoint" messages in the logs
and I can not help but feel that this is a ridiculous amount of effort
being put into the analysis of something that *didn't* happen.

Thanks!

Stephen

#8Michael Paquier
michael@paquier.xyz
In reply to: Stephen Frost (#7)
Re: Logging idle checkpoints

On Tue, Oct 3, 2017 at 12:01 AM, Stephen Frost <sfrost@snowman.net> wrote:

I certainly don't care for the idea of adding log messages saying we
aren't doing anything just to match a count that's incorrectly claiming
that checkpoints are happening when they aren't.

The down-thread suggestion of keeping track of skipped checkpoints might
be interesting, but I'm not entirely convinced it really is. We have
time to debate that, of course, but I don't really see how that's
helpful. At the moment, it seems like the suggestion to add that column
is based on the assumption that we're going to start logging skipped
checkpoints and having that column would allow us to match up the count
between the new column and the "skipped checkpoint" messages in the logs
and I can not help but feel that this is a ridiculous amount of effort
being put into the analysis of something that *didn't* happen.

Being able to look at how many checkpoints are skipped can be used as
a tuning indicator of max_wal_size and checkpoint_timeout, or in short
increase them if those remain idle. Since their introduction in
335feca4, m_timed_checkpoints and m_requested_checkpoints track the
number of checkpoint requests, not if a checkpoint has been actually
executed or not, I am not sure that this should be changed after 10
years. So, to put it in other words, wouldn't we want a way to track
checkpoints that are *executed*, meaning that we could increment a
counter after doing the skip checks in CreateRestartPoint() and
CreateCheckPoint()?
--
Michael

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#9Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Michael Paquier (#8)
Re: Logging idle checkpoints

At Tue, 3 Oct 2017 10:23:08 +0900, Michael Paquier <michael.paquier@gmail.com> wrote in <CAB7nPqQ3Q1J_wBC7yPXk39dO0RGvbM4-nYp2gMrCJ7pfPJXcYw@mail.gmail.com>

On Tue, Oct 3, 2017 at 12:01 AM, Stephen Frost <sfrost@snowman.net> wrote:

I certainly don't care for the idea of adding log messages saying we
aren't doing anything just to match a count that's incorrectly claiming
that checkpoints are happening when they aren't.

The down-thread suggestion of keeping track of skipped checkpoints might
be interesting, but I'm not entirely convinced it really is. We have
time to debate that, of course, but I don't really see how that's
helpful. At the moment, it seems like the suggestion to add that column
is based on the assumption that we're going to start logging skipped
checkpoints and having that column would allow us to match up the count
between the new column and the "skipped checkpoint" messages in the logs
and I can not help but feel that this is a ridiculous amount of effort
being put into the analysis of something that *didn't* happen.

Being able to look at how many checkpoints are skipped can be used as
a tuning indicator of max_wal_size and checkpoint_timeout, or in short
increase them if those remain idle.

We ususally adjust the GUCs based on how often checkpoint is
*executed* and how many of the executed checkpoints have been
triggered by xlog progress (or with shorter interval than
timeout). It seems enough. Counting skipped checkpoints gives
just a rough estimate of how long the system was getting no
substantial updates. I doubt that users get something valuable by
counting skipped checkpoints.

Since their introduction in
335feca4, m_timed_checkpoints and m_requested_checkpoints track the
number of checkpoint requests, not if a checkpoint has been actually
executed or not, I am not sure that this should be changed after 10
years. So, to put it in other words, wouldn't we want a way to track
checkpoints that are *executed*, meaning that we could increment a
counter after doing the skip checks in CreateRestartPoint() and
CreateCheckPoint()?

This sounds reasonable to me.

CreateRestartPoint() is already returning ckpt_performed, it is
used to let checkpointer retry in 15 seconds rather than waiting
the next checkpoint_timeout. Checkpoint might deserve the same
treatment on skipping.

By the way RestartCheckPoint emits DEBUG2 messages on skipping.
Although restartpoint has different characteristics from
checkpoint, if we change the message level for CreateCheckPoint
(currently DEBUG1), CreateRestartPoint might should get the same
change. (Elsewise at least they ought to have the same message
level?)

regards,

--
Kyotaro Horiguchi
NTT Open Source Software Center

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#10Stephen Frost
sfrost@snowman.net
In reply to: Kyotaro Horiguchi (#9)
Re: Logging idle checkpoints

Greetings,

* Kyotaro HORIGUCHI (horiguchi.kyotaro@lab.ntt.co.jp) wrote:

At Tue, 3 Oct 2017 10:23:08 +0900, Michael Paquier <michael.paquier@gmail.com> wrote in <CAB7nPqQ3Q1J_wBC7yPXk39dO0RGvbM4-nYp2gMrCJ7pfPJXcYw@mail.gmail.com>

On Tue, Oct 3, 2017 at 12:01 AM, Stephen Frost <sfrost@snowman.net> wrote:

I certainly don't care for the idea of adding log messages saying we
aren't doing anything just to match a count that's incorrectly claiming
that checkpoints are happening when they aren't.

The down-thread suggestion of keeping track of skipped checkpoints might
be interesting, but I'm not entirely convinced it really is. We have
time to debate that, of course, but I don't really see how that's
helpful. At the moment, it seems like the suggestion to add that column
is based on the assumption that we're going to start logging skipped
checkpoints and having that column would allow us to match up the count
between the new column and the "skipped checkpoint" messages in the logs
and I can not help but feel that this is a ridiculous amount of effort
being put into the analysis of something that *didn't* happen.

Being able to look at how many checkpoints are skipped can be used as
a tuning indicator of max_wal_size and checkpoint_timeout, or in short
increase them if those remain idle.

We ususally adjust the GUCs based on how often checkpoint is
*executed* and how many of the executed checkpoints have been
triggered by xlog progress (or with shorter interval than
timeout). It seems enough. Counting skipped checkpoints gives
just a rough estimate of how long the system was getting no
substantial updates. I doubt that users get something valuable by
counting skipped checkpoints.

Yeah, I tend to agree. I don't really see how counting skipped
checkpoints helps to size max_wal_size or even checkpoint_timeout. The
whole point here is that nothing is happening and if nothing is
happening then there's no real need to adjust max_wal_size or
checkpoint_timeout or, well, much of anything really..

Since their introduction in
335feca4, m_timed_checkpoints and m_requested_checkpoints track the
number of checkpoint requests, not if a checkpoint has been actually
executed or not, I am not sure that this should be changed after 10
years. So, to put it in other words, wouldn't we want a way to track
checkpoints that are *executed*, meaning that we could increment a
counter after doing the skip checks in CreateRestartPoint() and
CreateCheckPoint()?

This sounds reasonable to me.

I agree that tracking executed checkpoints is valuable, but, and perhaps
I'm missing something, isn't that the same as tracking non-skipped
checkpoints? I suppose we could have both, if we really feel the need,
provided that doesn't result in more work or effort being done than
simply keeping the count. I'd hate to end up in a situation where we're
writing things out unnecessairly just to keep track of checkpoints that
were requested but ultimately skipped because there wasn't anything to
do.

Thanks!

Stephen

#11Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Stephen Frost (#10)
Re: Logging idle checkpoints

At Tue, 3 Oct 2017 08:22:27 -0400, Stephen Frost <sfrost@snowman.net> wrote in <20171003122227.GJ4628@tamriel.snowman.net>

Greetings,

* Kyotaro HORIGUCHI (horiguchi.kyotaro@lab.ntt.co.jp) wrote:

At Tue, 3 Oct 2017 10:23:08 +0900, Michael Paquier <michael.paquier@gmail.com> wrote in <CAB7nPqQ3Q1J_wBC7yPXk39dO0RGvbM4-nYp2gMrCJ7pfPJXcYw@mail.gmail.com>

On Tue, Oct 3, 2017 at 12:01 AM, Stephen Frost <sfrost@snowman.net> wrote:
Since their introduction in
335feca4, m_timed_checkpoints and m_requested_checkpoints track the
number of checkpoint requests, not if a checkpoint has been actually
executed or not, I am not sure that this should be changed after 10
years. So, to put it in other words, wouldn't we want a way to track
checkpoints that are *executed*, meaning that we could increment a
counter after doing the skip checks in CreateRestartPoint() and
CreateCheckPoint()?

This sounds reasonable to me.

I agree that tracking executed checkpoints is valuable, but, and perhaps
I'm missing something, isn't that the same as tracking non-skipped
checkpoints? I suppose we could have both, if we really feel the need,
provided that doesn't result in more work or effort being done than
simply keeping the count. I'd hate to end up in a situation where we're
writing things out unnecessairly just to keep track of checkpoints that
were requested but ultimately skipped because there wasn't anything to
do.

I'm fine with counting both executed and skipped. But perhaps the
time of lastest checkpoint fits the concern better, like
vacuum. It is seen in control file but not in system views. If we
have count skipped checkpoints, I'd like to see the time (or LSN)
of last checkpoint in system views.

  checkpoints_timed     | bigint                   |           |          | 
  checkpoints_req       | bigint                   |           |          | 
+ checkpoints_skipped   | bigint
+ last_checkpint        | timestamp with time zone or LSN?

# This reminded me of a concern. I'd like to count vacuums that
# are required but skipped by lock-failure, or killed by other
# backend.

regards,

--
Kyotaro Horiguchi
NTT Open Source Software Center

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#12Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Kyotaro Horiguchi (#11)
Re: Logging idle checkpoints

Kyotaro HORIGUCHI wrote:

# This reminded me of a concern. I'd like to count vacuums that
# are required but skipped by lock-failure, or killed by other
# backend.

We clearly need to improve the stats and logs related to vacuuming work
executed, both by autovacuum and manually invoked. One other item I
have in my head is to report numbers related to the truncation phase of
a vacuum run, since in some cases it causes horrible and hard to
diagnose problems. (Also, add an reloption to stop vacuum from doing
the truncation phase at all -- for some usage patterns that is a serious
problem.)

However, please do open a new thread about it.

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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#13Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Alvaro Herrera (#12)
Re: Logging idle checkpoints

At Thu, 5 Oct 2017 13:41:42 +0200, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote in <20171005114142.dupjeqe2cnplhgkx@alvherre.pgsql>

Kyotaro HORIGUCHI wrote:

# This reminded me of a concern. I'd like to count vacuums that
# are required but skipped by lock-failure, or killed by other
# backend.

We clearly need to improve the stats and logs related to vacuuming work
executed, both by autovacuum and manually invoked. One other item I
have in my head is to report numbers related to the truncation phase of
a vacuum run, since in some cases it causes horrible and hard to
diagnose problems. (Also, add an reloption to stop vacuum from doing
the truncation phase at all -- for some usage patterns that is a serious
problem.)

However, please do open a new thread about it.

Thanks! Will do after a bit time of organization of the thougts.

reagareds,

--
Kyotaro Horiguchi
NTT Open Source Software Center

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#14Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Alvaro Herrera (#12)
More stats about skipped vacuums

Hello.
Once in a while I am asked about table bloat. In most cases the
cause is long lasting transactions and vacuum canceling in some
cases. Whatever the case users don't have enough clues to why
they have bloated tables.

At the top of the annoyances list for users would be that they
cannot know whether autovacuum decided that a table needs vacuum
or not. I suppose that it could be shown in pg_stat_*_tables.

n_mod_since_analyze | 20000
+ vacuum_requred | true
last_vacuum | 2017-10-10 17:21:54.380805+09

If vacuum_required remains true for a certain time, it means that
vacuuming stopped halfway or someone is killing it repeatedly.
That status could be shown in the same view.

  n_mod_since_analyze         | 20000
+ vacuum_requred              | true
  last_vacuum                 | 2017-10-10 17:21:54.380805+09
  last_autovacuum             | 2017-10-10 17:21:54.380805+09
+ last_autovacuum_status      | Killed by lock conflict

Where the "Killed by lock conflict" would be one of the followings.

- Completed (oldest xmin = 8023)
- May not be fully truncated (yielded at 1324 of 6447 expected)
- Truncation skipped
- Skipped by lock failure
- Killed by lock conflict

If we want more formal expression, we can show the values in the
following shape. And adding some more values could be useful.

  n_mod_since_analyze          | 20000
+ vacuum_requred               | true
+ last_vacuum_oldest_xid       | 8023
+ last_vacuum_left_to_truncate | 5123
+ last_vacuum_truncated        | 387
  last_vacuum                  | 2017-10-10 17:21:54.380805+09
  last_autovacuum              | 2017-10-10 17:21:54.380805+09
+ last_autovacuum_status       | Killed by lock conflict
...
  autovacuum_count             | 128
+ incomplete_autovacuum_count  | 53

# The last one might be needless..

Where the "Killed by lock conflict" is one of the followings.

- Completed
- Truncation skipped
- Partially truncated
- Skipped
- Killed by lock conflict

This seems enough to find the cause of a table bloat. The same
discussion could be applied to analyze but it might be the
another issue.

There may be a better way to indicate the vacuum soundness. Any
opinions and suggestions are welcome.

I'm going to make a patch to do the 'formal' one for the time
being.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#15Masahiko Sawada
sawada.mshk@gmail.com
In reply to: Kyotaro Horiguchi (#14)
Re: More stats about skipped vacuums

On Tue, Oct 10, 2017 at 7:26 PM, Kyotaro HORIGUCHI
<horiguchi.kyotaro@lab.ntt.co.jp> wrote:

Hello.
Once in a while I am asked about table bloat. In most cases the
cause is long lasting transactions and vacuum canceling in some
cases. Whatever the case users don't have enough clues to why
they have bloated tables.

At the top of the annoyances list for users would be that they
cannot know whether autovacuum decided that a table needs vacuum
or not. I suppose that it could be shown in pg_stat_*_tables.

n_mod_since_analyze | 20000
+ vacuum_requred | true
last_vacuum | 2017-10-10 17:21:54.380805+09

If vacuum_required remains true for a certain time, it means that
vacuuming stopped halfway or someone is killing it repeatedly.
That status could be shown in the same view.

Because the table statistics is updated at end of the vacuum I think
that the autovacuum will process the table at the next cycle if it has
stopped halfway or has killed. So you mean that vacuum_required is for
uses who want to reclaim garbage without wait for autovacuum retry?

n_mod_since_analyze         | 20000
+ vacuum_requred              | true
last_vacuum                 | 2017-10-10 17:21:54.380805+09
last_autovacuum             | 2017-10-10 17:21:54.380805+09
+ last_autovacuum_status      | Killed by lock conflict

Where the "Killed by lock conflict" would be one of the followings.

- Completed (oldest xmin = 8023)
- May not be fully truncated (yielded at 1324 of 6447 expected)
- Truncation skipped
- Skipped by lock failure
- Killed by lock conflict

If we want more formal expression, we can show the values in the
following shape. And adding some more values could be useful.

n_mod_since_analyze          | 20000
+ vacuum_requred               | true
+ last_vacuum_oldest_xid       | 8023
+ last_vacuum_left_to_truncate | 5123
+ last_vacuum_truncated        | 387
last_vacuum                  | 2017-10-10 17:21:54.380805+09
last_autovacuum              | 2017-10-10 17:21:54.380805+09
+ last_autovacuum_status       | Killed by lock conflict
...
autovacuum_count             | 128
+ incomplete_autovacuum_count  | 53

# The last one might be needless..

I'm not sure that the above informations will help for users or DBA
but personally I sometimes want to have the number of index scans of
the last autovacuum in the pg_stat_user_tables view. That value
indicates how efficiently vacuums performed and would be a signal to
increase the setting of autovacuum_work_mem for user.

Where the "Killed by lock conflict" is one of the followings.

- Completed
- Truncation skipped
- Partially truncated
- Skipped
- Killed by lock conflict

This seems enough to find the cause of a table bloat. The same
discussion could be applied to analyze but it might be the
another issue.

There may be a better way to indicate the vacuum soundness. Any
opinions and suggestions are welcome.

I'm going to make a patch to do the 'formal' one for the time
being.

Regards,

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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#16Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Masahiko Sawada (#15)
Re: More stats about skipped vacuums

Mmm. I've failed to create a brand-new thread..

Thank you for the comment.

At Fri, 20 Oct 2017 19:15:16 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in <CAD21AoAkaw-u0feAVN_VrKZA5tvzp7jT=mQCQP-SvMegKXHHaw@mail.gmail.com>

On Tue, Oct 10, 2017 at 7:26 PM, Kyotaro HORIGUCHI
<horiguchi.kyotaro@lab.ntt.co.jp> wrote:

Hello.
Once in a while I am asked about table bloat. In most cases the
cause is long lasting transactions and vacuum canceling in some
cases. Whatever the case users don't have enough clues to why
they have bloated tables.

At the top of the annoyances list for users would be that they
cannot know whether autovacuum decided that a table needs vacuum
or not. I suppose that it could be shown in pg_stat_*_tables.

n_mod_since_analyze | 20000
+ vacuum_requred | true
last_vacuum | 2017-10-10 17:21:54.380805+09

If vacuum_required remains true for a certain time, it means that
vacuuming stopped halfway or someone is killing it repeatedly.
That status could be shown in the same view.

Because the table statistics is updated at end of the vacuum I think
that the autovacuum will process the table at the next cycle if it has
stopped halfway or has killed. So you mean that vacuum_required is for
uses who want to reclaim garbage without wait for autovacuum retry?

It could be used for the purpose and for just knowing that a
table is left for a long time needing a vacuum and it would be a
trigger for users to take measures to deal with the situation.

n_mod_since_analyze         | 20000
+ vacuum_requred              | true
last_vacuum                 | 2017-10-10 17:21:54.380805+09
last_autovacuum             | 2017-10-10 17:21:54.380805+09
+ last_autovacuum_status      | Killed by lock conflict

Where the "Killed by lock conflict" would be one of the followings.

- Completed (oldest xmin = 8023)
- May not be fully truncated (yielded at 1324 of 6447 expected)
- Truncation skipped
- Skipped by lock failure
- Killed by lock conflict

If we want more formal expression, we can show the values in the
following shape. And adding some more values could be useful.

n_mod_since_analyze          | 20000
+ vacuum_requred               | true
+ last_vacuum_oldest_xid       | 8023
+ last_vacuum_left_to_truncate | 5123
+ last_vacuum_truncated        | 387
last_vacuum                  | 2017-10-10 17:21:54.380805+09
last_autovacuum              | 2017-10-10 17:21:54.380805+09
+ last_autovacuum_status       | Killed by lock conflict
...
autovacuum_count             | 128
+ incomplete_autovacuum_count  | 53

# The last one might be needless..

I'm not sure that the above informations will help for users or DBA
but personally I sometimes want to have the number of index scans of
the last autovacuum in the pg_stat_user_tables view. That value
indicates how efficiently vacuums performed and would be a signal to
increase the setting of autovacuum_work_mem for user.

Btree and all existing index AMs (except brin) seem to visit the
all pages in every index scan so it would be valuable. Instead
the number of visited index pages during a table scan might be
usable. It is more relevant to performance than the number of
scans, on the other hand it is a bit difficult to get something
worth from the number in a moment. I'll show the number of scans
in the first cut.

Where the "Killed by lock conflict" is one of the followings.

- Completed
- Truncation skipped
- Partially truncated
- Skipped
- Killed by lock conflict

This seems enough to find the cause of a table bloat. The same
discussion could be applied to analyze but it might be the
another issue.

There may be a better way to indicate the vacuum soundness. Any
opinions and suggestions are welcome.

I'm going to make a patch to do the 'formal' one for the time
being.

regards,

--
Kyotaro Horiguchi
NTT Open Source Software Center

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#17Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Kyotaro Horiguchi (#16)
Re: More stats about skipped vacuums

At Thu, 26 Oct 2017 15:06:30 +0900 (Tokyo Standard Time), Kyotaro HORIGUCHI <horiguchi.kyotaro@lab.ntt.co.jp> wrote in <20171026.150630.115694437.horiguchi.kyotaro@lab.ntt.co.jp>

At Fri, 20 Oct 2017 19:15:16 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in <CAD21AoAkaw-u0feAVN_VrKZA5tvzp7jT=mQCQP-SvMegKXHHaw@mail.gmail.com>

n_mod_since_analyze          | 20000
+ vacuum_requred               | true
+ last_vacuum_oldest_xid       | 8023
+ last_vacuum_left_to_truncate | 5123
+ last_vacuum_truncated        | 387
last_vacuum                  | 2017-10-10 17:21:54.380805+09
last_autovacuum              | 2017-10-10 17:21:54.380805+09
+ last_autovacuum_status       | Killed by lock conflict
...
autovacuum_count             | 128
+ incomplete_autovacuum_count  | 53

# The last one might be needless..

I'm not sure that the above informations will help for users or DBA
but personally I sometimes want to have the number of index scans of
the last autovacuum in the pg_stat_user_tables view. That value
indicates how efficiently vacuums performed and would be a signal to
increase the setting of autovacuum_work_mem for user.

Btree and all existing index AMs (except brin) seem to visit the
all pages in every index scan so it would be valuable. Instead
the number of visited index pages during a table scan might be
usable. It is more relevant to performance than the number of
scans, on the other hand it is a bit difficult to get something
worth from the number in a moment. I'll show the number of scans
in the first cut.

Where the "Killed by lock conflict" is one of the followings.

- Completed
- Truncation skipped
- Partially truncated
- Skipped
- Killed by lock conflict

This seems enough to find the cause of a table bloat. The same
discussion could be applied to analyze but it might be the
another issue.

There may be a better way to indicate the vacuum soundness. Any
opinions and suggestions are welcome.

I'm going to make a patch to do the 'formal' one for the time
being.

Done with small modifications. In the attached patch
pg_stat_all_tables has the following new columns. Documentations
is not provided at this stage.

-----
  n_mod_since_analyze     | 0
+ vacuum_required         | not requried
  last_vacuum             | 
  last_autovacuum         | 2017-10-30 18:51:32.060551+09
  last_analyze            | 
  last_autoanalyze        | 2017-10-30 18:48:33.414711+09
  vacuum_count            | 0
+ last_vacuum_truncated   | 0
+ last_vacuum_untruncated | 0
+ last_vacuum_index_scans | 0
+ last_vacuum_oldest_xmin | 2134
+ last_vacuum_status      | agressive vacuum completed
+ autovacuum_fail_count   | 0
  autovacuum_count        | 5
  analyze_count           | 0
  autoanalyze_count       | 1
-----
Where each column shows the following infomation.

+ vacuum_required | not requried

VACUUM requirement status. Takes the following values.

- partial
Partial (or normal) will be performed by the next autovacuum.
The word "partial" is taken from the comment for
vacuum_set_xid_limits.

- aggressive
Aggressive scan will be performed by the next autovacuum.

- required
Any type of autovacuum will be performed. The type of scan is
unknown because the view failed to take the required lock on
the table. (AutoVacuumrequirement())

- not required
Next autovacuum won't perform scan on this relation.

- not required (lock not acquired)

Autovacuum should be disabled and the distance to
freeze-limit is not known because required lock is not
available.

- close to freeze-limit xid
Shown while autovacuum is disabled. The table is in the
manual vacuum window to avoid anti-wraparound autovacuum.

+ last_vacuum_truncated | 0

The number of truncated pages in the last completed
(auto)vacuum.

+ last_vacuum_untruncated | 0
The number of pages the last completed (auto)vacuum tried to
truncate but could not for some reason.

+ last_vacuum_index_scans | 0
The number of index scans performed in the last completed
(auto)vacuum.

+ last_vacuum_oldest_xmin | 2134
The oldest xmin used in the last completed (auto)vacuum.

+ last_vacuum_status | agressive vacuum completed

The finish status of the last vacuum. Takes the following
values. (pg_stat_get_last_vacuum_status())

- completed
The last partial (auto)vacuum is completed.

- vacuum full completed
The last VACUUM FULL is completed.

- aggressive vacuum completed
The last aggressive (auto)vacuum is completed.

- error while $progress
The last vacuum stopped by error while $progress.
The $progress one of the vacuum progress phases.

- canceled while $progress
The last vacuum was canceled while $progress

This is caused by user cancellation of manual vacuum or
killed by another backend who wants to acquire lock on the
relation.

- skipped - lock unavailable
The last autovacuum on the relation was skipped because
required lock was not available.

- unvacuumable
A past autovacuum tried vacuum on the relation but it is not
vacuumable for reasons of ownership or accessibility problem.
(Such relations are not shown in pg_stat_all_tables..)

+ autovacuum_fail_count | 0
The number of successive failure of vacuum on the relation.
Reset to zero by completed vacuum.

======

In the patch, vacrelstats if pointed from a static variable and
cancel reporting is performed in PG_CATCH() section in vacuum().
Every unthrown error like lock acquisition failure is reported by
explicit pgstat_report_vacuum() with the corresponding finish
code.

Vacuum requirement status is calculated in AutoVacuumRequirment()
and returned as a string. Access share lock on the target
relation is required but it returns only available values if the
lock is not available. I decided to return incomplete (coarse
grained) result than wait for a lock that isn't known to be
relased in a short time for a perfect result.

regards,

--
Kyotaro Horiguchi
NTT Open Source Software Center

Attachments:

0001-Add-several-vacuum-information-in-pg_stat_-_tables.patchtext/x-patch; charset=us-asciiDownload+606-37
#18Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Kyotaro Horiguchi (#17)
Re: More stats about skipped vacuums

This is just a repost as a (true) new thread.

At Mon, 30 Oct 2017 20:57:50 +0900 (Tokyo Standard Time), Kyotaro HORIGUCHI <horiguchi.kyotaro@lab.ntt.co.jp> wrote in <20171030.205750.246076862.horiguchi.kyotaro@lab.ntt.co.jp>

At Fri, 20 Oct 2017 19:15:16 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in <CAD21AoAkaw-u0feAVN_VrKZA5tvzp7jT=mQCQP-SvMegKXHHaw@mail.gmail.com>

n_mod_since_analyze          | 20000
+ vacuum_requred               | true
+ last_vacuum_oldest_xid       | 8023
+ last_vacuum_left_to_truncate | 5123
+ last_vacuum_truncated        | 387
last_vacuum                  | 2017-10-10 17:21:54.380805+09
last_autovacuum              | 2017-10-10 17:21:54.380805+09
+ last_autovacuum_status       | Killed by lock conflict
...
autovacuum_count             | 128
+ incomplete_autovacuum_count  | 53

# The last one might be needless..

I'm not sure that the above informations will help for users or DBA
but personally I sometimes want to have the number of index scans of
the last autovacuum in the pg_stat_user_tables view. That value
indicates how efficiently vacuums performed and would be a signal to
increase the setting of autovacuum_work_mem for user.

Btree and all existing index AMs (except brin) seem to visit the
all pages in every index scan so it would be valuable. Instead
the number of visited index pages during a table scan might be
usable. It is more relevant to performance than the number of
scans, on the other hand it is a bit difficult to get something
worth from the number in a moment. I'll show the number of scans
in the first cut.

Where the "Killed by lock conflict" is one of the followings.

- Completed
- Truncation skipped
- Partially truncated
- Skipped
- Killed by lock conflict

This seems enough to find the cause of a table bloat. The same
discussion could be applied to analyze but it might be the
another issue.

There may be a better way to indicate the vacuum soundness. Any
opinions and suggestions are welcome.

I'm going to make a patch to do the 'formal' one for the time
being.

Done with small modifications. In the attached patch
pg_stat_all_tables has the following new columns. Documentations
is not provided at this stage.

-----
  n_mod_since_analyze     | 0
+ vacuum_required         | not requried
  last_vacuum             | 
  last_autovacuum         | 2017-10-30 18:51:32.060551+09
  last_analyze            | 
  last_autoanalyze        | 2017-10-30 18:48:33.414711+09
  vacuum_count            | 0
+ last_vacuum_truncated   | 0
+ last_vacuum_untruncated | 0
+ last_vacuum_index_scans | 0
+ last_vacuum_oldest_xmin | 2134
+ last_vacuum_status      | agressive vacuum completed
+ autovacuum_fail_count   | 0
  autovacuum_count        | 5
  analyze_count           | 0
  autoanalyze_count       | 1
-----
Where each column shows the following infomation.

+ vacuum_required | not requried

VACUUM requirement status. Takes the following values.

- partial
Partial (or normal) will be performed by the next autovacuum.
The word "partial" is taken from the comment for
vacuum_set_xid_limits.

- aggressive
Aggressive scan will be performed by the next autovacuum.

- required
Any type of autovacuum will be performed. The type of scan is
unknown because the view failed to take the required lock on
the table. (AutoVacuumrequirement())

- not required
Next autovacuum won't perform scan on this relation.

- not required (lock not acquired)

Autovacuum should be disabled and the distance to
freeze-limit is not known because required lock is not
available.

- close to freeze-limit xid
Shown while autovacuum is disabled. The table is in the
manual vacuum window to avoid anti-wraparound autovacuum.

+ last_vacuum_truncated | 0

The number of truncated pages in the last completed
(auto)vacuum.

+ last_vacuum_untruncated | 0
The number of pages the last completed (auto)vacuum tried to
truncate but could not for some reason.

+ last_vacuum_index_scans | 0
The number of index scans performed in the last completed
(auto)vacuum.

+ last_vacuum_oldest_xmin | 2134
The oldest xmin used in the last completed (auto)vacuum.

+ last_vacuum_status | agressive vacuum completed

The finish status of the last vacuum. Takes the following
values. (pg_stat_get_last_vacuum_status())

- completed
The last partial (auto)vacuum is completed.

- vacuum full completed
The last VACUUM FULL is completed.

- aggressive vacuum completed
The last aggressive (auto)vacuum is completed.

- error while $progress
The last vacuum stopped by error while $progress.
The $progress one of the vacuum progress phases.

- canceled while $progress
The last vacuum was canceled while $progress

This is caused by user cancellation of manual vacuum or
killed by another backend who wants to acquire lock on the
relation.

- skipped - lock unavailable
The last autovacuum on the relation was skipped because
required lock was not available.

- unvacuumable
A past autovacuum tried vacuum on the relation but it is not
vacuumable for reasons of ownership or accessibility problem.
(Such relations are not shown in pg_stat_all_tables..)

+ autovacuum_fail_count | 0
The number of successive failure of vacuum on the relation.
Reset to zero by completed vacuum.

======

In the patch, vacrelstats if pointed from a static variable and
cancel reporting is performed in PG_CATCH() section in vacuum().
Every unthrown error like lock acquisition failure is reported by
explicit pgstat_report_vacuum() with the corresponding finish
code.

Vacuum requirement status is calculated in AutoVacuumRequirment()
and returned as a string. Access share lock on the target
relation is required but it returns only available values if the
lock is not available. I decided to return incomplete (coarse
grained) result than wait for a lock that isn't known to be
relased in a short time for a perfect result.

regards,

--
Kyotaro Horiguchi
NTT Open Source Software Center

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#19Michael Paquier
michael@paquier.xyz
In reply to: Kyotaro Horiguchi (#17)
Re: [HACKERS] More stats about skipped vacuums

On Mon, Oct 30, 2017 at 8:57 PM, Kyotaro HORIGUCHI
<horiguchi.kyotaro@lab.ntt.co.jp> wrote:

At Thu, 26 Oct 2017 15:06:30 +0900 (Tokyo Standard Time), Kyotaro HORIGUCHI <horiguchi.kyotaro@lab.ntt.co.jp> wrote in <20171026.150630.115694437.horiguchi.kyotaro@lab.ntt.co.jp>

At Fri, 20 Oct 2017 19:15:16 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in <CAD21AoAkaw-u0feAVN_VrKZA5tvzp7jT=mQCQP-SvMegKXHHaw@mail.gmail.com>

n_mod_since_analyze          | 20000
+ vacuum_requred               | true
+ last_vacuum_oldest_xid       | 8023
+ last_vacuum_left_to_truncate | 5123
+ last_vacuum_truncated        | 387
last_vacuum                  | 2017-10-10 17:21:54.380805+09
last_autovacuum              | 2017-10-10 17:21:54.380805+09
+ last_autovacuum_status       | Killed by lock conflict
...
autovacuum_count             | 128
+ incomplete_autovacuum_count  | 53

# The last one might be needless..

I'm not sure that the above informations will help for users or DBA
but personally I sometimes want to have the number of index scans of
the last autovacuum in the pg_stat_user_tables view. That value
indicates how efficiently vacuums performed and would be a signal to
increase the setting of autovacuum_work_mem for user.

Btree and all existing index AMs (except brin) seem to visit the
all pages in every index scan so it would be valuable. Instead
the number of visited index pages during a table scan might be
usable. It is more relevant to performance than the number of
scans, on the other hand it is a bit difficult to get something
worth from the number in a moment. I'll show the number of scans
in the first cut.

Where the "Killed by lock conflict" is one of the followings.

- Completed
- Truncation skipped
- Partially truncated
- Skipped
- Killed by lock conflict

This seems enough to find the cause of a table bloat. The same
discussion could be applied to analyze but it might be the
another issue.

There may be a better way to indicate the vacuum soundness. Any
opinions and suggestions are welcome.

I'm going to make a patch to do the 'formal' one for the time
being.

Done with small modifications. In the attached patch
pg_stat_all_tables has the following new columns. Documentations
is not provided at this stage.

-----
n_mod_since_analyze     | 0
+ vacuum_required         | not requried
last_vacuum             |
last_autovacuum         | 2017-10-30 18:51:32.060551+09
last_analyze            |
last_autoanalyze        | 2017-10-30 18:48:33.414711+09
vacuum_count            | 0
+ last_vacuum_truncated   | 0
+ last_vacuum_untruncated | 0
+ last_vacuum_index_scans | 0
+ last_vacuum_oldest_xmin | 2134
+ last_vacuum_status      | agressive vacuum completed
+ autovacuum_fail_count   | 0
autovacuum_count        | 5
analyze_count           | 0
autoanalyze_count       | 1
-----
Where each column shows the following infomation.

+ vacuum_required | not requried

VACUUM requirement status. Takes the following values.

- partial
Partial (or normal) will be performed by the next autovacuum.
The word "partial" is taken from the comment for
vacuum_set_xid_limits.

- aggressive
Aggressive scan will be performed by the next autovacuum.

- required
Any type of autovacuum will be performed. The type of scan is
unknown because the view failed to take the required lock on
the table. (AutoVacuumrequirement())

- not required
Next autovacuum won't perform scan on this relation.

- not required (lock not acquired)

Autovacuum should be disabled and the distance to
freeze-limit is not known because required lock is not
available.

- close to freeze-limit xid
Shown while autovacuum is disabled. The table is in the
manual vacuum window to avoid anti-wraparound autovacuum.

+ last_vacuum_truncated | 0

The number of truncated pages in the last completed
(auto)vacuum.

+ last_vacuum_untruncated | 0
The number of pages the last completed (auto)vacuum tried to
truncate but could not for some reason.

+ last_vacuum_index_scans | 0
The number of index scans performed in the last completed
(auto)vacuum.

+ last_vacuum_oldest_xmin | 2134
The oldest xmin used in the last completed (auto)vacuum.

+ last_vacuum_status | agressive vacuum completed

The finish status of the last vacuum. Takes the following
values. (pg_stat_get_last_vacuum_status())

- completed
The last partial (auto)vacuum is completed.

- vacuum full completed
The last VACUUM FULL is completed.

- aggressive vacuum completed
The last aggressive (auto)vacuum is completed.

- error while $progress
The last vacuum stopped by error while $progress.
The $progress one of the vacuum progress phases.

- canceled while $progress
The last vacuum was canceled while $progress

This is caused by user cancellation of manual vacuum or
killed by another backend who wants to acquire lock on the
relation.

- skipped - lock unavailable
The last autovacuum on the relation was skipped because
required lock was not available.

- unvacuumable
A past autovacuum tried vacuum on the relation but it is not
vacuumable for reasons of ownership or accessibility problem.
(Such relations are not shown in pg_stat_all_tables..)

+ autovacuum_fail_count | 0
The number of successive failure of vacuum on the relation.
Reset to zero by completed vacuum.

======

In the patch, vacrelstats if pointed from a static variable and
cancel reporting is performed in PG_CATCH() section in vacuum().
Every unthrown error like lock acquisition failure is reported by
explicit pgstat_report_vacuum() with the corresponding finish
code.

Vacuum requirement status is calculated in AutoVacuumRequirment()
and returned as a string. Access share lock on the target
relation is required but it returns only available values if the
lock is not available. I decided to return incomplete (coarse
grained) result than wait for a lock that isn't known to be
relased in a short time for a perfect result.

             pg_stat_get_mod_since_analyze(C.oid) AS n_mod_since_analyze,
+           pg_stat_get_vacuum_necessity(C.oid) AS vacuum_required,
             pg_stat_get_last_vacuum_time(C.oid) as last_vacuum,
             pg_stat_get_last_autovacuum_time(C.oid) as last_autovacuum,
             pg_stat_get_last_analyze_time(C.oid) as last_analyze,
             pg_stat_get_last_autoanalyze_time(C.oid) as last_autoanalyze,
             pg_stat_get_vacuum_count(C.oid) AS vacuum_count,
+           pg_stat_get_last_vacuum_truncated(C.oid) AS last_vacuum_truncated,
+           pg_stat_get_last_vacuum_untruncated(C.oid) AS
last_vacuum_untruncated,
+           pg_stat_get_last_vacuum_index_scans(C.oid) AS
last_vacuum_index_scans,
+           pg_stat_get_last_vacuum_oldest_xmin(C.oid) AS
last_vacuum_oldest_xmin,
+           pg_stat_get_last_vacuum_status(C.oid) AS last_vacuum_status,
+           pg_stat_get_autovacuum_fail_count(C.oid) AS autovacuum_fail_count,
Please use spaces instead of tabs. Indentation is not consistent.
+       case PGSTAT_VACUUM_CANCELED:
+           phase = tabentry->vacuum_last_phase;
+           /* number of elements of phasestr above */
+           if (phase >= 0 && phase <= 7)
+               result = psprintf("%s while %s",
+                                 status == PGSTAT_VACUUM_CANCELED ?
+                                 "canceled" : "error",
+                                 phasestr[phase]);
Such complication is not necessary. The phase parameter is updated by
individual calls of pgstat_progress_update_param(), so the information
showed here overlaps with the existing information in the "phase"
field.

@@ -210,7 +361,6 @@ pg_stat_get_blocks_fetched(PG_FUNCTION_ARGS)
PG_RETURN_INT64(result);
}

-
Datum
pg_stat_get_blocks_hit(PG_FUNCTION_ARGS)
Noise diff.

Thinking about trying to et something into core by the end of the
commit fest, this patch presents multiple concepts at once which could
be split into separate patches for simplicity:
1) Additional data fields to help in debugging completed vacuums.
2) Tracking of interrupted vacuum jobs in progress table.
3) Get state of vacuum job on error.

However, progress reports are here to allow users to do decisions
based on the activity of how things are working. This patch proposes
to add multiple new fields:
- oldest Xmin.
- number of index scans.
- number of pages truncated.
- number of pages that should have been truncated, but are not truncated.
Among all this information, as Sawada-san has already mentioned
upthread, the more index scans the less dead tuples you can store at
once, so autovacuum_work_mem ought to be increases. This is useful for
tuning and should be documented properly if reported to give
indications about vacuum behavior. The rest though, could indicate how
aggressive autovacuum is able to remove tail blocks and do its work.
But what really matters for users to decide if autovacuum should be
more aggressive is tracking the number of dead tuples, something which
is already evaluated.

Tracking the number of failed vacuum attempts is also something
helpful to understand how much the job is able to complete. As there
is already tracking vacuum jobs that have completed, it could be
possible, instead of logging activity when a vacuum job has failed, to
track the number of *begun* jobs on a relation. Then it is possible to
guess how many have failed by taking the difference between those that
completed properly. Having counters per failure types could also be a
possibility.

For this commit fest, I would suggest a patch that simply adds
tracking for the number of index scans done, with documentation to
give recommendations about parameter tuning. i am switching the patch
as "waiting on author".
--
Michael

#20Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Michael Paquier (#19)
Re: [HACKERS] More stats about skipped vacuums

Thank you for reviewing this.

At Wed, 15 Nov 2017 16:13:01 +0900, Michael Paquier <michael.paquier@gmail.com> wrote in <CAB7nPqQm_WCKuUf5RD0CzeMuMO907ZPKP7mBh-3t2zSJ9jn+PA@mail.gmail.com>

pg_stat_get_mod_since_analyze(C.oid) AS n_mod_since_analyze,
+ pg_stat_get_vacuum_necessity(C.oid) AS vacuum_required,
pg_stat_get_last_vacuum_time(C.oid) as last_vacuum,
pg_stat_get_last_autovacuum_time(C.oid) as last_autovacuum,
pg_stat_get_last_analyze_time(C.oid) as last_analyze,
pg_stat_get_last_autoanalyze_time(C.oid) as last_autoanalyze,
pg_stat_get_vacuum_count(C.oid) AS vacuum_count,
Please use spaces instead of tabs. Indentation is not consistent.

Done. Thank you for pointing. (whitespace-mode showed me some
similar inconsistencies at the other places in the file...)

+       case PGSTAT_VACUUM_CANCELED:
+           phase = tabentry->vacuum_last_phase;
+           /* number of elements of phasestr above */
+           if (phase >= 0 && phase <= 7)
+               result = psprintf("%s while %s",
+                                 status == PGSTAT_VACUUM_CANCELED ?
+                                 "canceled" : "error",
+                                 phasestr[phase]);
Such complication is not necessary. The phase parameter is updated by
individual calls of pgstat_progress_update_param(), so the information
showed here overlaps with the existing information in the "phase"
field.

The "phase" is pg_stat_progress_vacuum's? If "complexy" means
phasestr[phase], the "phase" cannot be overlap with
last_vacuum_status since pg_stat_progress_vacuum's entry has
already gone when someone looks into pg_stat_all_tables and see a
failed vacuum status. Could you give a bit specific comment?

@@ -210,7 +361,6 @@ pg_stat_get_blocks_fetched(PG_FUNCTION_ARGS)
PG_RETURN_INT64(result);
}

-
Datum
pg_stat_get_blocks_hit(PG_FUNCTION_ARGS)
Noise diff.

Removed.

Thinking about trying to et something into core by the end of the
commit fest, this patch presents multiple concepts at once which could
be split into separate patches for simplicity:
1) Additional data fields to help in debugging completed vacuums.
2) Tracking of interrupted vacuum jobs in progress table.
3) Get state of vacuum job on error.

However, progress reports are here to allow users to do decisions
based on the activity of how things are working. This patch proposes
to add multiple new fields:
- oldest Xmin.
- number of index scans.
- number of pages truncated.
- number of pages that should have been truncated, but are not truncated.
Among all this information, as Sawada-san has already mentioned
upthread, the more index scans the less dead tuples you can store at
once, so autovacuum_work_mem ought to be increases. This is useful for
tuning and should be documented properly if reported to give
indications about vacuum behavior. The rest though, could indicate how
aggressive autovacuum is able to remove tail blocks and do its work.
But what really matters for users to decide if autovacuum should be
more aggressive is tracking the number of dead tuples, something which
is already evaluated.

Hmm. I tend to agree. Such numbers are better to be shown as
average of the last n vacuums or maximum. I decided to show
last_vacuum_index_scan only and I think that someone can record
it continuously to elsewhere if wants.

Tracking the number of failed vacuum attempts is also something
helpful to understand how much the job is able to complete. As there
is already tracking vacuum jobs that have completed, it could be
possible, instead of logging activity when a vacuum job has failed, to
track the number of *begun* jobs on a relation. Then it is possible to
guess how many have failed by taking the difference between those that
completed properly. Having counters per failure types could also be a
possibility.

Maybe pg_stat_all_tables is not the place to hold such many kinds
of vacuum specific information. pg_stat_vacuum_all_tables or
something like?

For this commit fest, I would suggest a patch that simply adds
tracking for the number of index scans done, with documentation to
give recommendations about parameter tuning. i am switching the patch
as "waiting on author".

Ok, the patch has been split into the following four parts. (Not
split by function, but by the kind of information to add.)
The first one is that.

0001. Adds pg_stat_all_tables.last_vacuum_index_scans. Documentation is added.

0002. Adds pg_stat_all_tables.vacuum_required. And primitive documentation.

0003. Adds pg_stat_all_tables.last_vacuum_status/autovacuum_fail_count
plus primitive documentation.

0004. truncation information stuff.

One concern on pg_stat_all_tables view is the number of
predefined functions it uses. Currently 20 functions and this
patch adds more seven. I feel it's better that at least the
functions this patch adds are merged into one function..

--
Kyotaro Horiguchi
NTT Open Source Software Center

Attachments:

0001-Show-index-scans-of-the-last-vacuum-in-pg_stat_all_t.patchtext/x-patch; charset=us-asciiDownload+45-4
0002-Add-vacuum_required-to-pg_stat_all_tables.patchtext/x-patch; charset=us-asciiDownload+210-24
0003-Add-vacuum-execution-status-in-pg_stat_all_tables.patchtext/x-patch; charset=us-asciiDownload+283-16
0004-Add-truncation-information-and-oldestxmin-to-pg_stat.patchtext/x-patch; charset=us-asciiDownload+128-12
#21Michael Paquier
michael@paquier.xyz
In reply to: Kyotaro Horiguchi (#20)
#22Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Michael Paquier (#21)
#23Michael Paquier
michael@paquier.xyz
In reply to: Kyotaro Horiguchi (#22)
#24Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Michael Paquier (#23)
#25Michael Paquier
michael@paquier.xyz
In reply to: Kyotaro Horiguchi (#24)
#26Robert Haas
robertmhaas@gmail.com
In reply to: Kyotaro Horiguchi (#22)
#27Michael Paquier
michael@paquier.xyz
In reply to: Robert Haas (#26)
#28Tom Lane
tgl@sss.pgh.pa.us
In reply to: Michael Paquier (#27)
#29Robert Haas
robertmhaas@gmail.com
In reply to: Tom Lane (#28)
#30Tom Lane
tgl@sss.pgh.pa.us
In reply to: Robert Haas (#29)
#31Michael Paquier
michael@paquier.xyz
In reply to: Tom Lane (#28)
#32Tom Lane
tgl@sss.pgh.pa.us
In reply to: Michael Paquier (#31)
#33Michael Paquier
michael@paquier.xyz
In reply to: Tom Lane (#32)
#34Tom Lane
tgl@sss.pgh.pa.us
In reply to: Michael Paquier (#33)
#35Robert Haas
robertmhaas@gmail.com
In reply to: Tom Lane (#30)
#36Tom Lane
tgl@sss.pgh.pa.us
In reply to: Robert Haas (#35)
#37Michael Paquier
michael@paquier.xyz
In reply to: Tom Lane (#34)
#38Michael Paquier
michael@paquier.xyz
In reply to: Tom Lane (#36)
#39Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Michael Paquier (#38)
#40Robert Haas
robertmhaas@gmail.com
In reply to: Kyotaro Horiguchi (#39)
#41Robert Haas
robertmhaas@gmail.com
In reply to: Tom Lane (#36)
#42Magnus Hagander
magnus@hagander.net
In reply to: Robert Haas (#41)
#43Tom Lane
tgl@sss.pgh.pa.us
In reply to: Magnus Hagander (#42)
#44Magnus Hagander
magnus@hagander.net
In reply to: Tom Lane (#43)
#45Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Robert Haas (#40)
#46Masahiko Sawada
sawada.mshk@gmail.com
In reply to: Kyotaro Horiguchi (#45)
#47Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Masahiko Sawada (#46)
#48Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Kyotaro Horiguchi (#47)
#49Robert Haas
robertmhaas@gmail.com
In reply to: Kyotaro Horiguchi (#48)
#50Tom Lane
tgl@sss.pgh.pa.us
In reply to: Robert Haas (#49)
#51Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Tom Lane (#50)
#52Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Kyotaro Horiguchi (#51)
#53Kyotaro Horiguchi
horikyota.ntt@gmail.com
In reply to: Kyotaro Horiguchi (#52)