RE: BUG #15067: Documentation or behaviour bug with autovacuum thresholds?

From: Greg Clough <greg(dot)clough(at)ipreo(dot)com>
To: Jim Nasby <jim(dot)nasby(at)openscg(dot)com>, Euler Taveira <euler(at)timbira(dot)com(dot)br>, "pgsql-bugs(at)lists(dot)postgresql(dot)org" <pgsql-bugs(at)lists(dot)postgresql(dot)org>
Subject: RE: BUG #15067: Documentation or behaviour bug with autovacuum thresholds?
Date: 2018-03-05 11:34:47
Message-ID: MWHPR03MB31330E113CFAEFC6152E02A4F7DA0@MWHPR03MB3133.namprd03.prod.outlook.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

> Obviously that doesn't make sense given your example, so I'm wondering if you did a single-row update some time before step 3.

Hi Jim. No, there were no other updates. I'm glad you agree this is strange.

> I suggest posting a complete test script demonstrating the behavior you're seeing.

Script attached below. I think it shows up some definite weirdness in the way autovacuum is running and reporting into the postgres.log. It should work on any basic database (I used v9.6.8 on CentOS v7.4), but ensure "autovacuum_naptime = 5s" so that the short sleeps actually allow autovacuum to run.

I ran this script in a terminal with psql, and had the postgres.log tailing in another. I apologise if there are a lot of combinations, but I'm trying to cover all angles to show it's not a simple corner case. I have also tried it with autovacuum_vacuum_scale_factor > 0, and the behaviour is the same... albeit with the autovacuum trigger point increased by 2000 * autovacuum_vacuum_scale_factor.

In short, it seems that it will only report the correct "tuples: XX removed" into the postgres.log if cumulative updates are done within a single transaction.

Cheers,
Greg Clough
Senior Technology Engineer
Ipreo
Castle House | 37-35 Paul St | London EC2A 4LS

--
-- Turn on logging for all autovacuum, and increase autovacuum frequency
--
ALTER SYSTEM SET log_autovacuum_min_duration = 0;

--
-- Capture some system information
--
SELECT version();
SHOW log_autovacuum_min_duration;
SHOW autovacuum_naptime; -- MUST BE SET TO A LOW VALUE, LIKE "5s"

--
-- Prepare a test table with some data
--
DROP TABLE IF EXISTS autovacuum_threshold_test;
CREATE TABLE autovacuum_threshold_test(id int);
INSERT INTO autovacuum_threshold_test(id) (SELECT generate_series(1,2000));

--
-- Set the autovacuum for the test table
--
ALTER TABLE autovacuum_threshold_test SET (autovacuum_vacuum_scale_factor = 0);
ALTER TABLE autovacuum_threshold_test SET (autovacuum_vacuum_threshold = 500);
\d+ autovacuum_threshold_test;

\echo ============================================================
\echo Trigger autovacuum, should vacuum 500 rows...
\echo ... but it does NOT, then it vacuums "1" row, which is < the threshold
\echo ------------------------------------------------------------
UPDATE autovacuum_threshold_test SET id = id WHERE id <= 500;
SELECT pg_sleep(30);
UPDATE autovacuum_threshold_test SET id = id WHERE id <= 1;
\echo ============================================================

\echo
\echo Wait between tests...
\echo
SELECT pg_sleep(30);
VACUUM FULL autovacuum_threshold_test;

\echo ============================================================
\echo Trigger autovacuum, should vacuum 500 rows...
\echo ... but it does NOT, and without the delay NEITHER are reported
\echo ------------------------------------------------------------
UPDATE autovacuum_threshold_test SET id = id WHERE id <= 500;
UPDATE autovacuum_threshold_test SET id = id WHERE id <= 1;
\echo ============================================================

\echo
\echo Wait between tests...
\echo
SELECT pg_sleep(30);
VACUUM FULL autovacuum_threshold_test;

\echo ============================================================
\echo Trigger autovacuum, should vacuum 499 + 2 = 501 rows...
\echo ... but only the "2" row vacuum is reported, either with or without a sleep
\echo ------------------------------------------------------------
UPDATE autovacuum_threshold_test SET id = id WHERE id <= 499;
-- SELECT pg_sleep(30);
UPDATE autovacuum_threshold_test SET id = id WHERE id BETWEEN 500 and 501;
\echo ============================================================

\echo
\echo Wait between tests...
\echo
SELECT pg_sleep(30);
VACUUM FULL autovacuum_threshold_test;

\echo ============================================================
\echo Trigger autovacuum, should vacuum 200 + 201 + 202 = 603 rows...
\echo ... but it does NOT, it only reports the final 202 row vacuum, either with or without a sleep
\echo ------------------------------------------------------------
UPDATE autovacuum_threshold_test SET id = id WHERE id BETWEEN 1 and 200;
-- SELECT pg_sleep(30);
UPDATE autovacuum_threshold_test SET id = id WHERE id BETWEEN 201 and 401;
-- SELECT pg_sleep(30);
UPDATE autovacuum_threshold_test SET id = id WHERE id BETWEEN 402 and 603;
\echo ============================================================

\echo
\echo Wait between tests...
\echo
SELECT pg_sleep(30);
VACUUM FULL autovacuum_threshold_test;

\echo ============================================================
\echo Trigger autovacuum, should vacuum 500 rows... then do a separate vacuum of 501 rows
\echo ... but it does NOT, it missed the 500 rows entirely, and only reports the 501 row vacuum, either with or without a sleep
\echo ------------------------------------------------------------
UPDATE autovacuum_threshold_test SET id = id WHERE id <= 500;
-- SELECT pg_sleep(30);
UPDATE autovacuum_threshold_test SET id = id WHERE id BETWEEN 501 and 1001;
\echo ============================================================

\echo
\echo Wait between tests...
\echo
SELECT pg_sleep(30);
VACUUM FULL autovacuum_threshold_test;

\echo ============================================================
\echo Trigger autovacuum, should vacuum 500 + 501 = 1001 rows...
\echo ... and it DOES, because it is in a single transaction
\echo ------------------------------------------------------------
BEGIN;
UPDATE autovacuum_threshold_test SET id = id WHERE id <= 500;
UPDATE autovacuum_threshold_test SET id = id WHERE id BETWEEN 501 and 1001;
COMMIT;
\echo ============================================================

\echo TESTS FINISHED
--
-- END OF FILE
--

In response to

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Tom Lane 2018-03-05 19:38:33 Re: BUG #15096: Unable to CREATE TABLE LIKE with bigint identity column
Previous Message Michael Paquier 2018-03-05 09:01:11 Re: BUG #14999: pg_rewind corrupts control file global/pg_control