pg.ddx.io pgsql-performance@postgresql.org mailing list archive help / color / mirror / Atom feed From: Rafael Martinez <r.m.guerrero@usit.uio.no>
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: pgsql-performance@postgresql.org
Subject: Re: Performance problems deleting data
Date: Tue, 04 Mar 2008 09:28:38 +0100
Message-ID: <47CD0836.2060808@usit.uio.no> (raw )
In-Reply-To: <26742.1204565113@sss.pgh.pa.us >
References: <47CC1139.4070708@usit.uio.no >
<26742.1204565113@sss.pgh.pa.us >
Tom Lane wrote:
> Rafael Martinez <r.m.guerrero@usit.uio.no> writes:
>
>> Any ideas why it is taking 2462558.813 ms to finish when the total time
>> for the deletion is 2.546 ms + 3.422 ms + 0.603ms?
>
Hei Tom, I got this information from my colleague:
> Is the problem repeatable?
Repeatable as in about 30+ times every day, the deletion of a row takes
more than 100 seconds. I have not found a way to provoke it though.
> Is the delay consistent?
No. I see frequently everything from below the 8 seconds
log_min_duration_statement to about 4900 seconds. As for distribution,
about half of the 30+ takes more than 500 seconds to complete, the rest
(obviously) between 100 and 500 seconds.
> What do you see in pg_locks while it's delaying?
locktype | database | relation | page | tuple | transactionid |
classid | objid | objsubid | transaction | pid | mode |
granted
---------------+----------+----------+------+-------+---------------+---------+-------+----------+-------------+-------+------------------+---------
relation | 16393 | 16784 | | | |
| | | 82179843 | 19890 | AccessShareLock | t
relation | 16393 | 16784 | | | |
| | | 82179843 | 19890 | RowExclusiveLock | t
relation | 16393 | 17176 | | | |
| | | 82179843 | 19890 | RowExclusiveLock | t
relation | 16393 | 16794 | | | |
| | | 82180131 | 19907 | AccessShareLock | t
relation | 16393 | 16794 | | | |
| | | 82180131 | 19907 | RowExclusiveLock | t
relation | 16393 | 16977 | | | |
| | | 82179843 | 19890 | AccessShareLock | t
relation | 16393 | 16977 | | | |
| | | 82179843 | 19890 | RowExclusiveLock | t
relation | 16393 | 16800 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16800 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
relation | 16393 | 17174 | | | |
| | | 82179843 | 19890 | RowExclusiveLock | t
transactionid | | | | | 80430155 |
| | | 80430155 | 29569 | ExclusiveLock | t
relation | 16393 | 17164 | | | |
| | | 82179843 | 19890 | AccessShareLock | t
relation | 16393 | 16816 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16816 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
relation | 16393 | 16812 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16812 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
relation | 16393 | 17174 | | | |
| | | 82180131 | 19907 | RowExclusiveLock | t
relation | 16393 | 16977 | | | |
| | | 82180131 | 19907 | AccessShareLock | t
relation | 16393 | 16977 | | | |
| | | 82180131 | 19907 | RowExclusiveLock | t
relation | 16393 | 16784 | | | |
| | | 82180131 | 19907 | AccessShareLock | t
relation | 16393 | 16784 | | | |
| | | 82180131 | 19907 | RowExclusiveLock | t
relation | 16393 | 16766 | | | |
| | | 82179843 | 19890 | AccessShareLock | t
relation | 16393 | 16766 | | | |
| | | 82179843 | 19890 | RowExclusiveLock | t
relation | 16393 | 16977 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16977 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
relation | 16393 | 17164 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16766 | | | |
| | | 82180131 | 19907 | AccessShareLock | t
relation | 16393 | 16766 | | | |
| | | 82180131 | 19907 | RowExclusiveLock | t
relation | 16393 | 10342 | | | |
| | | 82180134 | 31646 | AccessShareLock | t
relation | 16393 | 16794 | | | |
| | | 82179843 | 19890 | AccessShareLock | t
relation | 16393 | 16794 | | | |
| | | 82179843 | 19890 | RowExclusiveLock | t
relation | 16393 | 16835 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16835 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
relation | 16393 | 17176 | | | |
| | | 82180131 | 19907 | RowExclusiveLock | t
relation | 16393 | 16800 | | | |
| | | 82180131 | 19907 | AccessShareLock | t
relation | 16393 | 16800 | | | |
| | | 82180131 | 19907 | RowExclusiveLock | t
relation | 16393 | 16821 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16821 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
relation | 16393 | 17174 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
relation | 16393 | 16730 | | | |
| | | 80430155 | 29569 | AccessShareLock | t
transactionid | | | | | 82179669 |
| | | 82179669 | 19906 | ExclusiveLock | t
relation | 16393 | 16800 | | | |
| | | 82179843 | 19890 | AccessShareLock | t
relation | 16393 | 16800 | | | |
| | | 82179843 | 19890 | RowExclusiveLock | t
relation | 16393 | 16784 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16784 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
relation | 16393 | 16766 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16766 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
relation | 16393 | 16794 | | | |
| | | 82179669 | 19906 | AccessShareLock | t
relation | 16393 | 16794 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
transactionid | | | | | 82180134 |
| | | 82180134 | 31646 | ExclusiveLock | t
transactionid | | | | | 82179843 |
| | | 82179843 | 19890 | ExclusiveLock | t
relation | 16393 | 17176 | | | |
| | | 82179669 | 19906 | RowExclusiveLock | t
transactionid | | | | | 82180131 |
| | | 82180131 | 19907 | ExclusiveLock | t
relation | 16393 | 17164 | | | |
| | | 82180131 | 19907 | AccessShareLock | t
(54 rows)
> Also watch "vmstat 1" output --- is it consuming CPU and/or I/O?
>
>
CPU 50% idle, rest mainly used in "system". Virtually no IO. No
blocked processes. An impressive amount of context switches. No swap.
An strace(1) of the postgres process may give a hint about the "system"
part; this is what it does over and over and over again. The filename
does change to a different file in the same directory every now and
then, but not often.
semop(4227102, 0xbf8ef23a, 1) = 0
semop(4227102, 0xbf8ef67a, 1) = 0
open("pg_subtrans/047B", O_RDWR|O_LARGEFILE) = 12
_llseek(12, 139264, [139264], SEEK_SET) = 0
read(12, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
8192) = 8192
close(12) = 0
regards
--
Rafael Martinez, <r.m.guerrero@usit.uio.no>
Center for Information Technology Services
University of Oslo, Norway
PGP Public Key: http://folk.uio.no/rafael/
view thread (4+ messages) latest in thread
Message-ID: <47CD0836.2060808@usit.uio.no>
Permalink: ../47CD0836.2060808@usit.uio.no/
Also on: postgresql.org/message-id/47CD0836.2060808@usit.uio.no
copy link · copy postgr.es
reply Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-performance@postgresql.org
Cc: r.m.guerrero@usit.uio.no, tgl@sss.pgh.pa.us
Subject: Re: Performance problems deleting data
In-Reply-To: <47CD0836.2060808@usit.uio.no>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox