SEO

Hi all,

Short story:

I have a quite big table (about 200 million records, and ~2-3 million
updates/~1 million inserts/few thousand deletes per day). I started a
vacuum on it on friday evening, and it still runs now (monday
afternoon). I used "vacuum verbose", and the output looks like:

INFO: vacuuming "public.big_table"
INFO: index "pk_big_table" now contains 223227480 row versions in
1069776 pages
DETAIL: 711140 index row versions were removed.
80669 index pages have been deleted, 80669 are currently reusable.
CPU 14.56s/46.42u sec elapsed 13987.65 sec.
INFO: index "idx_big_table_1" now contains 223229722 row versions in
740108 pages
DETAIL: 711140 index row versions were removed.
58736 index pages have been deleted, 58733 are currently reusable.
CPU 12.90s/94.97u sec elapsed 10052.12 sec.
INFO: index "idx_big_table_2" now contains 16779341 row versions in
55831 pages
DETAIL: 125895 index row versions were removed.
369 index pages have been deleted, 337 are currently reusable.
CPU 1.39s/5.81u sec elapsed 763.25 sec.
INFO: index "idx_big_table_3" now contains 472945 row versions in 2536
pages
DETAIL: 5328 index row versions were removed.
595 index pages have been deleted, 595 are currently reusable.
CPU 0.06s/0.20u sec elapsed 35.36 sec.
INFO: index "idx_big_table_4" now contains 471419 row versions in 2537
pages
DETAIL: 5318 index row versions were removed.
591 index pages have been deleted, 591 are currently reusable.
CPU 0.08s/0.21u sec elapsed 36.18 sec.
INFO: "big_table": removed 2795984 row versions in 413228 pages
DETAIL: CPU 22.19s/26.92u sec elapsed 5095.57 sec.
INFO: index "pk_big_table" now contains 221069840 row versions in
1069780 pages
DETAIL: 2162406 index row versions were removed.
90604 index pages have been deleted, 80609 are currently reusable.
CPU 7.77s/15.92u sec elapsed 13576.07 sec.
INFO: index "idx_big_table_1" now contains 221087391 row versions in
740109 pages
DETAIL: 2162406 index row versions were removed.
66116 index pages have been deleted, 58647 are currently reusable.
CPU 6.34s/23.22u sec elapsed 10592.02 sec.
INFO: index "idx_big_table_2" now contains 16782762 row versions in
55831 pages
DETAIL: 21 index row versions were removed.
355 index pages have been deleted, 323 are currently reusable.
CPU 0.24s/0.78u sec elapsed 651.89 sec.
INFO: index "idx_big_table_3" now contains 482084 row versions in 2536
pages
DETAIL: 525 index row versions were removed.
561 index pages have been deleted, 561 are currently reusable.
CPU 0.04s/0.10u sec elapsed 36.80 sec.
INFO: index "idx_big_table_4" now contains 480575 row versions in 2537
pages
DETAIL: 525 index row versions were removed.
558 index pages have been deleted, 558 are currently reusable.
CPU 0.07s/0.17u sec elapsed 39.37 sec.
INFO: "big_table": removed 2795985 row versions in 32975 pages
DETAIL: CPU 0.96s/0.30u sec elapsed 232.51 sec.
INFO: index "pk_big_table" now contains 218297352 row versions in
1069780 pages
DETAIL: 2795309 index row versions were removed.
103434 index pages have been deleted, 80489 are currently reusable.
CPU 10.40s/18.63u sec elapsed 14420.05 sec.
INFO: index "idx_big_table_1" now contains 218310055 row versions in
740109 pages
DETAIL: 2795309 index row versions were removed.
75674 index pages have been deleted, 58591 are currently reusable.
CPU 6.46s/23.33u sec elapsed 10495.41 sec.
INFO: index "idx_big_table_2" now contains 16782885 row versions in
55831 pages
DETAIL: 29 index row versions were removed.
354 index pages have been deleted, 322 are currently reusable.
CPU 0.24s/0.72u sec elapsed 653.09 sec.
INFO: index "idx_big_table_3" now contains 491320 row versions in 2536
pages
DETAIL: 451 index row versions were removed.
529 index pages have been deleted, 529 are currently reusable.
CPU 0.02s/0.13u sec elapsed 36.83 sec.
INFO: index "idx_big_table_4" now contains 489798 row versions in 2537
pages
DETAIL: 451 index row versions were removed.
522 index pages have been deleted, 522 are currently reusable.
CPU 0.03s/0.13u sec elapsed 36.50 sec.
INFO: "big_table": removed 2795957 row versions in 32947 pages
DETAIL: CPU 0.93s/0.28u sec elapsed 216.91 sec.
INFO: index "pk_big_table" now contains 215519688 row versions in
1069780 pages
DETAIL: 2793693 index row versions were removed.
115142 index pages have been deleted, 80428 are currently reusable.
CPU 7.97s/16.05u sec elapsed 14921.06 sec.
INFO: index "idx_big_table_1" now contains 215523269 row versions in
740109 pages
DETAIL: 2793693 index row versions were removed.
83819 index pages have been deleted, 58576 are currently reusable.
CPU 8.62s/34.15u sec elapsed 9607.76 sec.
INFO: index "idx_big_table_2" now contains 16780518 row versions in
55831 pages
DETAIL: 2385 index row versions were removed.
362 index pages have been deleted, 322 are currently reusable.
CPU 0.20s/0.73u sec elapsed 701.77 sec.
INFO: index "idx_big_table_3" now contains 492309 row versions in 2536
pages
DETAIL: 1097 index row versions were removed.
520 index pages have been deleted, 520 are currently reusable.
CPU 0.06s/0.19u sec elapsed 39.09 sec.
INFO: index "idx_big_table_4" now contains 490789 row versions in 2537
pages
DETAIL: 1090 index row versions were removed.
515 index pages have been deleted, 515 are currently reusable.
CPU 0.05s/0.17u sec elapsed 40.08 sec.
INFO: "big_table": removed 2795966 row versions in 33760 pages
DETAIL: CPU 1.40s/0.47u sec elapsed 273.16 sec.
INFO: index "pk_big_table" now contains 212731896 row versions in
1069780 pages
DETAIL: 2791935 index row versions were removed.
127577 index pages have been deleted, 80406 are currently reusable.
CPU 7.78s/16.26u sec elapsed 14241.76 sec.
INFO: index "idx_big_table_1" now contains 212738938 row versions in
740109 pages
DETAIL: 2791935 index row versions were removed.
93049 index pages have been deleted, 58545 are currently reusable.
CPU 9.57s/32.24u sec elapsed 9782.60 sec.
INFO: index "idx_big_table_2" now contains 16772407 row versions in
55831 pages
DETAIL: 8234 index row versions were removed.
390 index pages have been deleted, 322 are currently reusable.
CPU 0.22s/0.82u sec elapsed 658.90 sec.
INFO: index "idx_big_table_3" now contains 496310 row versions in 2536
pages
DETAIL: 1719 index row versions were removed.
501 index pages have been deleted, 501 are currently reusable.
CPU 0.05s/0.19u sec elapsed 36.78 sec.
INFO: index "idx_big_table_4" now contains 494804 row versions in 2537
pages
DETAIL: 1716 index row versions were removed.
497 index pages have been deleted, 497 are currently reusable.
CPU 0.02s/0.18u sec elapsed 36.32 sec.
INFO: "big_table": removed 2795961 row versions in 36659 pages
DETAIL: CPU 1.04s/0.60u sec elapsed 253.21 sec.
INFO: index "pk_big_table" now contains 209952007 row versions in
1069780 pages
DETAIL: 2791879 index row versions were removed.
140136 index pages have been deleted, 80292 are currently reusable.
CPU 9.00s/15.42u sec elapsed 14884.36 sec.
INFO: index "idx_big_table_1" now contains 209966255 row versions in
740109 pages
DETAIL: 2791879 index row versions were removed.
102429 index pages have been deleted, 58476 are currently reusable.
CPU 7.78s/21.55u sec elapsed 11868.99 sec.
INFO: index "idx_big_table_2" now contains 16772692 row versions in
55831 pages
DETAIL: 107 index row versions were removed.
391 index pages have been deleted, 322 are currently reusable.
CPU 0.29s/0.94u sec elapsed 804.51 sec.
INFO: index "idx_big_table_3" now contains 506561 row versions in 2536
pages
DETAIL: 1741 index row versions were removed.
460 index pages have been deleted, 460 are currently reusable.
CPU 0.06s/0.20u sec elapsed 70.12 sec.
INFO: index "idx_big_table_4" now contains 505063 row versions in 2537
pages
DETAIL: 1741 index row versions were removed.
453 index pages have been deleted, 453 are currently reusable.
CPU 0.07s/0.15u sec elapsed 67.72 sec.
INFO: "big_table": removed 2795955 row versions in 33272 pages
DETAIL: CPU 0.95s/0.30u sec elapsed 436.58 sec.
INFO: index "pk_big_table" now contains 207177253 row versions in
1069780 pages
DETAIL: 2793516 index row versions were removed.
153135 index pages have been deleted, 80210 are currently reusable.
CPU 9.73s/16.60u sec elapsed 16165.25 sec.
INFO: index "idx_big_table_1" now contains 207181989 row versions in
740109 pages
DETAIL: 2793516 index row versions were removed.
112028 index pages have been deleted, 58454 are currently reusable.
CPU 6.60s/19.69u sec elapsed 10805.05 sec.
INFO: index "idx_big_table_2" now contains 16772703 row versions in
55831 pages
DETAIL: 16 index row versions were removed.
391 index pages have been deleted, 322 are currently reusable.
CPU 0.38s/1.10u sec elapsed 618.92 sec.
INFO: index "idx_big_table_3" now contains 508312 row versions in 2536
pages
DETAIL: 1860 index row versions were removed.
447 index pages have been deleted, 447 are currently reusable.
CPU 0.05s/0.15u sec elapsed 39.21 sec.
INFO: index "idx_big_table_4" now contains 506796 row versions in 2537
pages
DETAIL: 1860 index row versions were removed.
441 index pages have been deleted, 441 are currently reusable.
CPU 0.06s/0.16u sec elapsed 37.47 sec.
INFO: "big_table": removed 2796014 row versions in 33014 pages
DETAIL: CPU 0.64s/0.22u sec elapsed 231.78 sec.
INFO: index "pk_big_table" now contains 204387243 row versions in
1069780 pages
DETAIL: 2795393 index row versions were removed.
166053 index pages have been deleted, 80186 are currently reusable.
CPU 10.27s/19.48u sec elapsed 14750.33 sec.
INFO: index "idx_big_table_1" now contains 204393784 row versions in
740109 pages
DETAIL: 2795393 index row versions were removed.
121640 index pages have been deleted, 58403 are currently reusable.
CPU 7.23s/19.34u sec elapsed 10932.43 sec.
INFO: index "idx_big_table_2" now contains 16772967 row versions in
55831 pages
DETAIL: 7 index row versions were removed.
389 index pages have been deleted, 320 are currently reusable.
CPU 0.32s/0.85u sec elapsed 744.28 sec.
INFO: index "idx_big_table_3" now contains 513406 row versions in 2536
pages
DETAIL: 507 index row versions were removed.
429 index pages have been deleted, 429 are currently reusable.
CPU 0.04s/0.16u sec elapsed 47.37 sec.
INFO: index "idx_big_table_4" now contains 511904 row versions in 2537
pages
DETAIL: 507 index row versions were removed.
422 index pages have been deleted, 422 are currently reusable.
CPU 0.06s/0.14u sec elapsed 44.98 sec.
INFO: "big_table": removed 2795974 row versions in 32926 pages
DETAIL: CPU 1.14s/0.36u sec elapsed 287.30 sec.


Now the question:

I wonder why the repeated infos about all the steps ? Is vacuum in some
kind of loop here ?


Now the long story and why the long vacuum is a problem for me:

I have a postgres 8.1.3 (actually it's a non-released CVS version from
the 8.1 stable branch somewhere after 8.1.3 was released) installation
where I have a quite big table which is also frequently updated.

The big problem is that I can't run vacuum on it, because it won't
finish in the maintenance time window I can allocate for it.

I would let vacuum run on it as long as it's finished, but then I get a
huge performance hit on other tables, which are heavily
inserted/deleted, and must be vacuumed very frequently.
The long running vacuum on the big table will prevent effective vacuum
on those, they will get quickly too big, the system will slow down, the
big vacuum will be even slower, and so on.
One of these (normally small) tables is particularly a problem, as it
has a query running on it frequently (several times per second) which
requires a full table scan and can't be accelerated by any indexing. And
top that with the fact that it has a high insert/delete ratio when the
system is busy... I can't afford any long running transaction in busy
times on this system.

So, after a clean dump/reload of this system coupled with migration to
8.1, I thought that vacuuming the big table will be possible over night
(it has about 200 million records, and ~2-3 million updates/~1 million
inserts/few thousand deletes per day).
But to my surprise it was not enough, and it affected very negatively
other maintenance tasks too, so I had to cancel nightly vacuuming for
it.

So I scheduled the vacuum over the weekend, when we have only light
activity on this system. But it did not finish over the weekend
either... and again it affected all other activities too much. I had to
kill the vacuum (on monday) in the last few weeks, as it was stopping
business.

So we started to suspect that there is some concurrency problem with
either our hardware or OS, and moved the server to another machine with
the same hardware, same OS (debian linux), all the same settings but a
different file system (XFS instead of ext3).

We actually have seen a significant overall performance boost from this
simple move... But the vacuum still didn't finish over the weekend, it
just didn't affect anymore the other tasks, which finished slightly
slower than when running alone. The vacuum itself wouldn't be a problem
performance-wise, except it is a long running transaction, and it
affects other table's vacuuming schedule, as mentioned above. Business
hours are coming, and I will have to kill the vacuum again...

Cheers,
Csaba.



---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

Csaba Nagy wrote:

> I have a quite big table (about 200 million records, and ~2-3 million
> updates/~1 million inserts/few thousand deletes per day). I started a
> vacuum on it on friday evening, and it still runs now (monday
> afternoon). I used "vacuum verbose", and the output looks like:
>
> [vacuums list all the indexes noting how many tuples it cleaned, then
> "restarts" and lists all the indexes again, then again ... ad nauseam]

What happens is this: the vacuum commands scans the heap and notes which
tuples need to be removed. It needs to remember them in memory, but
memory is limited; it uses the maintenance_work_mem GUC setting to
figure out how much to use. Within this memory it needs to store the
TIDs (absolute location) of tuples that need to be deleted. When the
memory is filled, it stops scanning the heap and scans the first index,
looking for pointers to any of the tuples that were deleted in the heap.
Eventually it finds them all and goes to the next index: scan, delete
pointers. Next index. And so on, until all the indexes are done.

At this point, the first pass is done. Vacuum must then continue
scanning the heap for the next set of TIDs, until it finds enough to
fill maintenance_work_mem. Scan the indexes to clean them. Start
again. And again.

So one very effective way of speeding this process up is giving the
vacuum process lots of memory, because it will have to do fewer passes
at each index. How much do you have?

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

> So one very effective way of speeding this process up is giving the
> vacuum process lots of memory, because it will have to do fewer passes
> at each index. How much do you have?

OK, this is my problem... it is left at default (16 megabyte ?). This
must be a mistake in configuration, on other similar boxes I set this to
262144 (256 megabyte). The box has 4 Gbyte memory.

Thanks for the explanation - you were right on the spot, it will likely
solve the problem.

Cheers,
Csaba.




---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo@postgresql.org so that your
message can get through to the mailing list cleanly