Horton

Thread

Commits

  1. Fix initialization of pg_stat_get_lastscan()

  2. pgstat: Track time of the last scan of a relation

  3. Have GetCurrentTransactionStopTimestamp() set xactStopTimestamp if unset

  1. Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-08-23T09:55:09Z

    Often it is beneficial to review one's schema with a view to removing
indexes (and sometimes tables) that are no longer required. It's very
difficult to understand when that is the case by looking at the number of
scans of a relation as, for example, an index may be used infrequently but
may be critical in those times when it is used.

The attached patch against HEAD adds optional tracking of the last scan
time for relations. It updates pg_stat_*_tables with new last_seq_scan and
last_idx_scan columns, and pg_stat_*_indexes with a last_idx_scan column to
help with this.

Due to the use of gettimeofday(), those values are only maintained if a new
GUC, track_scans, is set to on. By default, it is off.

I did run a 12 hour test to see what the performance impact is. pgbench was
run with scale factor 10000 and 75 users across 4 identical bare metal
machines running Rocky 8 in parallel which showed roughly a -2% average
performance penalty against HEAD with track_scans enabled. Machines were
PowerEdge R7525's with 128GB RAM, dual 16C/32T AMD 7302 CPUs, with the data
directory on 6 x 800GB 12Gb/s SSD SAS drives in RAID 0. Kernel time source
is tsc.

               HEAD               track_scans      Penalty (%)
box1       19582.49735    19341.8881      -1.22869541
box2       19936.55513    19928.07479    -0.04253664659
box3       19631.78895    18649.64379    -5.002830696
box4       19810.86767    19420.67192    -1.969604525
Average 19740.42728    19335.06965    -2.05343896

Doc and test updates included.

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  2. Re: Tracking last scan time

    Greg Stark <stark@mit.edu> — 2022-08-23T12:07:05Z

    On Tue, 23 Aug 2022 at 11:00, Dave Page <dpage@pgadmin.org> wrote:
>
> Often it is beneficial to review one's schema with a view to removing indexes (and sometimes tables) that are no longer required. It's very difficult to understand when that is the case by looking at the number of scans of a relation as, for example, an index may be used infrequently but may be critical in those times when it is used.

I think this is easy to answer in a prometheus/datadog/etc world since
you can consult the history of the count to see when it was last
incremented. (Or do effectively that continously).

I guess that just reinforces the idea that it should be optional.
Perhaps there's room for some sort of general feature for controlling
various time series aggregates like max() and min() sum() or, uhm,
timeoflastchange() on whatever stats you want. That would let us
remove a bunch of stuff from pg_stat_statements and let users turn on
just the ones they want. And also let users enable things like time of
last rollback or conflict etc. But that's just something to think
about down the road.

> The attached patch against HEAD adds optional tracking of the last scan time for relations. It updates pg_stat_*_tables with new last_seq_scan and last_idx_scan columns, and pg_stat_*_indexes with a last_idx_scan column to help with this.
>
> Due to the use of gettimeofday(), those values are only maintained if a new GUC, track_scans, is set to on. By default, it is off.

Bikeshedding warning -- "track_scans" could equally apply to almost
any stats about scans. I think the really relevant thing here is the
times, not the scans. I think the GUC should be "track_scan_times". Or
could that still be confused with scan durations? Maybe
"track_scan_timestamps"?

You could maybe make the gettimeofday cheaper by doing it less often.
Like, skipping the increment if the old timestamp is newer than 1s
before the transaction start time (I think that's available free if
some other guc is enabled but I don't recall). Or isn't this cb
normally happening after transaction end? So xactStopTimestamp might
be available already?


-- 
greg

  3. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-08-24T13:01:15Z

    Hi

On Tue, 23 Aug 2022 at 13:07, Greg Stark <stark@mit.edu> wrote:

> On Tue, 23 Aug 2022 at 11:00, Dave Page <dpage@pgadmin.org> wrote:
> >
> > Often it is beneficial to review one's schema with a view to removing
> indexes (and sometimes tables) that are no longer required. It's very
> difficult to understand when that is the case by looking at the number of
> scans of a relation as, for example, an index may be used infrequently but
> may be critical in those times when it is used.
>
> I think this is easy to answer in a prometheus/datadog/etc world since
> you can consult the history of the count to see when it was last
> incremented. (Or do effectively that continously).
>

Yes. But not every PostgreSQL instance is monitored in that way.


>
> I guess that just reinforces the idea that it should be optional.
> Perhaps there's room for some sort of general feature for controlling
> various time series aggregates like max() and min() sum() or, uhm,
> timeoflastchange() on whatever stats you want. That would let us
> remove a bunch of stuff from pg_stat_statements and let users turn on
> just the ones they want. And also let users enable things like time of
> last rollback or conflict etc. But that's just something to think
> about down the road.
>

It's certainly an interesting idea.


>
> > The attached patch against HEAD adds optional tracking of the last scan
> time for relations. It updates pg_stat_*_tables with new last_seq_scan and
> last_idx_scan columns, and pg_stat_*_indexes with a last_idx_scan column to
> help with this.
> >
> > Due to the use of gettimeofday(), those values are only maintained if a
> new GUC, track_scans, is set to on. By default, it is off.
>
> Bikeshedding warning -- "track_scans" could equally apply to almost
> any stats about scans. I think the really relevant thing here is the
> times, not the scans. I think the GUC should be "track_scan_times". Or
> could that still be confused with scan durations? Maybe
> "track_scan_timestamps"?
>

The latter seems reasonable.


>
> You could maybe make the gettimeofday cheaper by doing it less often.
> Like, skipping the increment if the old timestamp is newer than 1s
> before the transaction start time (I think that's available free if
> some other guc is enabled but I don't recall). Or isn't this cb
> normally happening after transaction end? So xactStopTimestamp might
> be available already?
>

Something like:

 if (pgstat_track_scan_timestamps && lstats->t_counts.t_numscans &&
        tabentry->lastscan + USECS_PER_SEC <
GetCurrentTransactionStopTimestamp())
    tabentry->lastscan = GetCurrentTimestamp();

?

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  4. Re: Tracking last scan time

    Bruce Momjian <bruce@momjian.us> — 2022-08-24T14:18:20Z

    On Tue, Aug 23, 2022 at 10:55:09AM +0100, Dave Page wrote:
> Often it is beneficial to review one's schema with a view to removing indexes
> (and sometimes tables) that are no longer required. It's very difficult to
> understand when that is the case by looking at the number of scans of a
> relation as, for example, an index may be used infrequently but may be critical
> in those times when it is used.
> 
> The attached patch against HEAD adds optional tracking of the last scan time
> for relations. It updates pg_stat_*_tables with new last_seq_scan and
> last_idx_scan columns, and pg_stat_*_indexes with a last_idx_scan column to
> help with this.

Would it be simpler to allow the sequential and index scan columns to be
cleared so you can look later to see if it is non-zero?  Should we allow
arbitrary clearing of stat columns?

-- 
  Bruce Momjian  <bruce@momjian.us>        https://momjian.us
  EDB                                      https://enterprisedb.com

  Indecision is a decision.  Inaction is an action.  Mark Batterson

  5. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-08-24T15:01:21Z

    On Wed, 24 Aug 2022 at 15:18, Bruce Momjian <bruce@momjian.us> wrote:

> On Tue, Aug 23, 2022 at 10:55:09AM +0100, Dave Page wrote:
> > Often it is beneficial to review one's schema with a view to removing
> indexes
> > (and sometimes tables) that are no longer required. It's very difficult
> to
> > understand when that is the case by looking at the number of scans of a
> > relation as, for example, an index may be used infrequently but may be
> critical
> > in those times when it is used.
> >
> > The attached patch against HEAD adds optional tracking of the last scan
> time
> > for relations. It updates pg_stat_*_tables with new last_seq_scan and
> > last_idx_scan columns, and pg_stat_*_indexes with a last_idx_scan column
> to
> > help with this.
>
> Would it be simpler to allow the sequential and index scan columns to be
> cleared so you can look later to see if it is non-zero?  Should we allow
> arbitrary clearing of stat columns?
>

I don't think so, because then stat values wouldn't necessarily correlate
with each other, and you wouldn't know when any of them were last reset
unless we started tracking each individual reset. At least now you can see
when they were all reset, and you know they were reset at the same time.

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  6. Re: Tracking last scan time

    Bruce Momjian <bruce@momjian.us> — 2022-08-24T15:03:44Z

    On Wed, Aug 24, 2022 at 04:01:21PM +0100, Dave Page wrote:
> On Wed, 24 Aug 2022 at 15:18, Bruce Momjian <bruce@momjian.us> wrote:
> 
>     On Tue, Aug 23, 2022 at 10:55:09AM +0100, Dave Page wrote:
>     > Often it is beneficial to review one's schema with a view to removing
>     indexes
>     > (and sometimes tables) that are no longer required. It's very difficult
>     to
>     > understand when that is the case by looking at the number of scans of a
>     > relation as, for example, an index may be used infrequently but may be
>     critical
>     > in those times when it is used.
>     >
>     > The attached patch against HEAD adds optional tracking of the last scan
>     time
>     > for relations. It updates pg_stat_*_tables with new last_seq_scan and
>     > last_idx_scan columns, and pg_stat_*_indexes with a last_idx_scan column
>     to
>     > help with this.
> 
>     Would it be simpler to allow the sequential and index scan columns to be
>     cleared so you can look later to see if it is non-zero?  Should we allow
> 
> I don't think so, because then stat values wouldn't necessarily correlate with
> each other, and you wouldn't know when any of them were last reset unless we
> started tracking each individual reset. At least now you can see when they were
> all reset, and you know they were reset at the same time.

Yeah, true.  I was more asking if these two columns are in some way
special or if people would want a more general solution, and if so, is
that something we want in core Postgres.

-- 
  Bruce Momjian  <bruce@momjian.us>        https://momjian.us
  EDB                                      https://enterprisedb.com

  Indecision is a decision.  Inaction is an action.  Mark Batterson

  7. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-08-24T15:15:47Z

    On Wed, 24 Aug 2022 at 16:03, Bruce Momjian <bruce@momjian.us> wrote:

> On Wed, Aug 24, 2022 at 04:01:21PM +0100, Dave Page wrote:
> > On Wed, 24 Aug 2022 at 15:18, Bruce Momjian <bruce@momjian.us> wrote:
> >
> >     On Tue, Aug 23, 2022 at 10:55:09AM +0100, Dave Page wrote:
> >     > Often it is beneficial to review one's schema with a view to
> removing
> >     indexes
> >     > (and sometimes tables) that are no longer required. It's very
> difficult
> >     to
> >     > understand when that is the case by looking at the number of scans
> of a
> >     > relation as, for example, an index may be used infrequently but
> may be
> >     critical
> >     > in those times when it is used.
> >     >
> >     > The attached patch against HEAD adds optional tracking of the last
> scan
> >     time
> >     > for relations. It updates pg_stat_*_tables with new last_seq_scan
> and
> >     > last_idx_scan columns, and pg_stat_*_indexes with a last_idx_scan
> column
> >     to
> >     > help with this.
> >
> >     Would it be simpler to allow the sequential and index scan columns
> to be
> >     cleared so you can look later to see if it is non-zero?  Should we
> allow
> >
> > I don't think so, because then stat values wouldn't necessarily
> correlate with
> > each other, and you wouldn't know when any of them were last reset
> unless we
> > started tracking each individual reset. At least now you can see when
> they were
> > all reset, and you know they were reset at the same time.
>
> Yeah, true.  I was more asking if these two columns are in some way
> special or if people would want a more general solution, and if so, is
> that something we want in core Postgres.
>

They're special in the sense that they're the ones you're most likely going
to look at to see how much a relation is used I think (at least, I'd look
at them rather than the tuple counts).

There are certainly other things for which a last usage value may be
useful. Functions/procedures for example, or views. The benefits to
removing unused objects of that type are far, far lower than indexes or
tables of course.

There are other potential use cases for similar timestamps, such as object
creation times (and creating user), but they are more useful for auditing
than monitoring and optimisation.

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  8. Re: Tracking last scan time

    David Rowley <dgrowleyml@gmail.com> — 2022-08-25T00:43:41Z

    On Thu, 25 Aug 2022 at 03:03, Bruce Momjian <bruce@momjian.us> wrote:
>
> On Wed, Aug 24, 2022 at 04:01:21PM +0100, Dave Page wrote:
> > On Wed, 24 Aug 2022 at 15:18, Bruce Momjian <bruce@momjian.us> wrote:
> >     Would it be simpler to allow the sequential and index scan columns to be
> >     cleared so you can look later to see if it is non-zero?  Should we allow
> >
> > I don't think so, because then stat values wouldn't necessarily correlate with
> > each other, and you wouldn't know when any of them were last reset unless we
> > started tracking each individual reset. At least now you can see when they were
> > all reset, and you know they were reset at the same time.
>
> Yeah, true.  I was more asking if these two columns are in some way
> special or if people would want a more general solution, and if so, is
> that something we want in core Postgres.

Back when I used to do a bit of PostgreSQL DBA stuff, I had a nightly
job setup to record the state of pg_stat_all_tables and put that into
another table along with the current date. I then had a view that did
some calculations with col - LAG(col) OVER (PARTITION BY relid ORDER
BY date) to fetch the numerical values for each date.  I didn't ever
want to reset the stats because it messes with autovacuum. If you zero
out n_ins_since_vacuum more often than auto-vacuum would trigger, then
bad things happen over time (we should really warn about that in the
docs).

I don't have a particular opinion about the patch, I'm just pointing
out that there are other ways. Even just writing down the numbers on a
post-it note and coming back in a month to see if they've changed is
enough to tell if the table or index has been used.

We do also need to consider now that stats are stored in shared memory
that any fields we add are in RAM.

David

  9. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-08-26T13:05:36Z

    Hi

On Thu, 25 Aug 2022 at 01:44, David Rowley <dgrowleyml@gmail.com> wrote:

> On Thu, 25 Aug 2022 at 03:03, Bruce Momjian <bruce@momjian.us> wrote:
> >
> > On Wed, Aug 24, 2022 at 04:01:21PM +0100, Dave Page wrote:
> > > On Wed, 24 Aug 2022 at 15:18, Bruce Momjian <bruce@momjian.us> wrote:
> > >     Would it be simpler to allow the sequential and index scan columns
> to be
> > >     cleared so you can look later to see if it is non-zero?  Should we
> allow
> > >
> > > I don't think so, because then stat values wouldn't necessarily
> correlate with
> > > each other, and you wouldn't know when any of them were last reset
> unless we
> > > started tracking each individual reset. At least now you can see when
> they were
> > > all reset, and you know they were reset at the same time.
> >
> > Yeah, true.  I was more asking if these two columns are in some way
> > special or if people would want a more general solution, and if so, is
> > that something we want in core Postgres.
>
> Back when I used to do a bit of PostgreSQL DBA stuff, I had a nightly
> job setup to record the state of pg_stat_all_tables and put that into
> another table along with the current date. I then had a view that did
> some calculations with col - LAG(col) OVER (PARTITION BY relid ORDER
> BY date) to fetch the numerical values for each date.  I didn't ever
> want to reset the stats because it messes with autovacuum. If you zero
> out n_ins_since_vacuum more often than auto-vacuum would trigger, then
> bad things happen over time (we should really warn about that in the
> docs).
>
> I don't have a particular opinion about the patch, I'm just pointing
> out that there are other ways. Even just writing down the numbers on a
> post-it note and coming back in a month to see if they've changed is
> enough to tell if the table or index has been used.
>

There are usually other ways to perform monitoring tasks, but there is
something to be said for the convenience of having functionality built in
and not having to rely on tools, scripts, or post-it notes :-)


>
> We do also need to consider now that stats are stored in shared memory
> that any fields we add are in RAM.
>

That is a fair point. I believe this is both minimal, and useful though.

I've attached a v2 patch that incorporates Greg's suggestions.

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  10. Re: Tracking last scan time

    Bruce Momjian <bruce@momjian.us> — 2022-08-30T18:46:23Z

    On Fri, Aug 26, 2022 at 02:05:36PM +0100, Dave Page wrote:
> On Thu, 25 Aug 2022 at 01:44, David Rowley <dgrowleyml@gmail.com> wrote:
>     I don't have a particular opinion about the patch, I'm just pointing
>     out that there are other ways. Even just writing down the numbers on a
>     post-it note and coming back in a month to see if they've changed is
>     enough to tell if the table or index has been used.
> 
> 
> There are usually other ways to perform monitoring tasks, but there is
> something to be said for the convenience of having functionality built in and
> not having to rely on tools, scripts, or post-it notes :-)

Should we consider using something cheaper like time() so we don't need
a GUC to enable this?

-- 
  Bruce Momjian  <bruce@momjian.us>        https://momjian.us
  EDB                                      https://enterprisedb.com

  Indecision is a decision.  Inaction is an action.  Mark Batterson

  11. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-08-31T16:02:33Z

    On Tue, 30 Aug 2022 at 19:46, Bruce Momjian <bruce@momjian.us> wrote:

> On Fri, Aug 26, 2022 at 02:05:36PM +0100, Dave Page wrote:
> > On Thu, 25 Aug 2022 at 01:44, David Rowley <dgrowleyml@gmail.com> wrote:
> >     I don't have a particular opinion about the patch, I'm just pointing
> >     out that there are other ways. Even just writing down the numbers on
> a
> >     post-it note and coming back in a month to see if they've changed is
> >     enough to tell if the table or index has been used.
> >
> >
> > There are usually other ways to perform monitoring tasks, but there is
> > something to be said for the convenience of having functionality built
> in and
> > not having to rely on tools, scripts, or post-it notes :-)
>
> Should we consider using something cheaper like time() so we don't need
> a GUC to enable this?
>

Interesting idea, but on my mac at least, 100,000,000 gettimeofday() calls
takes about 2 seconds, whilst 100,000,000 time() calls takes 14(!) seconds.

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  12. Re: Tracking last scan time

    Bruce Momjian <bruce@momjian.us> — 2022-08-31T16:13:37Z

    On Wed, Aug 31, 2022 at 05:02:33PM +0100, Dave Page wrote:
> 
> 
> On Tue, 30 Aug 2022 at 19:46, Bruce Momjian <bruce@momjian.us> wrote:
> 
>     On Fri, Aug 26, 2022 at 02:05:36PM +0100, Dave Page wrote:
>     > On Thu, 25 Aug 2022 at 01:44, David Rowley <dgrowleyml@gmail.com> wrote:
>     >     I don't have a particular opinion about the patch, I'm just pointing
>     >     out that there are other ways. Even just writing down the numbers on
>     a
>     >     post-it note and coming back in a month to see if they've changed is
>     >     enough to tell if the table or index has been used.
>     >
>     >
>     > There are usually other ways to perform monitoring tasks, but there is
>     > something to be said for the convenience of having functionality built in
>     and
>     > not having to rely on tools, scripts, or post-it notes :-)
> 
>     Should we consider using something cheaper like time() so we don't need
>     a GUC to enable this?
> 
> 
> Interesting idea, but on my mac at least, 100,000,000 gettimeofday() calls
> takes about 2 seconds, whilst 100,000,000 time() calls takes 14(!) seconds.

Wow.  I was just thinking you need second-level accuracy, which must be
cheap somewhere.

-- 
  Bruce Momjian  <bruce@momjian.us>        https://momjian.us
  EDB                                      https://enterprisedb.com

  Indecision is a decision.  Inaction is an action.  Mark Batterson

  13. Re: Tracking last scan time

    Andres Freund <andres@anarazel.de> — 2022-08-31T16:21:08Z

    Hi,

On 2022-08-23 10:55:09 +0100, Dave Page wrote:
> Often it is beneficial to review one's schema with a view to removing
> indexes (and sometimes tables) that are no longer required. It's very
> difficult to understand when that is the case by looking at the number of
> scans of a relation as, for example, an index may be used infrequently but
> may be critical in those times when it is used.
> 
> The attached patch against HEAD adds optional tracking of the last scan
> time for relations. It updates pg_stat_*_tables with new last_seq_scan and
> last_idx_scan columns, and pg_stat_*_indexes with a last_idx_scan column to
> help with this.
> 
> Due to the use of gettimeofday(), those values are only maintained if a new
> GUC, track_scans, is set to on. By default, it is off.
> 
> I did run a 12 hour test to see what the performance impact is. pgbench was
> run with scale factor 10000 and 75 users across 4 identical bare metal
> machines running Rocky 8 in parallel which showed roughly a -2% average
> performance penalty against HEAD with track_scans enabled. Machines were
> PowerEdge R7525's with 128GB RAM, dual 16C/32T AMD 7302 CPUs, with the data
> directory on 6 x 800GB 12Gb/s SSD SAS drives in RAID 0. Kernel time source
> is tsc.
> 
>                HEAD               track_scans      Penalty (%)
> box1       19582.49735    19341.8881      -1.22869541
> box2       19936.55513    19928.07479    -0.04253664659
> box3       19631.78895    18649.64379    -5.002830696
> box4       19810.86767    19420.67192    -1.969604525
> Average 19740.42728    19335.06965    -2.05343896

Based on the size of those numbers this was a r/w pgbench. If it has this
noticable an impact for r/w, with a pretty low number of scans/sec, how's the
overhead for r/o (which can have 2 orders of magnitude more scans/sec)? It
must be quite bad.

I don't think we should accept this feature with this overhead - but I also
think we can do better, by accepting a bit less accuracy. For this to be
useful we don't need a perfectly accurate timestamp. The statement start time
is probably not accurate enough, but we could just have bgwriter or such
update one in shared memory every time we wake up? Or perhaps we could go to
an even lower granularity, by putting in the current LSN or such?

Greetings,

Andres Freund

  14. Re: Tracking last scan time

    Matthias van de Meent <boekewurm+postgres@gmail.com> — 2022-08-31T17:52:49Z

    On Wed, 31 Aug 2022 at 18:21, Andres Freund <andres@anarazel.de> wrote:
>
> Hi,
>
> On 2022-08-23 10:55:09 +0100, Dave Page wrote:
> > Often it is beneficial to review one's schema with a view to removing
> > indexes (and sometimes tables) that are no longer required. It's very
> > difficult to understand when that is the case by looking at the number of
> > scans of a relation as, for example, an index may be used infrequently but
> > may be critical in those times when it is used.
> >
> > The attached patch against HEAD adds optional tracking of the last scan
> > time for relations. It updates pg_stat_*_tables with new last_seq_scan and
> > last_idx_scan columns, and pg_stat_*_indexes with a last_idx_scan column to
> > help with this.
> >
> > Due to the use of gettimeofday(), those values are only maintained if a new
> > GUC, track_scans, is set to on. By default, it is off.
> >
> > I did run a 12 hour test to see what the performance impact is. pgbench was
> > run with scale factor 10000 and 75 users across 4 identical bare metal
> > machines running Rocky 8 in parallel which showed roughly a -2% average
> > performance penalty against HEAD with track_scans enabled. Machines were
> > PowerEdge R7525's with 128GB RAM, dual 16C/32T AMD 7302 CPUs, with the data
> > directory on 6 x 800GB 12Gb/s SSD SAS drives in RAID 0. Kernel time source
> > is tsc.
> >
> >                HEAD               track_scans      Penalty (%)
> > box1       19582.49735    19341.8881      -1.22869541
> > box2       19936.55513    19928.07479    -0.04253664659
> > box3       19631.78895    18649.64379    -5.002830696
> > box4       19810.86767    19420.67192    -1.969604525
> > Average 19740.42728    19335.06965    -2.05343896
>
> Based on the size of those numbers this was a r/w pgbench. If it has this
> noticable an impact for r/w, with a pretty low number of scans/sec, how's the
> overhead for r/o (which can have 2 orders of magnitude more scans/sec)? It
> must be quite bad.
>
> I don't think we should accept this feature with this overhead - but I also
> think we can do better, by accepting a bit less accuracy. For this to be
> useful we don't need a perfectly accurate timestamp. The statement start time
> is probably not accurate enough, but we could just have bgwriter or such
> update one in shared memory every time we wake up? Or perhaps we could go to
> an even lower granularity, by putting in the current LSN or such?

I don't think that LSN is precise enough. For example, if you're in a
(mostly) read-only system, the system may go long times without any
meaningful records being written.

As for having a lower granularity and preventing the
one-syscall-per-Relation issue, can't we reuse the query_start or
state_change timestamps that appear in pg_stat_activity (potentially
updated immediately before this stat flush), or some other per-backend
timestamp that is already maintained and considered accurate enough
for this use?
Regardless, with this patch as it is we get a new timestamp for each
relation processed, which I think is a waste of time (heh) even in
VDSO-enabled systems.

Apart from the above, I don't have any other meaningful opinion on
this patch - it might be a good addition, but I don't consume stats
often enough to make a good cost / benefit comparison.

Kind regards,

Matthias van de Meent

  15. Re: Tracking last scan time

    Bruce Momjian <bruce@momjian.us> — 2022-08-31T18:11:11Z

    On Wed, Aug 31, 2022 at 07:52:49PM +0200, Matthias van de Meent wrote:
> As for having a lower granularity and preventing the
> one-syscall-per-Relation issue, can't we reuse the query_start or
> state_change timestamps that appear in pg_stat_activity (potentially

Yeah, query start should be fine, but not transaction start time.

-- 
  Bruce Momjian  <bruce@momjian.us>        https://momjian.us
  EDB                                      https://enterprisedb.com

  Indecision is a decision.  Inaction is an action.  Mark Batterson

  16. Re: Tracking last scan time

    Andres Freund <andres@anarazel.de> — 2022-08-31T18:56:29Z

    Hi,

On 2022-08-31 19:52:49 +0200, Matthias van de Meent wrote:
> As for having a lower granularity and preventing the
> one-syscall-per-Relation issue, can't we reuse the query_start or
> state_change timestamps that appear in pg_stat_activity (potentially
> updated immediately before this stat flush), or some other per-backend
> timestamp that is already maintained and considered accurate enough
> for this use?

The problem is that it won't change at all for a query that runs for a week -
and we'll report the timestamp from a week ago when it finally ends.

But given this is done when stats are flushed, which only happens after the
transaction ended, we can just use GetCurrentTransactionStopTimestamp() - if
we got to flushing the transaction stats we'll already have computed that.


>  	tabentry->numscans += lstats->t_counts.t_numscans;
> +	if (pgstat_track_scans && lstats->t_counts.t_numscans)
> +		tabentry->lastscan = GetCurrentTimestamp();

Besides replacing GetCurrentTimestamp() with
GetCurrentTransactionStopTimestamp(), this should then also check if
tabentry->lastscan is already newer than the new timestamp.

Greetings,

Andres Freund

  17. Re: Tracking last scan time

    Bruce Momjian <bruce@momjian.us> — 2022-08-31T19:17:57Z

    On Wed, Aug 31, 2022 at 11:56:29AM -0700, Andres Freund wrote:
> Hi,
> 
> On 2022-08-31 19:52:49 +0200, Matthias van de Meent wrote:
> > As for having a lower granularity and preventing the
> > one-syscall-per-Relation issue, can't we reuse the query_start or
> > state_change timestamps that appear in pg_stat_activity (potentially
> > updated immediately before this stat flush), or some other per-backend
> > timestamp that is already maintained and considered accurate enough
> > for this use?
> 
> The problem is that it won't change at all for a query that runs for a week -
> and we'll report the timestamp from a week ago when it finally ends.
> 
> But given this is done when stats are flushed, which only happens after the
> transaction ended, we can just use GetCurrentTransactionStopTimestamp() - if
> we got to flushing the transaction stats we'll already have computed that.

Oh, good point --- it is safer to show a more recent time than a too-old
time.

-- 
  Bruce Momjian  <bruce@momjian.us>        https://momjian.us
  EDB                                      https://enterprisedb.com

  Indecision is a decision.  Inaction is an action.  Mark Batterson

  18. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-09-01T08:46:59Z

    On Wed, 31 Aug 2022 at 17:13, Bruce Momjian <bruce@momjian.us> wrote:

> On Wed, Aug 31, 2022 at 05:02:33PM +0100, Dave Page wrote:
> >
> >
> > On Tue, 30 Aug 2022 at 19:46, Bruce Momjian <bruce@momjian.us> wrote:
> >
> >     On Fri, Aug 26, 2022 at 02:05:36PM +0100, Dave Page wrote:
> >     > On Thu, 25 Aug 2022 at 01:44, David Rowley <dgrowleyml@gmail.com>
> wrote:
> >     >     I don't have a particular opinion about the patch, I'm just
> pointing
> >     >     out that there are other ways. Even just writing down the
> numbers on
> >     a
> >     >     post-it note and coming back in a month to see if they've
> changed is
> >     >     enough to tell if the table or index has been used.
> >     >
> >     >
> >     > There are usually other ways to perform monitoring tasks, but
> there is
> >     > something to be said for the convenience of having functionality
> built in
> >     and
> >     > not having to rely on tools, scripts, or post-it notes :-)
> >
> >     Should we consider using something cheaper like time() so we don't
> need
> >     a GUC to enable this?
> >
> >
> > Interesting idea, but on my mac at least, 100,000,000 gettimeofday()
> calls
> > takes about 2 seconds, whilst 100,000,000 time() calls takes 14(!)
> seconds.
>
> Wow.  I was just thinking you need second-level accuracy, which must be
> cheap somewhere.
>

Second-level accuracy would indeed be fine for this. Frankly, for my use
case just the date would be enough, but I can imagine people wanting
greater accuracy than that.

And yes, I was very surprised by the timing results I got as well. I guess
it's a quirk of macOS - on a Linux box I get ~4s for gettimeofday() and ~1s
for time().

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  19. Re: Tracking last scan time

    Bruce Momjian <bruce@momjian.us> — 2022-09-01T12:03:59Z

    On Thu, Sep  1, 2022 at 09:46:59AM +0100, Dave Page wrote:
> On Wed, 31 Aug 2022 at 17:13, Bruce Momjian <bruce@momjian.us> wrote:
>     Wow.  I was just thinking you need second-level accuracy, which must be
>     cheap somewhere.
> 
> 
> Second-level accuracy would indeed be fine for this. Frankly, for my use case
> just the date would be enough, but I can imagine people wanting greater
> accuracy than that. 
> 
> And yes, I was very surprised by the timing results I got as well. I guess it's
> a quirk of macOS - on a Linux box I get ~4s for gettimeofday() and ~1s for time
> ().

i think we lose 95% of our users if we require it to be enabled so let's
work to find a way it can be always enabled.

-- 
  Bruce Momjian  <bruce@momjian.us>        https://momjian.us
  EDB                                      https://enterprisedb.com

  Indecision is a decision.  Inaction is an action.  Mark Batterson

  20. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-09-01T12:18:00Z

    On Thu, 1 Sept 2022 at 13:04, Bruce Momjian <bruce@momjian.us> wrote:

> On Thu, Sep  1, 2022 at 09:46:59AM +0100, Dave Page wrote:
> > On Wed, 31 Aug 2022 at 17:13, Bruce Momjian <bruce@momjian.us> wrote:
> >     Wow.  I was just thinking you need second-level accuracy, which must
> be
> >     cheap somewhere.
> >
> >
> > Second-level accuracy would indeed be fine for this. Frankly, for my use
> case
> > just the date would be enough, but I can imagine people wanting greater
> > accuracy than that.
> >
> > And yes, I was very surprised by the timing results I got as well. I
> guess it's
> > a quirk of macOS - on a Linux box I get ~4s for gettimeofday() and ~1s
> for time
> > ().
>
> i think we lose 95% of our users if we require it to be enabled so let's
> work to find a way it can be always enabled.
>

So based on Andres' suggestion, something like this seems like it might
work:

if (pgstat_track_scan_timestamps && lstats->t_counts.t_numscans)
{
    TimestampTz t = GetCurrentTransactionStopTimestamp();
    if (t > tabentry->lastscan)
        tabentry->lastscan = t;
}

If that seems like a good option, I can run some more benchmarks (and then
remove the GUC if it looks good).

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  21. Re: Tracking last scan time

    Matthias van de Meent <boekewurm+postgres@gmail.com> — 2022-09-01T12:18:42Z

    On Wed, 31 Aug 2022 at 20:56, Andres Freund <andres@anarazel.de> wrote:
>
> Hi,
>
> On 2022-08-31 19:52:49 +0200, Matthias van de Meent wrote:
> > As for having a lower granularity and preventing the
> > one-syscall-per-Relation issue, can't we reuse the query_start or
> > state_change timestamps that appear in pg_stat_activity (potentially
> > updated immediately before this stat flush), or some other per-backend
> > timestamp that is already maintained and considered accurate enough
> > for this use?
>
> The problem is that it won't change at all for a query that runs for a week -
> and we'll report the timestamp from a week ago when it finally ends.

This earlier proposal to reuse pg_stat_activity values is also invalid
because those timestamps don't exist when you SET track_activities =
OFF.

> But given this is done when stats are flushed, which only happens after the
> transaction ended, we can just use GetCurrentTransactionStopTimestamp() - if
> we got to flushing the transaction stats we'll already have computed that.

I'm not entirely happy with that, as that would still add function
call overhead, and potentially still call GetCurrentTimestamp() in
this somewhat hot loop.

As an alternative, we could wire the `now` variable in
pgstat_report_stat (generated from
GetCurrentTransactionStopTimestamp() into pgstat_flush_pending_entries
and then into flush_pending_cb (or, store this in a static variable)
so that we can reuse that value, saving any potential function call
overhead.

> >       tabentry->numscans += lstats->t_counts.t_numscans;
> > +     if (pgstat_track_scans && lstats->t_counts.t_numscans)
> > +             tabentry->lastscan = GetCurrentTimestamp();
>
> Besides replacing GetCurrentTimestamp() with
> GetCurrentTransactionStopTimestamp(), this should then also check if
> tabentry->lastscan is already newer than the new timestamp.

I wonder how important that is. This value only gets set in a stats
flush, which may skew the stat update by several seconds (up to
PGSTAT_MAX_INTERVAL). I don't expect concurrent flushes to take so
long that it will set the values to It is possible, but I think it is
extremely unlikely that this is going to be important when you
consider that these stat flushes are not expected to run for more than
1 second.

Kind regards,

Matthias van de Meent

  22. Re: Tracking last scan time

    Andres Freund <andres@anarazel.de> — 2022-09-01T18:35:40Z

    Hi,

On 2022-09-01 14:18:42 +0200, Matthias van de Meent wrote:
> On Wed, 31 Aug 2022 at 20:56, Andres Freund <andres@anarazel.de> wrote:
> > But given this is done when stats are flushed, which only happens after the
> > transaction ended, we can just use GetCurrentTransactionStopTimestamp() - if
> > we got to flushing the transaction stats we'll already have computed that.
> 
> I'm not entirely happy with that, as that would still add function
> call overhead, and potentially still call GetCurrentTimestamp() in
> this somewhat hot loop.

We already used GetCurrentTransactionStopTimestamp() (as you reference below)
before we get to this point, so I doubt that we'll ever call
GetCurrentTimestamp(). And it's hard to imagine that the function call
overhead of GetCurrentTransactionStopTimestamp() matters compared to acquiring
locks etc.


> As an alternative, we could wire the `now` variable in
> pgstat_report_stat (generated from
> GetCurrentTransactionStopTimestamp() into pgstat_flush_pending_entries
> and then into flush_pending_cb (or, store this in a static variable)
> so that we can reuse that value, saving any potential function call
> overhead.

Passing it in doesn't clearly seem an improvement, but I also don't have a
strong opinion on it. I am strongly against the static variable approach.


> > >       tabentry->numscans += lstats->t_counts.t_numscans;
> > > +     if (pgstat_track_scans && lstats->t_counts.t_numscans)
> > > +             tabentry->lastscan = GetCurrentTimestamp();
> >
> > Besides replacing GetCurrentTimestamp() with
> > GetCurrentTransactionStopTimestamp(), this should then also check if
> > tabentry->lastscan is already newer than the new timestamp.
> 
> I wonder how important that is. This value only gets set in a stats
> flush, which may skew the stat update by several seconds (up to
> PGSTAT_MAX_INTERVAL). I don't expect concurrent flushes to take so
> long that it will set the values to It is possible, but I think it is
> extremely unlikely that this is going to be important when you
> consider that these stat flushes are not expected to run for more than
> 1 second.

I think it'll be confusing if you have values going back and forth, even if
just by a little. And it's cheap to defend against, so why not just do that?


Greetings,

Andres Freund

  23. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-09-06T13:15:56Z

    Hi

On Thu, 1 Sept 2022 at 19:35, Andres Freund <andres@anarazel.de> wrote:

> Hi,
>
> On 2022-09-01 14:18:42 +0200, Matthias van de Meent wrote:
> > On Wed, 31 Aug 2022 at 20:56, Andres Freund <andres@anarazel.de> wrote:
> > > But given this is done when stats are flushed, which only happens
> after the
> > > transaction ended, we can just use
> GetCurrentTransactionStopTimestamp() - if
> > > we got to flushing the transaction stats we'll already have computed
> that.
> >
> > I'm not entirely happy with that, as that would still add function
> > call overhead, and potentially still call GetCurrentTimestamp() in
> > this somewhat hot loop.
>
> We already used GetCurrentTransactionStopTimestamp() (as you reference
> below)
> before we get to this point, so I doubt that we'll ever call
> GetCurrentTimestamp(). And it's hard to imagine that the function call
> overhead of GetCurrentTransactionStopTimestamp() matters compared to
> acquiring
> locks etc.


Vik and I looked at this a little, and found that we actually don't have
generally have GetCurrentTransactionStopTimestamp() at this point - a
simple 'select * from pg_class' will result in 9 passes of this code, none
of which have xactStopTimestamp != 0.

After discussing it a little, we came to the conclusion that for the stated
use case, xactStartTimestamp is actually accurate enough, provided that we
only ever update it with a newer value. It would only likely be in extreme
edge-cases where the difference between start and end transaction time
would have any bearing on whether or not one might drop a table/index for
lack of use.

Doing it this way also means we no longer need the GUC to enable the
feature, which as Bruce notes, is likely to lose 95% of users.

Updated patch attached:

- GUC removed.
- The timestamp recorded is xactStartTimestamp.
- Docs updated to make it clear we're recording transaction start time.

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  24. Re: Tracking last scan time

    Andres Freund <andres@anarazel.de> — 2022-09-06T15:53:25Z

    Hi,

On 2022-09-06 14:15:56 +0100, Dave Page wrote:
> Vik and I looked at this a little, and found that we actually don't have
> generally have GetCurrentTransactionStopTimestamp() at this point - a
> simple 'select * from pg_class' will result in 9 passes of this code, none
> of which have xactStopTimestamp != 0.

Huh, pgstat_report_stat() used GetCurrentTransactionStopTimestamp() has used
for a long time. Wonder when that was broken. Looks like it's set only when a
xid is assigned. We should fix this.


> After discussing it a little, we came to the conclusion that for the stated
> use case, xactStartTimestamp is actually accurate enough, provided that we
> only ever update it with a newer value. It would only likely be in extreme
> edge-cases where the difference between start and end transaction time
> would have any bearing on whether or not one might drop a table/index for
> lack of use.

I don't at all agree with this. Since we already use
GetCurrentTransactionStopTimestamp() in this path we should fix it.

Greetings,

Andres Freund

  25. Re: Tracking last scan time

    Kyotaro Horiguchi <horikyota.ntt@gmail.com> — 2022-09-07T08:58:22Z

    At Tue, 6 Sep 2022 08:53:25 -0700, Andres Freund <andres@anarazel.de> wrote in 
> Hi,
> 
> On 2022-09-06 14:15:56 +0100, Dave Page wrote:
> > Vik and I looked at this a little, and found that we actually don't have
> > generally have GetCurrentTransactionStopTimestamp() at this point - a
> > simple 'select * from pg_class' will result in 9 passes of this code, none
> > of which have xactStopTimestamp != 0.
> 
> Huh, pgstat_report_stat() used GetCurrentTransactionStopTimestamp() has used
> for a long time. Wonder when that was broken. Looks like it's set only when a
> xid is assigned. We should fix this.

/*
 *	GetCurrentTransactionStopTimestamp
 *
 * We return current time if the transaction stop time hasn't been set
 * (which can happen if we decide we don't need to log an XLOG record).

So, that seems like intentional since 2007 (957d08c81f).  It seems to
me that the patch assumes that the only other use of the timstamp is
pgstats and it didn't let GetCurrentTransactionStopTimestamp() set the
variable for future use.

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center

  26. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-09-07T10:03:56Z

    Hi

On Tue, 6 Sept 2022 at 16:53, Andres Freund <andres@anarazel.de> wrote:

> Hi,
>
> On 2022-09-06 14:15:56 +0100, Dave Page wrote:
> > Vik and I looked at this a little, and found that we actually don't have
> > generally have GetCurrentTransactionStopTimestamp() at this point - a
> > simple 'select * from pg_class' will result in 9 passes of this code,
> none
> > of which have xactStopTimestamp != 0.
>
> Huh, pgstat_report_stat() used GetCurrentTransactionStopTimestamp() has
> used
> for a long time. Wonder when that was broken. Looks like it's set only
> when a
> xid is assigned. We should fix this.
>
>
> > After discussing it a little, we came to the conclusion that for the
> stated
> > use case, xactStartTimestamp is actually accurate enough, provided that
> we
> > only ever update it with a newer value. It would only likely be in
> extreme
> > edge-cases where the difference between start and end transaction time
> > would have any bearing on whether or not one might drop a table/index for
> > lack of use.
>
> I don't at all agree with this. Since we already use
> GetCurrentTransactionStopTimestamp() in this path we should fix it.
>

I just spent some time looking at this, and as far as I can see, we only
set xactStopTimestamp if the transaction needs to be WAL logged (and in
those cases, it is set before the stats callback runs). As you note though,
we are already calling GetCurrentTransactionStopTimestamp() in the
read-only case anyway, and thus already incurring the cost of
gettimeofday().

Here's a v4 patch. This reverts to using
GetCurrentTransactionStopTimestamp() for the last_scan times, and will
set xactStopTimestamp the first time GetCurrentTransactionStopTimestamp()
is called, thus avoiding multiple gettimeofday() calls.
SetCurrentTransactionStopTimestamp() is removed, as is use
of xactStopTimestamp (except when resetting it to 0).

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  27. Re: Tracking last scan time

    Vik Fearing <vik@postgresfriends.org> — 2022-09-30T15:58:31Z

    On 9/7/22 12:03, Dave Page wrote:
> Here's a v4 patch. This reverts to using
> GetCurrentTransactionStopTimestamp() for the last_scan times, and will
> set xactStopTimestamp the first time GetCurrentTransactionStopTimestamp()
> is called, thus avoiding multiple gettimeofday() calls.
> SetCurrentTransactionStopTimestamp() is removed, as is use
> of xactStopTimestamp (except when resetting it to 0).

This patch looks good to me and has much saner behavior than what it 
replaces.

As a matter of process, the oid for the new function should be in the 
8000-9000 range and the catversion should be bumped by the committer.

Marked as Ready for Committer.  Thanks for the patch!
-- 
Vik Fearing

  28. Re: Tracking last scan time

    Andres Freund <andres@anarazel.de> — 2022-09-30T17:58:06Z

    Hi,

On 2022-09-30 17:58:31 +0200, Vik Fearing wrote:
> On 9/7/22 12:03, Dave Page wrote:
> > Here's a v4 patch. This reverts to using
> > GetCurrentTransactionStopTimestamp() for the last_scan times, and will
> > set xactStopTimestamp the first time GetCurrentTransactionStopTimestamp()
> > is called, thus avoiding multiple gettimeofday() calls.
> > SetCurrentTransactionStopTimestamp() is removed, as is use
> > of xactStopTimestamp (except when resetting it to 0).
> 
> This patch looks good to me and has much saner behavior than what it
> replaces.

I agree. However, it seems like a significant enough behavioural change that
I'd rather commit it as a separate patch.  I agree with Vik's judgement that
the patch otherwise is otherwise ready. Happy to do that split myself, or you
can do it...

Greetings,

Andres Freund

  29. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-10-03T11:55:40Z

    Hi

On Fri, 30 Sept 2022 at 18:58, Andres Freund <andres@anarazel.de> wrote:

> Hi,
>
> On 2022-09-30 17:58:31 +0200, Vik Fearing wrote:
> > On 9/7/22 12:03, Dave Page wrote:
> > > Here's a v4 patch. This reverts to using
> > > GetCurrentTransactionStopTimestamp() for the last_scan times, and will
> > > set xactStopTimestamp the first time
> GetCurrentTransactionStopTimestamp()
> > > is called, thus avoiding multiple gettimeofday() calls.
> > > SetCurrentTransactionStopTimestamp() is removed, as is use
> > > of xactStopTimestamp (except when resetting it to 0).
> >
> > This patch looks good to me and has much saner behavior than what it
> > replaces.
>
> I agree. However, it seems like a significant enough behavioural change
> that
> I'd rather commit it as a separate patch.  I agree with Vik's judgement
> that
> the patch otherwise is otherwise ready. Happy to do that split myself, or
> you
> can do it...
>

Thanks. It's just the changes in xact.c, so it doesn't seem like it would
cause you any more work either way, in which case, I'll leave it to you :-)

FYI, the OID I chose was simply the closest single value to those used for
the other related functions (e.g. pg_stat_get_numscans). Seemed like a good
way to use up one more random unused value, but I don't care if it gets
changed to the 8000+ range.

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  30. Re: Tracking last scan time

    Michael Paquier <michael@paquier.xyz> — 2022-10-12T06:40:21Z

    On Mon, Oct 03, 2022 at 12:55:40PM +0100, Dave Page wrote:
> Thanks. It's just the changes in xact.c, so it doesn't seem like it would
> cause you any more work either way, in which case, I'll leave it to you :-)

Okay, I have just moved the patch to the next CF then, still marked as
ready for committer.  Are you planning to look at that?
--
Michael

  31. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-10-12T08:09:46Z

    On Wed, 12 Oct 2022 at 07:40, Michael Paquier <michael@paquier.xyz> wrote:

> On Mon, Oct 03, 2022 at 12:55:40PM +0100, Dave Page wrote:
> > Thanks. It's just the changes in xact.c, so it doesn't seem like it would
> > cause you any more work either way, in which case, I'll leave it to you
> :-)
>
> Okay, I have just moved the patch to the next CF then, still marked as
> ready for committer.  Are you planning to look at that?
>

Thanks. Was the question directed at me or Andres?

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  32. Re: Tracking last scan time

    Michael Paquier <michael@paquier.xyz> — 2022-10-12T08:15:30Z

    On Wed, Oct 12, 2022 at 09:09:46AM +0100, Dave Page wrote:
> On Wed, 12 Oct 2022 at 07:40, Michael Paquier <michael@paquier.xyz> wrote:
>> Okay, I have just moved the patch to the next CF then, still marked as
>> ready for committer.  Are you planning to look at that?
>
> Thanks. Was the question directed at me or Andres?

Apologies for the confusion.  This question is addressed to Andres.
--
Michael

  33. Re: Tracking last scan time

    Andres Freund <andres@anarazel.de> — 2022-10-12T19:50:31Z

    Hi,

On 2022-10-12 15:40:21 +0900, Michael Paquier wrote:
> On Mon, Oct 03, 2022 at 12:55:40PM +0100, Dave Page wrote:
> > Thanks. It's just the changes in xact.c, so it doesn't seem like it would
> > cause you any more work either way, in which case, I'll leave it to you :-)
> 
> Okay, I have just moved the patch to the next CF then, still marked as
> ready for committer.  Are you planning to look at that?

Yep, doing so right now.

I think this should have at a basic test in src/test/regress/sql/stats.sql. If
I can write one in a few minutes I'll go for that, otherwise will reply
detailing difficulties.


> +      <para>
> +       The time of the last sequential scan of this table, based on the
> +       most recent transaction stop time
> +      </para></entry>

Related rows seem to say "on this table".

Greetings,

Andres Freund

  34. Re: Tracking last scan time

    Andres Freund <andres@anarazel.de> — 2022-10-12T22:52:36Z

    Hi,

On 2022-10-12 12:50:31 -0700, Andres Freund wrote:
> I think this should have at a basic test in src/test/regress/sql/stats.sql. If
> I can write one in a few minutes I'll go for that, otherwise will reply
> detailing difficulties.

Took a bit longer (+lunch). Attached.


In the attached 0001, the patch to make GetCurrentTransactionStopTimestamp()
set xactStopTimestamp, I added a few comment updates and an Assert() to ensure
that CurrentTransactionState->state is TRANS_(DEFAULT|COMMIT|ABORT|PREPARE). I
am worried that otherwise we might end up with someone ending up using it in a
place before the end of the transaction, which'd then end up recording the
wrong timestamp in the commit/abort record.


For 0002, the commit adding lastscan, I added catversion/stats version bumps
(because I was planning to commit it already...), a commit message, and that
minor docs change mentioned earlier.


0003 adds the tests mentioned above. I plan to merge them with 0002, but left
them separate for easier review for now.

To be able to compare timestamps for > not just >= we need to make sure that
two subsequent timestamps differ. The attached achieves this by sleeping for
100ms between those points - we do that in other places already. I'd started
out with 10ms, which I am fairly sure would suffice, but then deciced to copy
the existing 100ms sleeps.

I verified tests pass under valgrind, debug_discard_caches and after I make
pgstat_report_stat() only flush when force is passed in.

Greetings,

Andres Freund

  35. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-10-13T13:38:06Z

    Hi

On Wed, 12 Oct 2022 at 23:52, Andres Freund <andres@anarazel.de> wrote:

> Hi,
>
> On 2022-10-12 12:50:31 -0700, Andres Freund wrote:
> > I think this should have at a basic test in
> src/test/regress/sql/stats.sql. If
> > I can write one in a few minutes I'll go for that, otherwise will reply
> > detailing difficulties.
>
> Took a bit longer (+lunch). Attached.
>
>
> In the attached 0001, the patch to make
> GetCurrentTransactionStopTimestamp()
> set xactStopTimestamp, I added a few comment updates and an Assert() to
> ensure
> that CurrentTransactionState->state is
> TRANS_(DEFAULT|COMMIT|ABORT|PREPARE). I
> am worried that otherwise we might end up with someone ending up using it
> in a
> place before the end of the transaction, which'd then end up recording the
> wrong timestamp in the commit/abort record.
>
>
> For 0002, the commit adding lastscan, I added catversion/stats version
> bumps
> (because I was planning to commit it already...), a commit message, and
> that
> minor docs change mentioned earlier.
>
>
> 0003 adds the tests mentioned above. I plan to merge them with 0002, but
> left
> them separate for easier review for now.
>
> To be able to compare timestamps for > not just >= we need to make sure
> that
> two subsequent timestamps differ. The attached achieves this by sleeping
> for
> 100ms between those points - we do that in other places already. I'd
> started
> out with 10ms, which I am fairly sure would suffice, but then deciced to
> copy
> the existing 100ms sleeps.
>
> I verified tests pass under valgrind, debug_discard_caches and after I make
> pgstat_report_stat() only flush when force is passed in.
>

Thanks for that. It looks good to me, bar one comment (repeated 3 times in
the sql and expected files):

fetch timestamps from before the next test

"from " should be removed.

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  36. Re: Tracking last scan time

    Andres Freund <andres@anarazel.de> — 2022-10-14T18:16:38Z

    Hi,

On 2022-10-13 14:38:06 +0100, Dave Page wrote:
> Thanks for that. It looks good to me, bar one comment (repeated 3 times in
> the sql and expected files):
> 
> fetch timestamps from before the next test
> 
> "from " should be removed.

I was trying to say something with that from, but clearly it wasn't
understandable :). Removed.

With that I pushed the changes and marked the CF entry as committed.

Thanks for the feature Dave and the reviews everyone.

Greetings,

Andres Freund

  37. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-10-14T18:54:46Z

    On Fri, 14 Oct 2022 at 19:16, Andres Freund <andres@anarazel.de> wrote:

> Hi,
>
> On 2022-10-13 14:38:06 +0100, Dave Page wrote:
> > Thanks for that. It looks good to me, bar one comment (repeated 3 times
> in
> > the sql and expected files):
> >
> > fetch timestamps from before the next test
> >
> > "from " should be removed.
>
> I was trying to say something with that from, but clearly it wasn't
> understandable :). Removed.
>
> With that I pushed the changes and marked the CF entry as committed.


Thanks!


> --
-- 
Dave Page
https://pgsnake.blogspot.com

EDB Postgres
https://www.enterprisedb.com

  38. Re: Tracking last scan time

    Robert Treat <rob@xzilla.net> — 2022-10-23T20:09:44Z

    On Fri, Oct 14, 2022 at 2:55 PM Dave Page <dpage@pgadmin.org> wrote:
> On Fri, 14 Oct 2022 at 19:16, Andres Freund <andres@anarazel.de> wrote:
>> On 2022-10-13 14:38:06 +0100, Dave Page wrote:
>> > Thanks for that. It looks good to me, bar one comment (repeated 3 times in
>> > the sql and expected files):
>> >
>> > fetch timestamps from before the next test
>> >
>> > "from " should be removed.
>>
>> I was trying to say something with that from, but clearly it wasn't
>> understandable :). Removed.
>>
>> With that I pushed the changes and marked the CF entry as committed.
>
>
> Thanks!
>

Hey folks,

I was looking at this a bit further (great addition btw) and noticed
the following behavior (this is a mre of the original testing that
uncovered this):

pagila=# select * from pg_stat_user_tables ;
 relid | schemaname | relname | seq_scan | last_seq_scan |
seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
autovacuum_count | analyze_count | autoanalyze_count
-------+------------+---------+----------+---------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
(0 rows)

pagila=# create table x (xx int);
CREATE TABLE
Time: 2.145 ms
pagila=# select * from pg_stat_user_tables ;
 relid | schemaname | relname | seq_scan | last_seq_scan |
seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
autovacuum_count | analyze_count | autoanalyze_count
-------+------------+---------+----------+---------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
 16392 | public     | x       |        0 | [null]        |
0 |   [null] | [null]        |        [null] |         0 |         0 |
        0 |             0 |          0 |          0 |
 0 |                  0 | [null]      | [null]          | [null]
| [null]           |            0 |                0 |             0 |
                0
(1 row)

pagila=# insert into x select 1;
INSERT 0 1
pagila=# select * from pg_stat_user_tables ;
 relid | schemaname | relname | seq_scan |     last_seq_scan      |
seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
autovacuum_count | analyze_count | autoanalyze_count
-------+------------+---------+----------+------------------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
 16392 | public     | x       |        0 | 1999-12-31 19:00:00-05 |
        0 |   [null] | [null]        |        [null] |         1 |
    0 |         0 |             0 |          1 |          0 |
         1 |                  1 | [null]      | [null]          |
[null]       | [null]           |            0 |                0 |
         0 |                 0
(1 row)

Normally we populate "last" columns with a NULL value when the
corresponding marker is zero, which seems correct in the first query,
but no longer matches in the second. I can see an argument that this
is a necessary exception to that rule (I'm not sure I agree with it,
but I see it) but even in that scenario, ISTM we should avoid
populating the table with a "special value", which generally goes
against observability best practices, and I believe we've been able to
avoid it elsewhere.

Beyond that, I also notice the behavior changes when adding a table
with a PK, though not necessarily better...

pagila=# drop table x;
DROP TABLE
Time: 2.896 ms
pagila=# select * from pg_stat_user_tables ;
 relid | schemaname | relname | seq_scan | last_seq_scan |
seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
autovacuum_count | analyze_count | autoanalyze_count
-------+------------+---------+----------+---------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
(0 rows)

pagila=# create table x (xx int primary key) ;
CREATE TABLE

pagila=# select * from pg_stat_user_tables ;
 relid | schemaname | relname | seq_scan |         last_seq_scan
  | seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch |
n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup |
n_dead_tup | n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
autovacuum_count | analyze_count | autoanalyze_count
-------+------------+---------+----------+-------------------------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
 16400 | public     | x       |        1 | 2022-10-23
15:53:04.935192-04 |            0 |        0 | [null]        |
    0 |         0 |         0 |         0 |             0 |          0
|          0 |                   0 |                  0 | [null]
| [null]          | [null]       | [null]           |            0 |
             0 |             0 |                 0
(1 row)

pagila=# insert into x select 1;
INSERT 0 1

pagila=# select * from pg_stat_user_tables ;
 relid | schemaname | relname | seq_scan |         last_seq_scan
  | seq_tup_read | idx_scan |     last_idx_scan      | idx_tup_fetch |
n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup |
n_dead_tup | n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
autovacuum_count | analyze_count | autoanalyze_count
-------+------------+---------+----------+-------------------------------+--------------+----------+------------------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
 16400 | public     | x       |        1 | 2022-10-23
15:53:04.935192-04 |            0 |        0 | 1999-12-31 19:00:00-05
|             0 |         1 |         0 |         0 |             0 |
        1 |          0 |                   1 |                  1 |
[null]      | [null]          | [null]       | [null]           |
      0 |                0 |             0 |                 0
(1 row)

This time the create table both populate a sequential scan and
populates the last_seq_scan with a real/correct value. However an
insert into the table neither advances the seq_scan nor the
last_seq_scan values which seems like different behavior from my
original example, with the added negative that the last_idx_scan is
now populated with a special value :-(

I think the simplest fix which should correspond to existing versions
behavior would be to just ensure that we replace any "special value"
timestamps with a real transaction timestamp, and then maybe note that
these fields may be advanced by operations which don't strictly show
up as a sequential or index scan.


Robert Treat
https://xzilla.net

  39. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-10-31T11:36:51Z

    FYI, this is not intentional, and I do plan to look into it, however I've
been somewhat busy with pgconfeu, and am travelling for the rest of this
week as well.

On Sun, 23 Oct 2022 at 21:09, Robert Treat <rob@xzilla.net> wrote:

> On Fri, Oct 14, 2022 at 2:55 PM Dave Page <dpage@pgadmin.org> wrote:
> > On Fri, 14 Oct 2022 at 19:16, Andres Freund <andres@anarazel.de> wrote:
> >> On 2022-10-13 14:38:06 +0100, Dave Page wrote:
> >> > Thanks for that. It looks good to me, bar one comment (repeated 3
> times in
> >> > the sql and expected files):
> >> >
> >> > fetch timestamps from before the next test
> >> >
> >> > "from " should be removed.
> >>
> >> I was trying to say something with that from, but clearly it wasn't
> >> understandable :). Removed.
> >>
> >> With that I pushed the changes and marked the CF entry as committed.
> >
> >
> > Thanks!
> >
>
> Hey folks,
>
> I was looking at this a bit further (great addition btw) and noticed
> the following behavior (this is a mre of the original testing that
> uncovered this):
>
> pagila=# select * from pg_stat_user_tables ;
>  relid | schemaname | relname | seq_scan | last_seq_scan |
> seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
> n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
> n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
> autovacuum_count | analyze_count | autoanalyze_count
>
> -------+------------+---------+----------+---------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
> (0 rows)
>
> pagila=# create table x (xx int);
> CREATE TABLE
> Time: 2.145 ms
> pagila=# select * from pg_stat_user_tables ;
>  relid | schemaname | relname | seq_scan | last_seq_scan |
> seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
> n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
> n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
> autovacuum_count | analyze_count | autoanalyze_count
>
> -------+------------+---------+----------+---------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>  16392 | public     | x       |        0 | [null]        |
> 0 |   [null] | [null]        |        [null] |         0 |         0 |
>         0 |             0 |          0 |          0 |
>  0 |                  0 | [null]      | [null]          | [null]
> | [null]           |            0 |                0 |             0 |
>                 0
> (1 row)
>
> pagila=# insert into x select 1;
> INSERT 0 1
> pagila=# select * from pg_stat_user_tables ;
>  relid | schemaname | relname | seq_scan |     last_seq_scan      |
> seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
> n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
> n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
> autovacuum_count | analyze_count | autoanalyze_count
>
> -------+------------+---------+----------+------------------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>  16392 | public     | x       |        0 | 1999-12-31 19:00:00-05 |
>         0 |   [null] | [null]        |        [null] |         1 |
>     0 |         0 |             0 |          1 |          0 |
>          1 |                  1 | [null]      | [null]          |
> [null]       | [null]           |            0 |                0 |
>          0 |                 0
> (1 row)
>
> Normally we populate "last" columns with a NULL value when the
> corresponding marker is zero, which seems correct in the first query,
> but no longer matches in the second. I can see an argument that this
> is a necessary exception to that rule (I'm not sure I agree with it,
> but I see it) but even in that scenario, ISTM we should avoid
> populating the table with a "special value", which generally goes
> against observability best practices, and I believe we've been able to
> avoid it elsewhere.
>
> Beyond that, I also notice the behavior changes when adding a table
> with a PK, though not necessarily better...
>
> pagila=# drop table x;
> DROP TABLE
> Time: 2.896 ms
> pagila=# select * from pg_stat_user_tables ;
>  relid | schemaname | relname | seq_scan | last_seq_scan |
> seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
> n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
> n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
> autovacuum_count | analyze_count | autoanalyze_count
>
> -------+------------+---------+----------+---------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
> (0 rows)
>
> pagila=# create table x (xx int primary key) ;
> CREATE TABLE
>
> pagila=# select * from pg_stat_user_tables ;
>  relid | schemaname | relname | seq_scan |         last_seq_scan
>   | seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch |
> n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup |
> n_dead_tup | n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
> autovacuum_count | analyze_count | autoanalyze_count
>
> -------+------------+---------+----------+-------------------------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>  16400 | public     | x       |        1 | 2022-10-23
> 15:53:04.935192-04 |            0 |        0 | [null]        |
>     0 |         0 |         0 |         0 |             0 |          0
> |          0 |                   0 |                  0 | [null]
> | [null]          | [null]       | [null]           |            0 |
>              0 |             0 |                 0
> (1 row)
>
> pagila=# insert into x select 1;
> INSERT 0 1
>
> pagila=# select * from pg_stat_user_tables ;
>  relid | schemaname | relname | seq_scan |         last_seq_scan
>   | seq_tup_read | idx_scan |     last_idx_scan      | idx_tup_fetch |
> n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup |
> n_dead_tup | n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
> autovacuum_count | analyze_count | autoanalyze_count
>
> -------+------------+---------+----------+-------------------------------+--------------+----------+------------------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>  16400 | public     | x       |        1 | 2022-10-23
> 15:53:04.935192-04 |            0 |        0 | 1999-12-31 19:00:00-05
> |             0 |         1 |         0 |         0 |             0 |
>         1 |          0 |                   1 |                  1 |
> [null]      | [null]          | [null]       | [null]           |
>       0 |                0 |             0 |                 0
> (1 row)
>
> This time the create table both populate a sequential scan and
> populates the last_seq_scan with a real/correct value. However an
> insert into the table neither advances the seq_scan nor the
> last_seq_scan values which seems like different behavior from my
> original example, with the added negative that the last_idx_scan is
> now populated with a special value :-(
>
> I think the simplest fix which should correspond to existing versions
> behavior would be to just ensure that we replace any "special value"
> timestamps with a real transaction timestamp, and then maybe note that
> these fields may be advanced by operations which don't strictly show
> up as a sequential or index scan.
>
>
> Robert Treat
> https://xzilla.net
>


-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  40. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-11-03T20:44:16Z

    On Mon, 31 Oct 2022 at 07:36, Dave Page <dpage@pgadmin.org> wrote:

> FYI, this is not intentional, and I do plan to look into it, however I've
> been somewhat busy with pgconfeu, and am travelling for the rest of this
> week as well.
>

Here's a patch to fix this issue. Many thanks to Peter Eisentraut who
figured it out in a few minutes after I spent far too long looking down
rabbit holes in entirely the wrong place.

Thanks for the bug report.


>
> On Sun, 23 Oct 2022 at 21:09, Robert Treat <rob@xzilla.net> wrote:
>
>> On Fri, Oct 14, 2022 at 2:55 PM Dave Page <dpage@pgadmin.org> wrote:
>> > On Fri, 14 Oct 2022 at 19:16, Andres Freund <andres@anarazel.de> wrote:
>> >> On 2022-10-13 14:38:06 +0100, Dave Page wrote:
>> >> > Thanks for that. It looks good to me, bar one comment (repeated 3
>> times in
>> >> > the sql and expected files):
>> >> >
>> >> > fetch timestamps from before the next test
>> >> >
>> >> > "from " should be removed.
>> >>
>> >> I was trying to say something with that from, but clearly it wasn't
>> >> understandable :). Removed.
>> >>
>> >> With that I pushed the changes and marked the CF entry as committed.
>> >
>> >
>> > Thanks!
>> >
>>
>> Hey folks,
>>
>> I was looking at this a bit further (great addition btw) and noticed
>> the following behavior (this is a mre of the original testing that
>> uncovered this):
>>
>> pagila=# select * from pg_stat_user_tables ;
>>  relid | schemaname | relname | seq_scan | last_seq_scan |
>> seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
>> n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
>> n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
>> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
>> autovacuum_count | analyze_count | autoanalyze_count
>>
>> -------+------------+---------+----------+---------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>> (0 rows)
>>
>> pagila=# create table x (xx int);
>> CREATE TABLE
>> Time: 2.145 ms
>> pagila=# select * from pg_stat_user_tables ;
>>  relid | schemaname | relname | seq_scan | last_seq_scan |
>> seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
>> n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
>> n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
>> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
>> autovacuum_count | analyze_count | autoanalyze_count
>>
>> -------+------------+---------+----------+---------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>>  16392 | public     | x       |        0 | [null]        |
>> 0 |   [null] | [null]        |        [null] |         0 |         0 |
>>         0 |             0 |          0 |          0 |
>>  0 |                  0 | [null]      | [null]          | [null]
>> | [null]           |            0 |                0 |             0 |
>>                 0
>> (1 row)
>>
>> pagila=# insert into x select 1;
>> INSERT 0 1
>> pagila=# select * from pg_stat_user_tables ;
>>  relid | schemaname | relname | seq_scan |     last_seq_scan      |
>> seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
>> n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
>> n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
>> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
>> autovacuum_count | analyze_count | autoanalyze_count
>>
>> -------+------------+---------+----------+------------------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>>  16392 | public     | x       |        0 | 1999-12-31 19:00:00-05 |
>>         0 |   [null] | [null]        |        [null] |         1 |
>>     0 |         0 |             0 |          1 |          0 |
>>          1 |                  1 | [null]      | [null]          |
>> [null]       | [null]           |            0 |                0 |
>>          0 |                 0
>> (1 row)
>>
>> Normally we populate "last" columns with a NULL value when the
>> corresponding marker is zero, which seems correct in the first query,
>> but no longer matches in the second. I can see an argument that this
>> is a necessary exception to that rule (I'm not sure I agree with it,
>> but I see it) but even in that scenario, ISTM we should avoid
>> populating the table with a "special value", which generally goes
>> against observability best practices, and I believe we've been able to
>> avoid it elsewhere.
>>
>> Beyond that, I also notice the behavior changes when adding a table
>> with a PK, though not necessarily better...
>>
>> pagila=# drop table x;
>> DROP TABLE
>> Time: 2.896 ms
>> pagila=# select * from pg_stat_user_tables ;
>>  relid | schemaname | relname | seq_scan | last_seq_scan |
>> seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch | n_tup_ins |
>> n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |
>> n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
>> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
>> autovacuum_count | analyze_count | autoanalyze_count
>>
>> -------+------------+---------+----------+---------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>> (0 rows)
>>
>> pagila=# create table x (xx int primary key) ;
>> CREATE TABLE
>>
>> pagila=# select * from pg_stat_user_tables ;
>>  relid | schemaname | relname | seq_scan |         last_seq_scan
>>   | seq_tup_read | idx_scan | last_idx_scan | idx_tup_fetch |
>> n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup |
>> n_dead_tup | n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
>> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
>> autovacuum_count | analyze_count | autoanalyze_count
>>
>> -------+------------+---------+----------+-------------------------------+--------------+----------+---------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>>  16400 | public     | x       |        1 | 2022-10-23
>> 15:53:04.935192-04 |            0 |        0 | [null]        |
>>     0 |         0 |         0 |         0 |             0 |          0
>> |          0 |                   0 |                  0 | [null]
>> | [null]          | [null]       | [null]           |            0 |
>>              0 |             0 |                 0
>> (1 row)
>>
>> pagila=# insert into x select 1;
>> INSERT 0 1
>>
>> pagila=# select * from pg_stat_user_tables ;
>>  relid | schemaname | relname | seq_scan |         last_seq_scan
>>   | seq_tup_read | idx_scan |     last_idx_scan      | idx_tup_fetch |
>> n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup |
>> n_dead_tup | n_mod_since_analyze | n_ins_since_vacuum | last_vacuum |
>> last_autovacuum | last_analyze | last_autoanalyze | vacuum_count |
>> autovacuum_count | analyze_count | autoanalyze_count
>>
>> -------+------------+---------+----------+-------------------------------+--------------+----------+------------------------+---------------+-----------+-----------+-----------+---------------+------------+------------+---------------------+--------------------+-------------+-----------------+--------------+------------------+--------------+------------------+---------------+-------------------
>>  16400 | public     | x       |        1 | 2022-10-23
>> 15:53:04.935192-04 |            0 |        0 | 1999-12-31 19:00:00-05
>> |             0 |         1 |         0 |         0 |             0 |
>>         1 |          0 |                   1 |                  1 |
>> [null]      | [null]          | [null]       | [null]           |
>>       0 |                0 |             0 |                 0
>> (1 row)
>>
>> This time the create table both populate a sequential scan and
>> populates the last_seq_scan with a real/correct value. However an
>> insert into the table neither advances the seq_scan nor the
>> last_seq_scan values which seems like different behavior from my
>> original example, with the added negative that the last_idx_scan is
>> now populated with a special value :-(
>>
>> I think the simplest fix which should correspond to existing versions
>> behavior would be to just ensure that we replace any "special value"
>> timestamps with a real transaction timestamp, and then maybe note that
>> these fields may be advanced by operations which don't strictly show
>> up as a sequential or index scan.
>>
>>
>> Robert Treat
>> https://xzilla.net
>>
>
>
> --
> Dave Page
> Blog: https://pgsnake.blogspot.com
> Twitter: @pgsnake
>
> EDB: https://www.enterprisedb.com
>
>

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com

  41. Re: Tracking last scan time

    Michael Paquier <michael@paquier.xyz> — 2022-11-07T07:54:07Z

    On Thu, Nov 03, 2022 at 04:44:16PM -0400, Dave Page wrote:
> Here's a patch to fix this issue. Many thanks to Peter Eisentraut who
> figured it out in a few minutes after I spent far too long looking down
> rabbit holes in entirely the wrong place.

FWIW, all the other areas of pgstatfuncs.c manipulate timestamptz
fields with a style like the attached.  That's a nit, still per the
role of consistency with the surroundings..

Anyway, it seems to me that a regression test is in order before a
scan happens just after the relation creation, and the same problem
shows up with last_idx_scan.
--
Michael

  42. Re: Tracking last scan time

    Michael Paquier <michael@paquier.xyz> — 2022-11-08T04:09:59Z

    On Mon, Nov 07, 2022 at 04:54:07PM +0900, Michael Paquier wrote:
> FWIW, all the other areas of pgstatfuncs.c manipulate timestamptz
> fields with a style like the attached.  That's a nit, still per the
> role of consistency with the surroundings..
> 
> Anyway, it seems to me that a regression test is in order before a
> scan happens just after the relation creation, and the same problem
> shows up with last_idx_scan.

Hearing nothing, done this way as of d7744d5.  Thanks for the report,
Robert.  And thanks for the patch, Dave.
--
Michael

  43. Re: Tracking last scan time

    Dave Page <dpage@pgadmin.org> — 2022-11-08T09:25:25Z

    On Tue, 8 Nov 2022 at 04:10, Michael Paquier <michael@paquier.xyz> wrote:

> On Mon, Nov 07, 2022 at 04:54:07PM +0900, Michael Paquier wrote:
> > FWIW, all the other areas of pgstatfuncs.c manipulate timestamptz
> > fields with a style like the attached.  That's a nit, still per the
> > role of consistency with the surroundings..
> >
> > Anyway, it seems to me that a regression test is in order before a
> > scan happens just after the relation creation, and the same problem
> > shows up with last_idx_scan.
>
> Hearing nothing, done this way as of d7744d5.  Thanks for the report,
> Robert.  And thanks for the patch, Dave.
>

Thank you!

-- 
Dave Page
Blog: https://pgsnake.blogspot.com
Twitter: @pgsnake

EDB: https://www.enterprisedb.com