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

What else I don't understand is that an update is so slow, whereas this


rvponp=# insert into tblTest (id, descpages) select oid, -pages from
tblPrintjobs ;

INSERT 0 622972

rvponp=# delete from tblTest ;

DELETE 622972

rvponp=#


takes about 1 minute for the insert, and 5 seconds for the delete.



On 13 Jun 2005, at 13:51, Yves Vindevogel wrote:


<excerpt><excerpt>

I have started this on my testmachine at 11h20.  It's still running
and here it's 13h40.


Setup:

Intel P4 2Ghz, 1 Gb ram

ReiserFS 3 (with atime in fstab, which is not optimal)

Slackware 10

PG 7.4


I have the same problems on my OSX and other test machines.


It's frustrating.  Even Microsoft Access is faster !!


On 13 Jun 2005, at 11:02, Yves Vindevogel wrote:


<excerpt>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><<Pasted Graphic 2.tiff><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></excerpt></excerpt></excerpt><excerpt><excerpt><excerpt>




---------------------------(end of
broadcast)---------------------------

TIP 7: don't forget to increase your free space map settings


</excerpt>Met vriendelijke groeten,

Bien à vous,

Kind regards,


<bold>Yves Vindevogel</bold>

<bold>Implements</bold>

<smaller>

</smaller></excerpt><<Pasted Graphic 2.tiff><smaller>

<excerpt>

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></excerpt></smaller></excerpt><excerpt><excerpt>



</excerpt>Met vriendelijke groeten,

Bien à vous,

Kind regards,


<bold>Yves Vindevogel</bold>

<bold>Implements</bold>

<smaller>

</smaller><<Pasted Graphic 2.tiff><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></excerpt><excerpt>


---------------------------(end of
broadcast)---------------------------

TIP 1: subscribe and unsubscribe commands go to
majordomo@postgresql.org


</excerpt>Met vriendelijke groeten,

Bien à vous,

Kind regards,


<bold>Yves Vindevogel</bold>

<bold>Implements</bold>

<smaller>

</smaller>What else I don't understand is that an update is so slow, whereas this

rvponp=# insert into tblTest (id, descpages) select oid, -pages from
tblPrintjobs ;
INSERT 0 622972
rvponp=# delete from tblTest ;
DELETE 622972
rvponp=#

takes about 1 minute for the insert, and 5 seconds for the delete.


On 13 Jun 2005, at 13:51, Yves Vindevogel wrote:

>>
>> I have started this on my testmachine at 11h20.  It's still running
>> and here it's 13h40.
>>
>> Setup:
>> Intel P4 2Ghz, 1 Gb ram
>> ReiserFS 3 (with atime in fstab, which is not optimal)
>> Slackware 10
>> PG 7.4
>>
>> I have the same problems on my OSX and other test machines.
>>
>> It's frustrating.  Even Microsoft Access is faster !!
>>
>> On 13 Jun 2005, at 11:02, Yves Vindevogel wrote:
>>
>>> 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
>>>
>>> <Pasted Graphic 2.tiff>
>>>
>>> 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.
>>>
>>>
>>>
>>> ---------------------------(end of
>>> broadcast)---------------------------
>>> TIP 7: don't forget to increase your free space map settings
>>>
>> Met vriendelijke groeten,
>> Bien à vous,
>> Kind regards,
>>
>> Yves Vindevogel
>> Implements
>>
> <Pasted Graphic 2.tiff>
>>
>> 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.
>>
>>
> Met vriendelijke groeten,
> Bien à vous,
> Kind regards,
>
> Yves Vindevogel
> Implements
>
> <Pasted Graphic 2.tiff>
>
> 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.
>
> ---------------------------(end of
> broadcast)---------------------------
> TIP 1: subscribe and unsubscribe commands go to
> majordomo@postgresql.org
>
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.