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
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
