PostgreSQL – 1 billion rows table cannot get vacuumed despite no errors

postgresqlpostgresql-9.4vacuum

I have a statistics table that should be processed in a scheduled task to remove rows and count them into a separate, smaller table. Unfortunately the cron task failed for some period of time and the table has grown into 1 billion rows, weighting over 240gb total.

I have started noticing vacuum (to prevent wraparound) tasks running on this table. I'm currently running the processing task on the 'highest setting' and have already dropped a few hundred million rows, but new ones keep coming too.

The table is usually used as insert -> process -> delete, so it should never grow that big but unfortunately it did.

The current status of the table is that I don't even know how many rows it still has left – counting will take hours and estimated row count is still same as it was before I started processing.

I tried running vacuum analyze verbose statistics (despite also running autovacuum) and leaving it for the entire night, but it looks as if the task never finishes, it keeps re-scanning the table over and over again claiming it deleted the same amount of rows every time:

user=#  VACUUM ANALYZE VERBOSE statistics;
INFO:  vacuuming "statistics"
INFO:  scanned index "statistics_pkey" to remove 11184581 row versions
DETAIL:  CPU 17.85s/171.75u sec elapsed 1553.15 sec.
INFO:  scanned index "statistics_datetime_idx" to remove 11184581 row versions
DETAIL:  CPU 43.90s/179.68u sec elapsed 4604.34 sec.
INFO:  "statistics": removed 11184581 row versions in 174840 pages
DETAIL:  CPU 1.68s/1.03u sec elapsed 73.91 sec.
INFO:  scanned index "statistics_pkey" to remove 11184537 row versions
DETAIL:  CPU 18.64s/164.96u sec elapsed 1589.46 sec.
INFO:  scanned index "statistics_datetime_idx" to remove 11184537 row versions
DETAIL:  CPU 46.39s/180.82u sec elapsed 4760.44 sec.
INFO:  "statistics": removed 11184537 row versions in 175755 pages
DETAIL:  CPU 1.75s/0.95u sec elapsed 41.88 sec.
INFO:  scanned index "statistics_pkey" to remove 11184534 row versions
DETAIL:  CPU 17.32s/157.37u sec elapsed 1455.38 sec.
INFO:  scanned index "statistics_datetime_idx" to remove 11184534 row versions
DETAIL:  CPU 42.42s/173.59u sec elapsed 4510.30 sec.
INFO:  "statistics": removed 11184534 row versions in 175642 pages
DETAIL:  CPU 1.28s/1.20u sec elapsed 29.39 sec.
INFO:  scanned index "statistics_pkey" to remove 11184561 row versions
DETAIL:  CPU 17.51s/163.48u sec elapsed 1429.46 sec.
INFO:  scanned index "statistics_datetime_idx" to remove 11184561 row versions
DETAIL:  CPU 40.98s/179.79u sec elapsed 4471.40 sec.
INFO:  "statistics": removed 11184561 row versions in 176023 pages
DETAIL:  CPU 1.82s/1.03u sec elapsed 40.42 sec.
INFO:  scanned index "statistics_pkey" to remove 11184572 row versions
DETAIL:  CPU 16.82s/162.21u sec elapsed 1474.60 sec.
INFO:  scanned index "statistics_datetime_idx" to remove 11184572 row versions
DETAIL:  CPU 43.56s/173.71u sec elapsed 4504.49 sec.
INFO:  "statistics": removed 11184572 row versions in 178045 pages
DETAIL:  CPU 1.87s/1.25u sec elapsed 69.82 sec.
INFO:  scanned index "statistics_pkey" to remove 11184576 row versions
DETAIL:  CPU 17.40s/158.51u sec elapsed 1507.03 sec.
INFO:  scanned index "statistics_datetime_idx" to remove 11184576 row versions
DETAIL:  CPU 43.17s/177.07u sec elapsed 4823.64 sec.
INFO:  "statistics": removed 11184576 row versions in 175004 pages
DETAIL:  CPU 1.64s/1.20u sec elapsed 114.17 sec.
INFO:  scanned index "statistics_pkey" to remove 11184550 row versions
DETAIL:  CPU 16.29s/155.93u sec elapsed 1665.41 sec.

And it goes on and on and on..if I press CTRL+C in the console it says that the statement was cancelled due to user request, so I guess nothing is done at all.

The dead tuples amount is still insanely huge, as if vacuum did nothing:

user=# select n_dead_tup, seq_scan, n_tup_upd, n_tup_del, n_live_tup, last_vacuum, last_autovacuum from pg_stat_user_tables where relname = 'statistics';
 n_dead_tup | seq_scan | n_tup_upd | n_tup_del | n_live_tup | last_vacuum | last_autovacuum

------------+----------+-----------+-----------+------------+-------------+-------------------------------
  476347206 |       40 |         0 | 534973404 | 1032395335 |             | 2020-08-25 21:59:35.265896+02

The table has an ordinary PRIMARY KEY(id) index and also a composite INDEX(device, datetime).

May it be that vacuum doesn't work because I keep the processing task (which is deleting rows) running, and also new rows are being inserted every now and then?

I have looked for hanging transactions that could block the table – but there aren't any.

What else can I check, and how can I get this table back to the 'normal' state again?

Best Answer

it keeps re-scanning the table over and over again claiming it deleted the same amount of rows every time

No, it's not re-scanning. Vacuum will scan the table and populate the list of tuple ids for dead rows. Then vacuum will remove such tuple IDs from indexes and table. But this list is limited in size by the maintenance_work_mem setting: if there are more dead rows in the table than will fit in the list, the cleanup will remove rows from the indexes and the table every time the list is full. And then it will continue to scan the table. That is why you see repeated "scanned index" with approximately the same number of dead rows. n_live_tup will be updated at the end of vacuum process, but work is in progress. Unfortunally pg_stat_progress_vacuum system view was added only in 9.6, so you can not track progress of table scan.

You need increase maintenance_work_mem (up to 1GB, vacuum process has such upper limit) to process more dead rows per iteration. The index vacuum is a noticeably slow part, but not very dependent on the size of the list of dead rows. So bigger list of dead rows is better. Also probably it is acceptable for your server to decrease vacuum_cost_page_* settings to allow more disk IO during vacuum.

Related Question