Thread: Is Autovacuum running?

Is Autovacuum running?

From
Brad White
Date:
I'm concerned that Autovacuum may not be running based on the results of this query.

SELECT relname, last_vacuum, last_autovacuum FROM pg_stat_user_tables;
gives 211 rows like this...
relname                    | last_vacuum | last_autovacuum
BusinessIncidentCategories | null | null
Valid Use                  | null | null
Serial Pool Part Types     | null | null
BusinessIncidentLog        | null | null
Rate Categories            | null | null


I don't see any process with 'auto' or 'vacuum' in the name in TaskManager.
I don't see anything similar set up in Services to run in the background.
I do see pg_ctl running for each instance of the server running, 9.4 and 14.

The settings look ok as far as I can tell.

SELECT name, setting FROM pg_settings WHERE name='autovacuum';
name       | setting
autovacuum | on

SELECT name, setting FROM pg_settings WHERE name='track_counts';
name         | setting
track_counts | on

SELECT relname, reloptions FROM pg_class;
These are not turned OFF, and I assume the default is ON.
relname               | reloptions
pg_statistic          | null
pg_type               | null
Activity Codes        | null
Activity Codes_ID_seq | null
......
 
SELECT * from pg_settings where category like 'Autovacuum';
autovacuumonAutovacuumStarts the autovacuum subprocess.sighupbooldefaultonon
autovacuum_analyze_scale_factor0.1AutovacuumNumber of tuple inserts, updates, or deletes prior to analyze as a fraction of reltuples.sighuprealdefault01000.10.1
autovacuum_analyze_threshold50AutovacuumMinimum number of tuple inserts, updates, or deletes prior to analyze.sighupintegerdefault02.15E+095050
autovacuum_freeze_max_age2E+08AutovacuumAge at which to autovacuum a table to prevent transaction ID wraparound.postmasterintegerdefault1E+082E+092E+082E+08
autovacuum_max_workers3AutovacuumSets the maximum number of simultaneously running autovacuum worker processes.postmasterintegerdefault1838860733
autovacuum_multixact_freeze_max_age4E+08AutovacuumMultixact age at which to autovacuum a table to prevent multixact wraparound.postmasterintegerdefault100000002E+094E+084E+08
autovacuum_naptime60sAutovacuumTime to sleep between autovacuum runs.sighupintegerdefault121474836060
autovacuum_vacuum_cost_delay20msAutovacuumVacuum cost delay in milliseconds, for autovacuum.sighupintegerdefault-11002020
autovacuum_vacuum_cost_limit-1AutovacuumVacuum cost amount available before napping, for autovacuum.sighupintegerdefault-110000-1-1
autovacuum_vacuum_scale_factor0.2AutovacuumNumber of tuple updates or deletes prior to vacuum as a fraction of reltuples.sighuprealdefault01000.20.2
autovacuum_vacuum_threshold50AutovacuumMinimum number of tuple updates or deletes prior to vacuum.sighupintegerdefault02.15E+095050
  

Re: Is Autovacuum running?

From
Brad White
Date:


On Mon, Feb 20, 2023 at 1:42 PM Brad White <b55white@gmail.com> wrote:
I'm concerned that Autovacuum may not be running based on the results of this query.

SELECT relname, last_vacuum, last_autovacuum FROM pg_stat_user_tables;
gives 211 rows like this...
relname                    | last_vacuum | last_autovacuum 
BusinessIncidentCategories | null | null
Valid Use                  | null | null
Serial Pool Part Types     | null | null
BusinessIncidentLog        | null | null
Rate Categories            | null | null



Any suggestions on how to proceed?

Thanks,
Brad. 

Re: Is Autovacuum running?

From
Christophe Pettus
Date:

> On Feb 21, 2023, at 09:54, Brad White <b55white@gmail.com> wrote:
> Any suggestions on how to proceed?

First, look at pg_stat_user_tables to see how many inserts etc. have occurred on the tables that are not showing an
autovacuum;they may have simply not reached the threshold yet.  If they have, do a VACUUM VERBOSE across the database
andmake sure that you can manually vacuum them, or if it reports that it can't remove tuples. 


Re: Is Autovacuum running?

From
Brad White
Date:
On Tue, Feb 21, 2023 at 11:58 AM Christophe Pettus <xof@thebuild.com> wrote:


> On Feb 21, 2023, at 09:54, Brad White <b55white@gmail.com> wrote:
> Any suggestions on how to proceed?

First, look at pg_stat_user_tables to see how many inserts etc. have occurred on the tables that are not showing an autovacuum; they may have simply not reached the threshold yet.  If they have, do a VACUUM VERBOSE across the database and make sure that you can manually vacuum them, or if it reports that it can't remove tuples.

Running the table_bloat_check query from here 
shows some tables with over 20MB and over 20% bloat while my threshold is set to 0.1.

Before
tablename   | est_rows | pct_bloat | mb_bloat | table_mb
Order Items | 169234   | 33        | 25.98    | 79.695

DocumentLog | 189670   | 23        | 5.52     | 23.648

After
Order Items | 179860   | 28        | 22.6     | 79.695
DocumentLog | 197537   | 23        | 5.78     | 24.672

These two now show up as vacuumed in 
SELECT relname, last_vacuum, last_autovacuum FROM pg_stat_user_tables;
So at least that table is working.

tl;dr  Looks to me like vacuum removed  2215 rows from the "Order Items" indexes.
"There were 166068 unused item pointers."
I don't see anything that looks like an error.

[SQL]vacuum verbose "Order Items"

INFO:  vacuuming "public.Order Items"

INFO:  scanned index "Order Items_pkey" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.01u sec elapsed 0.01 sec.

INFO:  scanned index "Order Items_AuthorityNum" to remove 2215 row versions
DETAIL:  CPU 0.01s/0.00u sec elapsed 0.14 sec.

INFO:  scanned index "Order Items_CopySrcID" to remove 2215 row versions
DETAIL:  CPU 0.01s/0.00u sec elapsed 0.13 sec.

INFO:  scanned index "Order Items_DelivMethFID" to remove 2215 row versions
DETAIL:  CPU 0.01s/0.01u sec elapsed 0.12 sec.

INFO:  scanned index "Order Items_Delivery State FID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.00u sec elapsed 0.09 sec.

INFO:  scanned index "Order Items_Delivery Zip Code" to remove 2215 row versions
DETAIL:  CPU 0.01s/0.03u sec elapsed 0.09 sec.

INFO:  scanned index "Order Items_DiscountFID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.03u sec elapsed 0.10 sec.

INFO:  scanned index "Order Items_EntityWAuthorityFID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.00u sec elapsed 0.06 sec.

INFO:  scanned index "Order Items_ID" to remove 2215 row versions
DETAIL:  CPU 0.01s/0.00u sec elapsed 0.05 sec.

INFO:  scanned index "Order Items_InsertFlag" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.01u sec elapsed 0.10 sec.

INFO:  scanned index "Order Items_ItemFlow2" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.01u sec elapsed 0.09 sec.

INFO:  scanned index "Order Items_LastSerCaptureTypeID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.00u sec elapsed 0.09 sec.

INFO:  scanned index "Order Items_MastInv_FID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.00u sec elapsed 0.11 sec.

INFO:  scanned index "Order Items_OpCarrFID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.03u sec elapsed 0.06 sec.

INFO:  scanned index "Order Items_OrderDate" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.00u sec elapsed 0.06 sec.

INFO:  scanned index "Order Items_OrderFID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.01u sec elapsed 0.01 sec.

INFO:  scanned index "Order Items_PowerU_FID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.01u sec elapsed 0.09 sec.

INFO:  scanned index "Order Items_Representative" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.00u sec elapsed 0.12 sec.

INFO:  scanned index "Order Items_SelValidUseFID" to remove 2215 row versions
DETAIL:  CPU 0.03s/0.01u sec elapsed 0.06 sec.

INFO:  scanned index "Order Items_SerialAuthCode" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.03u sec elapsed 0.10 sec.

INFO:  scanned index "Order Items_SerialNum" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.00u sec elapsed 0.10 sec.

INFO:  scanned index "Order Items_SourceID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.01u sec elapsed 0.11 sec.

INFO:  scanned index "Order Items_StatusReasonFID" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.00u sec elapsed 0.05 sec.

INFO:  scanned index "Order Items_SupplyOrderKey" to remove 2215 row versions
DETAIL:  CPU 0.00s/0.01u sec elapsed 0.11 sec.

INFO:  scanned index "Order Items_TrailerU_FID" to remove 2215 row versions
DETAIL:  CPU 0.01s/0.00u sec elapsed 0.09 sec.

INFO:  scanned index "Order Items_VendorFID" to remove 2215 row versions
DETAIL:  CPU 0.01s/0.01u sec elapsed 0.08 sec.

INFO:  "Order Items": removed 2215 row versions in 1289 pages
DETAIL:  CPU 0.00s/0.04u sec elapsed 0.03 sec.

INFO:  index "Order Items_pkey" now contains 149465 row versions in 961 pages
DETAIL:  162 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_AuthorityNum" now contains 149465 row versions in 3182 pages
DETAIL:  2215 index row versions were removed.
5 index pages have been deleted, 5 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_CopySrcID" now contains 149465 row versions in 3020 pages
DETAIL:  2215 index row versions were removed.
4 index pages have been deleted, 4 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_DelivMethFID" now contains 149465 row versions in 3022 pages
DETAIL:  2215 index row versions were removed.
2 index pages have been deleted, 2 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_Delivery State FID" now contains 149465 row versions in 2426 pages
DETAIL:  2215 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_Delivery Zip Code" now contains 149465 row versions in 2285 pages
DETAIL:  2215 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_DiscountFID" now contains 149465 row versions in 3015 pages
DETAIL:  2215 index row versions were removed.
1 index pages have been deleted, 1 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_EntityWAuthorityFID" now contains 149465 row versions in 1503 pages
DETAIL:  2215 index row versions were removed.
27 index pages have been deleted, 27 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_ID" now contains 149465 row versions in 1130 pages
DETAIL:  316 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_InsertFlag" now contains 149465 row versions in 2980 pages
DETAIL:  1616 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_ItemFlow2" now contains 149465 row versions in 2267 pages
DETAIL:  2215 index row versions were removed.
30 index pages have been deleted, 29 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_LastSerCaptureTypeID" now contains 149465 row versions in 2618 pages
DETAIL:  2215 index row versions were removed.
3 index pages have been deleted, 3 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_MastInv_FID" now contains 149465 row versions in 1514 pages
DETAIL:  1883 index row versions were removed.
69 index pages have been deleted, 69 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_OpCarrFID" now contains 149465 row versions in 1496 pages
DETAIL:  2215 index row versions were removed.
29 index pages have been deleted, 29 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_OrderDate" now contains 149465 row versions in 1529 pages
DETAIL:  240 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_OrderFID" now contains 149465 row versions in 1224 pages
DETAIL:  161 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_PowerU_FID" now contains 149465 row versions in 1851 pages
DETAIL:  2072 index row versions were removed.
1 index pages have been deleted, 1 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_Representative" now contains 149465 row versions in 3506 pages
DETAIL:  2215 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_SelValidUseFID" now contains 149465 row versions in 1753 pages
DETAIL:  1995 index row versions were removed.
14 index pages have been deleted, 14 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_SerialAuthCode" now contains 149465 row versions in 3023 pages
DETAIL:  2215 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_SerialNum" now contains 149465 row versions in 2636 pages
DETAIL:  2215 index row versions were removed.
3 index pages have been deleted, 3 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_SourceID" now contains 149465 row versions in 2948 pages
DETAIL:  2215 index row versions were removed.
1 index pages have been deleted, 1 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_StatusReasonFID" now contains 149465 row versions in 1467 pages
DETAIL:  313 index row versions were removed.
51 index pages have been deleted, 51 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_SupplyOrderKey" now contains 149465 row versions in 2916 pages
DETAIL:  2215 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_TrailerU_FID" now contains 149465 row versions in 2549 pages
DETAIL:  2177 index row versions were removed.
1 index pages have been deleted, 1 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  index "Order Items_VendorFID" now contains 149465 row versions in 1693 pages
DETAIL:  2215 index row versions were removed.
7 index pages have been deleted, 7 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  "Order Items": found 64 removable, 53611 nonremovable row versions in 2591 out of 10201 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 166068 unused item pointers.
0 pages are entirely empty.
CPU 0.14s/0.34u sec elapsed 2.42 sec.

INFO:  vacuuming "pg_toast.pg_toast_402310"

INFO:  index "pg_toast_402310_index" now contains 0 row versions in 1 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  "pg_toast_402310": found 0 removable, 0 nonremovable row versions in 0 out of 0 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

Time: 2.569s

Affected rows: 0

Re: Is Autovacuum running?

From
Christophe Pettus
Date:

> On Feb 21, 2023, at 10:48, Brad White <b55white@gmail.com> wrote:
>
> Running the table_bloat_check query from here
> https://github.com/pgexperts/pgx_scripts/blob/master/bloat/table_bloat_check.sql
> shows some tables with over 20MB and over 20% bloat while my threshold is set to 0.1.

Apples-to-oranges comparison.  That query attempts to calculate a percentage of the overall table filespace that is not
occupiedby live data.  A perfectly 100% vacuumed table with only live tuples can (and probably will) still have bloat,
sincefree space is counted as bloat.  (It's just an approximation, so it changing after a vacuum isn't particularly
surprising.)

The autovacuum threshold doesn't use the same calculations as the bloat query.  That happens when n_dead_tup exceeds
threshold+ pg_class.reltuples * scale_factor.  If there are more than 21,651 or more rows in the table, 2215 dead
tuplesis below that, and autovacuum won't run on the table. 

The output from vacuum didn't have anything it in that would indicate that it couldn't recover dead tuples (like a
long-runningtransaction or something), so there's no reason that autovacuum wouldn't run on the table in the future
whenthe number of dead tuples reaches the threshold. 

By the way, you really should check to see if all those indexes are being used.  That's a *lot* of indexes, which will
greatlyslow down inserts, take up filespace, and slow down autovacuum (since it has to scan each index before it can
reclaimspace in the heap). 


Re: Is Autovacuum running?

From
David Rowley
Date:
On Tue, 21 Feb 2023 at 08:42, Brad White <b55white@gmail.com> wrote:
>
> I'm concerned that Autovacuum may not be running based on the results of this query.
>
> SELECT relname, last_vacuum, last_autovacuum FROM pg_stat_user_tables;
> gives 211 rows like this...
> relname                    | last_vacuum | last_autovacuum
> BusinessIncidentCategories | null | null
> Valid Use                  | null | null
> Serial Pool Part Types     | null | null
> BusinessIncidentLog        | null | null
> Rate Categories            | null | null

It's probably worth having a look at:

select datname,stats_reset,now() from pg_stat_database where datname =
current_database();

while you're connected to the database with those tables. If you're
resetting the stats, then that resets the counters used by autovacuum
and also the columns you mention above. That can lead to autovacuum
not doing any vacuuming or analyzing.

There's a warning in the documentation about this [1]:

"Using pg_stat_reset() also resets counters that autovacuum uses to
determine when to trigger a vacuum or an analyze. Resetting these
counters can cause autovacuum to not perform necessary work, which can
cause problems such as table bloat or out-dated table statistics. A
database-wide ANALYZE is recommended after the statistics have been
reset."

David

[1] https://www.postgresql.org/docs/14/monitoring-stats.html#MONITORING-PG-STAT-ALL-TABLES-VIEW



Re: Is Autovacuum running?

From
Brad White
Date:
On Tue, Feb 21, 2023 at 2:56 PM David Rowley <dgrowleyml@gmail.com> wrote:
On Tue, 21 Feb 2023 at 08:42, Brad White <b55white@gmail.com> wrote:
>
> I'm concerned that Autovacuum may not be running based on the results of this query.
>
> SELECT relname, last_vacuum, last_autovacuum FROM pg_stat_user_tables;
> gives 211 rows like this...
> relname                    | last_vacuum | last_autovacuum
> BusinessIncidentCategories | null | null
> Valid Use                  | null | null
> Serial Pool Part Types     | null | null
> BusinessIncidentLog        | null | null
> Rate Categories            | null | null

It's probably worth having a look at:

select datname,stats_reset,now() from pg_stat_database where datname =
current_database();

while you're connected to the database with those tables. If you're
resetting the stats, then that resets the counters used by autovacuum
and also the columns you mention above. That can lead to autovacuum
not doing any vacuuming or analyzing.

Well that explains a lot.

datname | stats_reset            | now
DB      | 2023-02-17 14:28:27-06 | 2023-02-21 16:16:34-06

I heard that the system was running slowly on Friday. They may have cycled the service in an attempt to resolve that.

I went ahead and ran ANALIZE. We'll see if that affects anything.

Thanks,
Brad.

Re: Is Autovacuum running?

From
David Rowley
Date:
On Wed, 22 Feb 2023 at 11:28, Brad White <b55white@gmail.com> wrote:
> datname | stats_reset            | now
> DB      | 2023-02-17 14:28:27-06 | 2023-02-21 16:16:34-06
>
> I heard that the system was running slowly on Friday. They may have cycled the service in an attempt to resolve
that.

You'll probably want to not do that then.  Just in case I wasn't
clear, this'll not only reset the last_vacuumed values, but also
values that autovacuums uses to determine if it needs to do anything
or not.  So, say if a table normally gets autovacuumed about once
every 2 days, if you reset the stats each day, then it'll likely just
*never* be autovacuumed, at least, not until an antiwraparound vacuum
is needed.  That's not a good situation. That's why the warning in the
docs exists about pg_stat_reset().

If you're resetting the stats to track something like how busy the
database is each week, you should probably just store the current
values and calculate the differences from last week using LAG(...)
OVER (....)

> I went ahead and ran ANALIZE. We'll see if that affects anything.

I think you might want to use that bloat script and get a round of
vacuuming done on any table that looks more bloated than what
autovacuum would trigger on. You may also have a bunch of bloated
indexes that need to be reindexed. I'm not too sure how that bloat
checking script will perform if vacuums have been neglected. You'd at
least want to ANALYZE every table first.

I would make not running pg_stat_reset() ever a priority.

David