| From: | Jon Nelson <jnelson+pgsql(at)jamponi(dot)net> |
|---|---|
| To: | pgsql-performance(at)postgresql(dot)org |
| Subject: | odd postgresql performance (excessive lseek) |
| Date: | 2010-10-14 20:00:32 |
| Message-ID: | AANLkTikS8ptnCVJK+6u-Z3Xh8WMKdgq+T+trdxt3xgYB@mail.gmail.com |
| Views: | Raw Message | Whole Thread | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-performance |
postgres 8.4.4 on openSUSE 11.3 (2.6.36rc7, x86_64).
I was watching a fairly large query run and observed that the disk
light went out. I checked 'top' and postgres was using 100% CPU so I
strace'd the running process.
This is what I saw:
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(87, 0, SEEK_END) = 585531392
lseek(94, 270680064, SEEK_SET) = 270680064
read(94, "<elided>"..., 8192) = 8192
and I observed that pattern quite a bit.
I know lseek is cheap, but a superfluous systemcall is a superfluous
systemcall, and over a short period amounted to 37% (according to
strace) of the time spent in the system.
What's with the excess calls to lseek?
The query plan was a nested loop anti-join (on purpose).
--
Jon
| From | Date | Subject | |
|---|---|---|---|
| Next Message | Jon Nelson | 2010-10-14 20:10:01 | Re: oracle to psql migration - slow query in postgres |
| Previous Message | Robert Haas | 2010-10-14 19:56:05 | Re: Slow count(*) again... |