Re: Updates on large tables are extremely slow - Mailing list pgsql-performance

rvponp=# vacuum verbose tblPrintjobs ;

INFO:  vacuuming "public.tblprintjobs"

INFO:  index "pkprintjobs" now contains 622972 row versions in 8410
pages

DETAIL:  9526 index row versions were removed.

0 index pages have been deleted, 0 are currently reusable.

CPU 0.60s/0.31u sec elapsed 31.68 sec.

INFO:  index "uxprintjobs" now contains 622972 row versions in 3978
pages

DETAIL:  9526 index row versions were removed.

0 index pages have been deleted, 0 are currently reusable.

CPU 0.15s/0.48u sec elapsed 3.59 sec.

INFO:  index "ixprintjobsipaddress" now contains 622972 row versions
in 2542 pages

DETAIL:  9526 index row versions were removed.

49 index pages have been deleted, 0 are currently reusable.

CPU 0.13s/0.24u sec elapsed 2.57 sec.

INFO:  index "ixprintjobshostname" now contains 622972 row versions in
2038 pages

DETAIL:  9526 index row versions were removed.

35 index pages have been deleted, 0 are currently reusable.

CPU 0.09s/0.30u sec elapsed 1.14 sec.

INFO:  index "ixprintjobsrecordnumber" now contains 622972 row
versions in 1850 pages

DETAIL:  9526 index row versions were removed.

0 index pages have been deleted, 0 are currently reusable.

CPU 0.07s/0.28u sec elapsed 1.51 sec.

INFO:  index "ixprintjobseventdate" now contains 622972 row versions
in 1408 pages

DETAIL:  9526 index row versions were removed.

4 index pages have been deleted, 0 are currently reusable.

CPU 0.05s/0.24u sec elapsed 2.61 sec.

INFO:  index "ixprintjobseventtime" now contains 622972 row versions
in 1711 pages

DETAIL:  9526 index row versions were removed.

0 index pages have been deleted, 0 are currently reusable.

CPU 0.12s/0.53u sec elapsed 11.66 sec.

INFO:  index "ixprintjobseventcomputer" now contains 622972 row
versions in 2039 pages

DETAIL:  9526 index row versions were removed.

36 index pages have been deleted, 0 are currently reusable.

CPU 0.12s/0.23u sec elapsed 1.27 sec.

INFO:  index "ixprintjobseventuser" now contains 622972 row versions
in 2523 pages

DETAIL:  9526 index row versions were removed.

19 index pages have been deleted, 0 are currently reusable.

CPU 0.14s/0.24u sec elapsed 1.74 sec.

INFO:  index "ixprintjobsloginuser" now contains 622972 row versions
in 2114 pages

DETAIL:  9526 index row versions were removed.

13 index pages have been deleted, 0 are currently reusable.

CPU 0.07s/0.32u sec elapsed 4.29 sec.

INFO:  index "ixprintjobsprintqueue" now contains 622972 row versions
in 2201 pages

DETAIL:  9526 index row versions were removed.

30 index pages have been deleted, 0 are currently reusable.

CPU 0.10s/0.34u sec elapsed 1.92 sec.

INFO:  index "ixprintjobsprintport" now contains 622972 row versions
in 3040 pages

DETAIL:  9526 index row versions were removed.

40 index pages have been deleted, 0 are currently reusable.

CPU 0.18s/0.27u sec elapsed 2.63 sec.

INFO:  index "ixprintjobssize" now contains 622972 row versions in
1733 pages

DETAIL:  9526 index row versions were removed.

0 index pages have been deleted, 0 are currently reusable.

CPU 0.16s/0.43u sec elapsed 4.07 sec.

INFO:  index "ixprintjobspages" now contains 622972 row versions in
1746 pages

DETAIL:  9526 index row versions were removed.

24 index pages have been deleted, 0 are currently reusable.

CPU 0.13s/0.22u sec elapsed 1.58 sec.

INFO:  index "ixprintjobsapplicationtype" now contains 622972 row
versions in 1395 pages

DETAIL:  9526 index row versions were removed.

27 index pages have been deleted, 0 are currently reusable.

CPU 0.07s/0.29u sec elapsed 1.20 sec.

INFO:  index "ixprintjobsusertype" now contains 622972 row versions in
1393 pages

DETAIL:  9526 index row versions were removed.

24 index pages have been deleted, 0 are currently reusable.

CPU 0.07s/0.22u sec elapsed 0.82 sec.

INFO:  index "ixprintjobsdocumentname" now contains 622972 row
versions in 4539 pages

DETAIL:  9526 index row versions were removed.

6 index pages have been deleted, 0 are currently reusable.

CPU 0.24s/0.38u sec elapsed 5.83 sec.

INFO:  index "ixprintjobsdesceventdate" now contains 622972 row
versions in 1757 pages

DETAIL:  9526 index row versions were removed.

4 index pages have been deleted, 0 are currently reusable.

CPU 0.08s/0.25u sec elapsed 1.16 sec.

INFO:  index "ixprintjobsdesceventtime" now contains 622972 row
versions in 1711 pages

DETAIL:  9526 index row versions were removed.

0 index pages have been deleted, 0 are currently reusable.

CPU 0.18s/0.52u sec elapsed 9.44 sec.

INFO:  index "ixprintjobsdescpages" now contains 622972 row versions
in 1748 pages

DETAIL:  9526 index row versions were removed.

24 index pages have been deleted, 0 are currently reusable.

CPU 0.06s/0.26u sec elapsed 0.94 sec.

INFO:  index "ixprintjobspagesperjob" now contains 622972 row versions
in 5259 pages

DETAIL:  9526 index row versions were removed.

4 index pages have been deleted, 0 are currently reusable.

CPU 0.31s/0.36u sec elapsed 5.47 sec.

INFO:  "tblprintjobs": removed 9526 row versions in 307 pages

DETAIL:  CPU 0.00s/0.06u sec elapsed 0.23 sec.

INFO:  "tblprintjobs": found 9526 removable, 622972 nonremovable row
versions in 19382 pages

DETAIL:  0 dead row versions cannot be removed yet.

There were 75443 unused item pointers.

0 pages are entirely empty.

CPU 3.43s/6.83u sec elapsed 97.86 sec.

INFO:  vacuuming "pg_toast.pg_toast_2169880"

INFO:  index "pg_toast_2169880_index" now contains 0 row versions in 1
pages

DETAIL:  0 index pages have been deleted, 0 are currently reusable.

CPU 0.00s/0.00u sec elapsed 0.00 sec.

INFO:  "pg_toast_2169880": found 0 removable, 0 nonremovable row
versions in 0 pages

DETAIL:  0 dead row versions cannot be removed yet.

There were 0 unused item pointers.

0 pages are entirely empty.

CPU 0.00s/0.00u sec elapsed 0.00 sec.

VACUUM

rvponp=#




On 13 Jun 2005, at 10:54, Mark Kirkwood wrote:


<excerpt>Apologies - I should have said output of 'VACUUM VERBOSE
mytable'.


(been using 8.1, which displays dead tuple info in ANALYZE...).


Mark


Yves Vindevogel wrote:

<excerpt>rvponp=# analyze verbose tblPrintjobs ;

INFO: analyzing "public.tblprintjobs"

INFO: "tblprintjobs": 19076 pages, 3000 rows sampled, 588209 estimated
total rows

ANALYZE

On 13 Jun 2005, at 04:43, Mark Kirkwood wrote:

    Yves Vindevogel wrote:

        I'm trying to update a table that has about 600.000 records.

        The update query is very simple : update mytable set pagesdesc =

        - pages ;

        The query takes about half an hour to an hour to execute. I
have

        tried a lot of things.

    Half an hour seem a bit long - I would expect less than 5 minutes
on

    reasonable hardware.

    You may have dead tuple bloat - can you post the output of 'ANALYZE

    VERBOSE mytable' ?

</excerpt>


</excerpt>Met vriendelijke groeten,

Bien à vous,

Kind regards,


<bold>Yves Vindevogel</bold>

<bold>Implements</bold>

<smaller>

</smaller>rvponp=# vacuum verbose tblPrintjobs ;
INFO:  vacuuming "public.tblprintjobs"
INFO:  index "pkprintjobs" now contains 622972 row versions in 8410
pages
DETAIL:  9526 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.60s/0.31u sec elapsed 31.68 sec.
INFO:  index "uxprintjobs" now contains 622972 row versions in 3978
pages
DETAIL:  9526 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.15s/0.48u sec elapsed 3.59 sec.
INFO:  index "ixprintjobsipaddress" now contains 622972 row versions in
2542 pages
DETAIL:  9526 index row versions were removed.
49 index pages have been deleted, 0 are currently reusable.
CPU 0.13s/0.24u sec elapsed 2.57 sec.
INFO:  index "ixprintjobshostname" now contains 622972 row versions in
2038 pages
DETAIL:  9526 index row versions were removed.
35 index pages have been deleted, 0 are currently reusable.
CPU 0.09s/0.30u sec elapsed 1.14 sec.
INFO:  index "ixprintjobsrecordnumber" now contains 622972 row versions
in 1850 pages
DETAIL:  9526 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.07s/0.28u sec elapsed 1.51 sec.
INFO:  index "ixprintjobseventdate" now contains 622972 row versions in
1408 pages
DETAIL:  9526 index row versions were removed.
4 index pages have been deleted, 0 are currently reusable.
CPU 0.05s/0.24u sec elapsed 2.61 sec.
INFO:  index "ixprintjobseventtime" now contains 622972 row versions in
1711 pages
DETAIL:  9526 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.12s/0.53u sec elapsed 11.66 sec.
INFO:  index "ixprintjobseventcomputer" now contains 622972 row
versions in 2039 pages
DETAIL:  9526 index row versions were removed.
36 index pages have been deleted, 0 are currently reusable.
CPU 0.12s/0.23u sec elapsed 1.27 sec.
INFO:  index "ixprintjobseventuser" now contains 622972 row versions in
2523 pages
DETAIL:  9526 index row versions were removed.
19 index pages have been deleted, 0 are currently reusable.
CPU 0.14s/0.24u sec elapsed 1.74 sec.
INFO:  index "ixprintjobsloginuser" now contains 622972 row versions in
2114 pages
DETAIL:  9526 index row versions were removed.
13 index pages have been deleted, 0 are currently reusable.
CPU 0.07s/0.32u sec elapsed 4.29 sec.
INFO:  index "ixprintjobsprintqueue" now contains 622972 row versions
in 2201 pages
DETAIL:  9526 index row versions were removed.
30 index pages have been deleted, 0 are currently reusable.
CPU 0.10s/0.34u sec elapsed 1.92 sec.
INFO:  index "ixprintjobsprintport" now contains 622972 row versions in
3040 pages
DETAIL:  9526 index row versions were removed.
40 index pages have been deleted, 0 are currently reusable.
CPU 0.18s/0.27u sec elapsed 2.63 sec.
INFO:  index "ixprintjobssize" now contains 622972 row versions in 1733
pages
DETAIL:  9526 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.16s/0.43u sec elapsed 4.07 sec.
INFO:  index "ixprintjobspages" now contains 622972 row versions in
1746 pages
DETAIL:  9526 index row versions were removed.
24 index pages have been deleted, 0 are currently reusable.
CPU 0.13s/0.22u sec elapsed 1.58 sec.
INFO:  index "ixprintjobsapplicationtype" now contains 622972 row
versions in 1395 pages
DETAIL:  9526 index row versions were removed.
27 index pages have been deleted, 0 are currently reusable.
CPU 0.07s/0.29u sec elapsed 1.20 sec.
INFO:  index "ixprintjobsusertype" now contains 622972 row versions in
1393 pages
DETAIL:  9526 index row versions were removed.
24 index pages have been deleted, 0 are currently reusable.
CPU 0.07s/0.22u sec elapsed 0.82 sec.
INFO:  index "ixprintjobsdocumentname" now contains 622972 row versions
in 4539 pages
DETAIL:  9526 index row versions were removed.
6 index pages have been deleted, 0 are currently reusable.
CPU 0.24s/0.38u sec elapsed 5.83 sec.
INFO:  index "ixprintjobsdesceventdate" now contains 622972 row
versions in 1757 pages
DETAIL:  9526 index row versions were removed.
4 index pages have been deleted, 0 are currently reusable.
CPU 0.08s/0.25u sec elapsed 1.16 sec.
INFO:  index "ixprintjobsdesceventtime" now contains 622972 row
versions in 1711 pages
DETAIL:  9526 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.18s/0.52u sec elapsed 9.44 sec.
INFO:  index "ixprintjobsdescpages" now contains 622972 row versions in
1748 pages
DETAIL:  9526 index row versions were removed.
24 index pages have been deleted, 0 are currently reusable.
CPU 0.06s/0.26u sec elapsed 0.94 sec.
INFO:  index "ixprintjobspagesperjob" now contains 622972 row versions
in 5259 pages
DETAIL:  9526 index row versions were removed.
4 index pages have been deleted, 0 are currently reusable.
CPU 0.31s/0.36u sec elapsed 5.47 sec.
INFO:  "tblprintjobs": removed 9526 row versions in 307 pages
DETAIL:  CPU 0.00s/0.06u sec elapsed 0.23 sec.
INFO:  "tblprintjobs": found 9526 removable, 622972 nonremovable row
versions in 19382 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 75443 unused item pointers.
0 pages are entirely empty.
CPU 3.43s/6.83u sec elapsed 97.86 sec.
INFO:  vacuuming "pg_toast.pg_toast_2169880"
INFO:  index "pg_toast_2169880_index" now contains 0 row versions in 1
pages
DETAIL:  0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  "pg_toast_2169880": found 0 removable, 0 nonremovable row
versions in 0 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
VACUUM
rvponp=#



On 13 Jun 2005, at 10:54, Mark Kirkwood wrote:

> Apologies - I should have said output of 'VACUUM VERBOSE mytable'.
>
> (been using 8.1, which displays dead tuple info in ANALYZE...).
>
> Mark
>
> Yves Vindevogel wrote:
>> rvponp=# analyze verbose tblPrintjobs ;
>> INFO: analyzing "public.tblprintjobs"
>> INFO: "tblprintjobs": 19076 pages, 3000 rows sampled, 588209
>> estimated total rows
>> ANALYZE
>> On 13 Jun 2005, at 04:43, Mark Kirkwood wrote:
>>     Yves Vindevogel wrote:
>>         I'm trying to update a table that has about 600.000 records.
>>         The update query is very simple : update mytable set
>> pagesdesc =
>>         - pages ;
>>         The query takes about half an hour to an hour to execute. I
>> have
>>         tried a lot of things.
>>     Half an hour seem a bit long - I would expect less than 5 minutes
>> on
>>     reasonable hardware.
>>     You may have dead tuple bloat - can you post the output of
>> 'ANALYZE
>>     VERBOSE mytable' ?
>
>
Met vriendelijke groeten,
Bien à vous,
Kind regards,

Yves Vindevogel
Implements

<smaller>


Mail: yves.vindevogel@implements.be  - Mobile: +32 (478) 80 82 91


Kempische Steenweg 206 - 3500 Hasselt - Tel-Fax: +32 (11) 43 55 76


Web: http://www.implements.be

<italic><x-tad-smaller>

First they ignore you.  Then they laugh at you.  Then they fight you.
Then you win.

Mahatma Ghandi.</x-tad-smaller></italic></smaller>



Mail: yves.vindevogel@implements.be  - Mobile: +32 (478) 80 82 91

Kempische Steenweg 206 - 3500 Hasselt - Tel-Fax: +32 (11) 43 55 76

Web: http://www.implements.be

First they ignore you.  Then they laugh at you.  Then they fight you.
Then you win.
Mahatma Ghandi.