Re: Table-level log_autovacuum_min_duration

Hi, Michael

I found that definition of VERBOSE and log_autovacuum is not 
pretty match. For example, "VERBOSE" can output logs of 
scanning indices and scanning detail of analyze, but 
log_autovacuum can't output them.

Please see following sequences.

1. execute these queries.
DROP TABLE t1;CREATE TABLE t1(id integer primary key,name text);ALTER TABLE t1 SET (log_autovacuum_min_duration=0);ALTER TABLE t1 ALTER COLUMN name SET STORAGE EXTERNAL;INSERT INTO t1 SELECT GENERATE_SERIES(1,100),repeat('a',3000);UPDATE t1 SET name='update';

2. after a while, output the following logs by autovacuum movement.
(For your convenience, I put the "### TYPE ###" prefix on each logs.)
### VERBOSE  ###INFO:  vacuuming "public.t1"### VERBOSE  ###INFO:  scanned index "t1_pkey" to remove 33 row versions### VERBOSE  ###DETAIL:  CPU 0.00s/0.00u sec elapsed 0.00 sec.### VERBOSE  ###INFO:  "t1": removed 33 row versions in 1 pages### VERBOSE  ###DETAIL:  CPU 0.00s/0.00u sec elapsed 0.00 sec.### VERBOSE  ###INFO:  index "t1_pkey" now contains 100 row versions in 2 pages### VERBOSE  ###DETAIL:  33 index row versions were removed.### VERBOSE  ###        0 index pages have been deleted, 0 are currently reusable.### VERBOSE  ###        CPU 0.00s/0.00u sec elapsed 0.00 sec.### VERBOSE  ###INFO:  "t1": found 100 removable, 100 nonremovable row versions in 2 out of 2 pages### VERBOSE  ###DETAIL:  0 dead row versions cannot be removed yet.### VERBOSE  ###        There were 0 unused item pointers.### VERBOSE  ###        Skipped 0 pages due to buffer pins.### VERBOSE  ###        0 pages are entirely empty.### VERBOSE  ###        CPU 0.00s/0.00u sec elapsed 0.00 sec.### LOG_AVAC ###LOG:  automatic vacuum of table "naoya.public.t1": index scans: 1### LOG_AVAC ###        pages: 0 removed, 2 remain, 0 skipped due to pins### LOG_AVAC ###        tuples: 100 removed, 100 remain, 0 are dead but not yet removable### LOG_AVAC ###        buffer usage: 47 hits, 4 misses, 4 dirtied### LOG_AVAC ###        avg read rate: 14.192 MB/s, avg write rate: 14.192 MB/s### LOG_AVAC ###        system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec### VERBOSE  ###INFO:  analyzing "public.t1"### VERBOSE  ###INFO:  "t1": scanned 2 of 2 pages, containing 100 live rows and 0 dead rows; 100 rows in sample, 100 estimated total rows### LOG_AVAC ###LOG:  automatic analyze of table "naoya.public.t1" system usage: CPU 0.00s/0.00u sec elapsed 0.04 sec### VERBOSE  ###INFO:  vacuuming "pg_toast.pg_toast_72882"### VERBOSE  ###INFO:  scanned index "pg_toast_72882_index" to remove 200 row versions### VERBOSE  ###DETAIL:  CPU 0.00s/0.00u sec elapsed 0.00 sec.### VERBOSE  ###INFO:  "pg_toast_72882": removed 200 row versions in 50 pages### VERBOSE  ###DETAIL:  CPU 0.00s/0.00u sec elapsed 0.00 sec.### VERBOSE  ###INFO:  index "pg_toast_72882_index" now contains 0 row versions in 2 pages### VERBOSE  ###DETAIL:  200 index row versions were removed.### VERBOSE  ###        0 index pages have been deleted, 0 are currently reusable.### VERBOSE  ###        CPU 0.00s/0.00u sec elapsed 0.00 sec.### VERBOSE  ###INFO:  "pg_toast_72882": found 200 removable, 0 nonremovable row versions in 50 out of 50 pages### VERBOSE  ###DETAIL:  0 dead row versions cannot be removed yet.### VERBOSE  ###        There were 0 unused item pointers.### VERBOSE  ###        Skipped 0 pages due to buffer pins.### VERBOSE  ###        0 pages are entirely empty.### VERBOSE  ###        CPU 0.00s/0.00u sec elapsed 0.00 sec.### VERBOSE  ###INFO:  "pg_toast_72882": truncated 50 to 0 pages### VERBOSE  ###DETAIL:  CPU 0.00s/0.00u sec elapsed 0.03 sec.### LOG_AVAC ###LOG:  automatic vacuum of table "naoya.pg_toast.pg_toast_72882": index scans: 1### LOG_AVAC ###        pages: 50 removed, 0 remain, 0 skipped due to pins### LOG_AVAC ###        tuples: 200 removed, 0 remain, 0 are dead but not yet removable### LOG_AVAC ###        buffer usage: 223 hits, 2 misses, 1 dirtied### LOG_AVAC ###        avg read rate: 0.457 MB/s, avg write rate: 0.228 MB/s### LOG_AVAC ###       system usage: CPU 0.00s/0.00u sec elapsed 0.03 sec

I think VACOPT_VERBOSE should not be easily replaced to log_min_duration>=0.

And, in this v7 patch looks that VERBOSE log is always output 
in INFO-Level when log_autovacuum_min_duration is set to 0. 
Is this your point?

Regards,
---
Naoya