Hi All,
I was running some pgbench tests and observed this phenomenon. This might be
a known issue, but I thought its nevertheless worth mentioning.
Auto-analyze process grabs a MVCC snapshot. If it runs on a very large
table, it may take considerable time and would stop the OldestXmin from
advancing. During that time, if there are highly updated small tables, those
would bloat a lot. For example, in the attached log snippet (and the HEAD is
patched a bit to produce more information than what you would otherwise
see), for a scale factor of 50 and 50 clients:
branches and tellers tables, which had a stable size of around 65 and 90
pages respectively, bloat to 402 and 499 pages respectively when accounts
table is being analyzed. The accounts table analyze takes around 5 mins on
my decent server and the branches and tellers tables keep bloating during
that time. If these small tables are very actively accessed, vacuum may not
be able to even truncate them later, once OldestXmin advances at the end of
auto analyze.
I understand analyze needs snapshot to run index predicate functions, but is
there something we can do ? There is a PROC_IN_ANALYZE flag, but we don't
seem to be using it anywhere. Since acquire_sample_rows() returns palloced
tuples, can't we let OldestXmin advance after scanning a page by ignoring
procs with the flag set, just like we do for PROC_IN_VACUUM ?
Thanks,
Pavan
--
Pavan Deolasee
EnterpriseDB http://www.enterprisedb.com
7457:2006-07-07 09:46:05.829 ISTLOG: automatic analyze of table
"postgres.public.pgbench_branches" total rows 50, dead rows 2919, system usage:
CPU 0.00s/0.00u sec elapsed 0.03 sec
7457:2006-07-07 09:46:05.874 ISTLOG: index "pgbench_tellers_pkey" now contains
500 row versions in 9 pages
7457:2006-07-07 09:46:05.874 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.01 sec.
7457:2006-07-07 09:46:05.874 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 0
pages: 0 removed, 90 remain
tuples: 4977 removed, 853 remain
index pointers: 0 removed
total cost delay: 0
system usage for first pass CPU 0.00s/0.00u sec elapsed 0.00 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 0.02 sec
7457:2006-07-07 09:46:05.899 ISTLOG: automatic analyze of table
"postgres.public.pgbench_tellers" total rows 500, dead rows 357, system usage:
CPU 0.00s/0.00u sec elapsed 0.00 sec
7462:2006-07-07 09:47:19.309 ISTLOG: index "pgbench_branches_pkey" now
contains 50 row versions in 2 pages
7462:2006-07-07 09:47:19.309 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 56.13 sec.
7462:2006-07-07 09:47:19.309 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_branches": index scans: 0
pages: 0 removed, 65 remain
tuples: 5220 removed, 350 remain
index pointers: 0 removed
total cost delay: 20
system usage for first pass CPU 0.18s/0.18u sec elapsed 0.18 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 56.31 sec
7462:2006-07-07 09:47:19.341 ISTLOG: automatic analyze of table
"postgres.public.pgbench_branches" total rows 50, dead rows 4238, system usage:
CPU 0.00s/0.00u sec elapsed 0.02 sec
7462:2006-07-07 09:47:19.809 ISTLOG: index "pgbench_tellers_pkey" now contains
500 row versions in 9 pages
7462:2006-07-07 09:47:19.809 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.03 sec.
7462:2006-07-07 09:47:19.810 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 0
pages: 0 removed, 90 remain
tuples: 5442 removed, 770 remain
index pointers: 0 removed
total cost delay: 40
system usage for first pass CPU 0.38s/0.38u sec elapsed 0.38 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 0.41 sec
7462:2006-07-07 09:47:19.858 ISTLOG: automatic analyze of table
"postgres.public.pgbench_tellers" total rows 500, dead rows 390, system usage:
CPU 0.00s/0.00u sec elapsed 0.02 sec
7467:2006-07-07 09:47:22.994 ISTLOG: automatic analyze of table
"postgres.public.pgbench_branches" total rows 50, dead rows 4644, system usage:
CPU 0.00s/0.00u sec elapsed 0.00 sec
7473:2006-07-07 09:48:48.390 ISTLOG: index "pgbench_branches_pkey" now
contains 50 row versions in 2 pages
7473:2006-07-07 09:48:48.390 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 25.27 sec.
7473:2006-07-07 09:48:48.390 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_branches": index scans: 0
pages: 0 removed, 65 remain
tuples: 2852 removed, 368 remain
index pointers: 0 removed
total cost delay: 20
system usage for first pass CPU 0.11s/0.11u sec elapsed 0.11 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 25.38 sec
7473:2006-07-07 09:48:48.432 ISTLOG: automatic analyze of table
"postgres.public.pgbench_branches" total rows 50, dead rows 3374, system usage:
CPU 0.00s/0.00u sec elapsed 0.03 sec
7473:2006-07-07 09:48:48.652 ISTLOG: index "pgbench_tellers_pkey" now contains
500 row versions in 9 pages
7473:2006-07-07 09:48:48.652 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.12 sec.
7473:2006-07-07 09:48:48.652 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 0
pages: 0 removed, 90 remain
tuples: 5603 removed, 719 remain
index pointers: 0 removed
total cost delay: 20
system usage for first pass CPU 0.07s/0.07u sec elapsed 0.07 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 0.20 sec
7473:2006-07-07 09:48:48.709 ISTLOG: automatic analyze of table
"postgres.public.pgbench_tellers" total rows 500, dead rows 573, system usage:
CPU 0.00s/0.00u sec elapsed 0.02 sec
7473:2006-07-07 09:49:32.332 ISTLOG: automatic analyze of table
"postgres.public.pgbench_history" total rows 1984743, dead rows 0, system
usage: CPU 0.12s/0.27u sec elapsed 43.58 sec
7482:2006-07-07 09:50:26.959 ISTLOG: scanned index "pgbench_tellers_pkey" to
remove 2044 row versions
7482:2006-07-07 09:50:26.959 ISTDETAIL: CPU 0.00s/0.00u sec elapsed 0.12 sec.
7482:2006-07-07 09:50:27.246 ISTLOG: "pgbench_tellers": removed 2044 row
versions in 99 pages
7482:2006-07-07 09:50:27.246 ISTDETAIL: CPU 0.00s/0.00u sec elapsed 0.28 sec.
7482:2006-07-07 09:50:27.246 ISTLOG: index "pgbench_tellers_pkey" now contains
500 row versions in 13 pages
7482:2006-07-07 09:50:27.246 ISTDETAIL: 2044 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.
7482:2006-07-07 09:50:27.246 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 1
pages: 0 removed, 147 remain
tuples: 3602 removed, 961 remain
index pointers: 2044 removed
total cost delay: 363
system usage for first pass CPU 0.82s/0.82u sec elapsed 3.82 sec
systema usage for second pass CPU 0.28s/0.28u sec elapsed 0.28 sec
system usage for index scan CPU 0.12s/0.12u sec elapsed 0.12 sec
total system usage: CPU 0.00s/0.00u sec elapsed 4.24 sec
7482:2006-07-07 09:50:27.327 ISTLOG: automatic analyze of table
"postgres.public.pgbench_tellers" total rows 500, dead rows 1080, system usage:
CPU 0.00s/0.00u sec elapsed 0.06 sec
7488:2006-07-07 09:51:23.210 ISTLOG: index "pgbench_tellers_pkey" now contains
986 row versions in 13 pages
7488:2006-07-07 09:51:23.210 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.01 sec.
7488:2006-07-07 09:51:23.210 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 0
pages: 0 removed, 147 remain
tuples: 31 removed, 13993 remain
index pointers: 0 removed
total cost delay: 106
system usage for first pass CPU 0.19s/0.19u sec elapsed 0.19 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 0.20 sec
7488:2006-07-07 09:51:23.314 ISTLOG: automatic analyze of table
"postgres.public.pgbench_tellers" total rows 500, dead rows 13716, system
usage: CPU 0.00s/0.00u sec elapsed 0.08 sec
7476:2006-07-07 09:51:57.292 ISTLOG: index "pgbench_branches_pkey" now
contains 535 row versions in 5 pages
7476:2006-07-07 09:51:57.292 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 151.18 sec.
7476:2006-07-07 09:51:57.292 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_branches": index scans: 0
pages: 0 removed, 108 remain
tuples: 0 removed, 21125 remain
index pointers: 0 removed
total cost delay: 40
system usage for first pass CPU 0.10s/0.10u sec elapsed 3.10 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 154.29 sec
7476:2006-07-07 09:51:57.382 ISTLOG: automatic analyze of table
"postgres.public.pgbench_branches" total rows 50, dead rows 37833, system
usage: CPU 0.00s/0.00u sec elapsed 0.06 sec
7476:2006-07-07 09:51:57.629 ISTLOG: index "pgbench_tellers_pkey" now contains
3883 row versions in 15 pages
7476:2006-07-07 09:51:57.629 ISTDETAIL: 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.
7476:2006-07-07 09:51:57.629 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 0
pages: 0 removed, 245 remain
tuples: 0 removed, 38172 remain
index pointers: 0 removed
total cost delay: 100
system usage for first pass CPU 0.21s/0.21u sec elapsed 0.21 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 0.21 sec
7476:2006-07-07 09:51:57.684 ISTLOG: automatic analyze of table
"postgres.public.pgbench_tellers" total rows 500, dead rows 37783, system
usage: CPU 0.00s/0.00u sec elapsed 0.04 sec
7491:2006-07-07 09:52:29.608 ISTLOG: scanned index "pgbench_branches_pkey" to
remove 383 row versions
7491:2006-07-07 09:52:29.608 ISTDETAIL: CPU 0.00s/0.00u sec elapsed 2.39 sec.
7491:2006-07-07 09:52:29.964 ISTLOG: "pgbench_branches": removed 383 row
versions in 98 pages
7491:2006-07-07 09:52:29.964 ISTDETAIL: CPU 0.00s/0.00u sec elapsed 0.35 sec.
7491:2006-07-07 09:52:29.965 ISTLOG: index "pgbench_branches_pkey" now
contains 775 row versions in 5 pages
7491:2006-07-07 09:52:29.965 ISTDETAIL: 40 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.
7491:2006-07-07 09:52:29.965 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_branches": index scans: 1
pages: 0 removed, 328 remain
tuples: 0 removed, 53138 remain
index pointers: 383 removed
total cost delay: 518
system usage for first pass CPU 0.38s/0.38u sec elapsed 3.38 sec
systema usage for second pass CPU 0.35s/0.35u sec elapsed 0.35 sec
system usage for index scan CPU 0.39s/0.39u sec elapsed 2.39 sec
total system usage: CPU 0.00s/0.00u sec elapsed 6.13 sec
7491:2006-07-07 09:52:30.088 ISTLOG: automatic analyze of table
"postgres.public.pgbench_branches" total rows 48, dead rows 54528, system
usage: CPU 0.00s/0.00u sec elapsed 0.10 sec
7491:2006-07-07 09:52:30.315 ISTLOG: index "pgbench_tellers_pkey" now contains
6028 row versions in 23 pages
7491:2006-07-07 09:52:30.315 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.05 sec.
7491:2006-07-07 09:52:30.315 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 0
pages: 0 removed, 340 remain
tuples: 0 removed, 55275 remain
index pointers: 0 removed
total cost delay: 120
system usage for first pass CPU 0.13s/0.13u sec elapsed 0.13 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 0.19 sec
7491:2006-07-07 09:52:30.394 ISTLOG: automatic analyze of table
"postgres.public.pgbench_tellers" total rows 502, dead rows 54912, system
usage: CPU 0.00s/0.00u sec elapsed 0.06 sec
7496:2006-07-07 09:53:32.948 ISTLOG: index "pgbench_branches_pkey" now
contains 935 row versions in 7 pages
7496:2006-07-07 09:53:32.948 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 1.39 sec.
7496:2006-07-07 09:53:32.948 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_branches": index scans: 0
pages: 0 removed, 328 remain
tuples: 0 removed, 67065 remain
index pointers: 0 removed
total cost delay: 255
system usage for first pass CPU 0.54s/0.54u sec elapsed 8.54 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 9.93 sec
7496:2006-07-07 09:53:33.323 ISTLOG: index "pgbench_tellers_pkey" now contains
7559 row versions in 27 pages
7496:2006-07-07 09:53:33.323 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.02 sec.
7496:2006-07-07 09:53:33.324 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 0
pages: 0 removed, 393 remain
tuples: 0 removed, 69217 remain
index pointers: 0 removed
total cost delay: 254
system usage for first pass CPU 0.30s/0.30u sec elapsed 0.30 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 0.32 sec
7503:2006-07-07 09:54:34.867 ISTLOG: index "pgbench_branches_pkey" now
contains 1209 row versions in 7 pages
7503:2006-07-07 09:54:34.867 ISTDETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 2.95 sec.
7503:2006-07-07 09:54:34.868 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_branches": index scans: 0
pages: 0 removed, 364 remain
tuples: 0 removed, 78054 remain
index pointers: 0 removed
total cost delay: 208
system usage for first pass CPU 0.90s/0.90u sec elapsed 8.90 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.00u sec elapsed 11.85 sec
7503:2006-07-07 09:54:35.271 ISTLOG: index "pgbench_tellers_pkey" now contains
8935 row versions in 35 pages
7503:2006-07-07 09:54:35.271 ISTDETAIL: 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.
7503:2006-07-07 09:54:35.271 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 0
pages: 0 removed, 447 remain
tuples: 0 removed, 79764 remain
index pointers: 0 removed
total cost delay: 183
system usage for first pass CPU 0.21s/0.21u sec elapsed 0.21 sec
systema usage for second pass CPU 0.00s/0.00u sec elapsed 0.00 sec
system usage for index scan CPU 0.00s/0.00u sec elapsed 0.00 sec
total system usage: CPU 0.00s/0.01u sec elapsed 0.21 sec
7482:2006-07-07 09:54:55.027 ISTLOG: automatic analyze of table
"postgres.public.pgbench_accounts" total rows 4988305, dead rows 189797, system
usage: CPU 0.57s/0.53u sec elapsed 267.66 sec
7507:2006-07-07 09:55:23.166 ISTLOG: automatic analyze of table
"postgres.public.pgbench_branches" total rows 50, dead rows 6522, system usage:
CPU 0.00s/0.00u sec elapsed 0.15 sec
7507:2006-07-07 09:55:23.250 ISTLOG: automatic analyze of table
"postgres.public.pgbench_tellers" total rows 500, dead rows 14324, system
usage: CPU 0.00s/0.00u sec elapsed 0.05 sec
7510:2006-07-07 09:56:37.175 ISTLOG: scanned index "pgbench_branches_pkey" to
remove 1362 row versions
7510:2006-07-07 09:56:37.175 ISTDETAIL: CPU 0.00s/0.00u sec elapsed 0.72 sec.
7510:2006-07-07 09:56:37.520 ISTLOG: "pgbench_branches": removed 1362 row
versions in 364 pages
7510:2006-07-07 09:56:37.520 ISTDETAIL: CPU 0.00s/0.00u sec elapsed 0.34 sec.
7510:2006-07-07 09:56:37.520 ISTLOG: index "pgbench_branches_pkey" now
contains 50 row versions in 7 pages
7510:2006-07-07 09:56:37.520 ISTDETAIL: 1362 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.
7510:2006-07-07 09:56:37.520 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_branches": index scans: 1
pages: 0 removed, 402 remain
tuples: 4436 removed, 582 remain
index pointers: 1362 removed
total cost delay: 378
system usage for first pass CPU 0.43s/0.43u sec elapsed 13.43 sec
systema usage for second pass CPU 0.34s/0.34u sec elapsed 0.34 sec
system usage for index scan CPU 0.72s/0.72u sec elapsed 0.72 sec
total system usage: CPU 0.00s/0.00u sec elapsed 14.50 sec
7510:2006-07-07 09:56:37.624 ISTLOG: automatic analyze of table
"postgres.public.pgbench_branches" total rows 50, dead rows 1896, system usage:
CPU 0.00s/0.00u sec elapsed 0.04 sec
7510:2006-07-07 09:56:37.847 ISTLOG: scanned index "pgbench_tellers_pkey" to
remove 9794 row versions
7510:2006-07-07 09:56:37.847 ISTDETAIL: CPU 0.00s/0.00u sec elapsed 0.12 sec.
7510:2006-07-07 09:56:38.309 ISTLOG: "pgbench_tellers": removed 9794 row
versions in 447 pages
7510:2006-07-07 09:56:38.309 ISTDETAIL: CPU 0.00s/0.00u sec elapsed 0.46 sec.
7510:2006-07-07 09:56:38.309 ISTLOG: index "pgbench_tellers_pkey" now contains
500 row versions in 40 pages
7510:2006-07-07 09:56:38.309 ISTDETAIL: 9794 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.
7510:2006-07-07 09:56:38.310 ISTLOG: automatic vacuum of table
"postgres.public.pgbench_tellers": index scans: 1
pages: 0 removed, 499 remain
tuples: 3465 removed, 773 remain
index pointers: 9794 removed
total cost delay: 534
system usage for first pass CPU 0.06s/0.06u sec elapsed 0.06 sec
systema usage for second pass CPU 0.46s/0.46u sec elapsed 0.46 sec
system usage for index scan CPU 0.12s/0.12u sec elapsed 0.12 sec
total system usage: CPU 0.00s/0.00u sec elapsed 0.65 sec
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
