From: Sergey Burladyan <eshkinkot@gmail.com>
To: Jeff Janes <jeff.janes@gmail.com>
Cc: pgsql-performance\@postgresql.org <pgsql-performance@postgresql.org>
Subject: Re: Looks like merge join planning time is too big, 55 seconds
Date: Thu, 01 Aug 2013 23:13:26 +0400
Message-ID: <87li4lusvd.fsf@seb.koffice.internal> (raw)
In-Reply-To: <CAMkU=1zyWZEC0YfQ0D4obWWHZqcLoLApUzf-f2+LOVH2ib=s_g@mail.gmail.com>
References: <CAJ2ymdjK-+LZHFY+cskRq98c_4F1PEfveOVNbNGpWL0Pczy5Ew@mail.gmail.com>
<8761vpwid4.fsf@seb.koffice.internal>
<CAMkU=1zyWZEC0YfQ0D4obWWHZqcLoLApUzf-f2+LOVH2ib=s_g@mail.gmail.com>
List-Unsubscribe: <mailto:majordomo@postgresql.org?body=unsub%20pgsql-performance>
Jeff Janes <jeff.janes@gmail.com> writes:
> I'd use strace to find what file handle is being read and written, and
> lsof to figure out what file that is.
I use strace, it is more read then write:
$ cut -d '(' -f 1 /var/tmp/pg.trace | sort | uniq -c | sort -n
49 select
708 close
1021 open
7356 write
212744 read
219650 lseek
top reads:
7859 read(150 open("base/16444/17685.129", O_RDWR|O_CREAT, 0600) = 150
9513 read(149 open("base/16444/17685.128", O_RDWR|O_CREAT, 0600) = 149
10529 read(151 open("base/16444/17685.130", O_RDWR|O_CREAT, 0600) = 151
12155 read(152 open("base/16444/17685.131", O_RDWR|O_CREAT, 0600) = 152
12768 read(154 open("base/16444/17685.133", O_RDWR|O_CREAT, 0600) = 154
16210 read(153 open("base/16444/17685.132", O_RDWR|O_CREAT, 0600) = 153
it is 'items' table:
select relname from pg_class where relfilenode = 17685;
relname
---------
items
each read is 8192 bytes, so for EXPLAIN query with two simple index scan, *without* ANALYZE postgres
read (7859 + 9513 + 10529 + 12155 + 12768 + 16210) * 8192 = 565 526 528 bytes from it.
> It looks like it is more write than read, which does seem strange.
Why it read something for simple EXPLAIN, without real executing query? :-)
> Any chance you can create a self-contained test case?
I think I cannot do this, it is ~1 Tb heavily load database. This is at standby server.
PS: two strace for quick and slow explain:
explain
select i.item_id from items i
where item_id = 169946840
$ cut -d '(' -f 1 /var/tmp/pg-all-normal.trace | sort | uniq -c
313 lseek
308 open
2 read
13 recvfrom
6 sendto
explain
select i.item_id, u.user_id from items i
left join users u on u.user_id = i.user_id
where item_id = 169946840
$ cut -d '(' -f 1 /var/tmp/pg-all-slow.trace | sort | uniq -c
963 close
1 fsync
5093393 lseek
925 open
6004995 read
14 recvfrom
1 rt_sigreturn
9 select
4361 semop
7 sendto
1 --- SIGUSR1
685605 write
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
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: eshkinkot@gmail.com, jeff.janes@gmail.com
Subject: Re: Looks like merge join planning time is too big, 55 seconds
In-Reply-To: <87li4lusvd.fsf@seb.koffice.internal>
* 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