Re: Looks like merge join planning time is too big, 55 seconds

On Thu, Aug 1, 2013 at 8:17 AM, Sergey Burladyan <eshkinkot(at)gmail(dot)com> wrote:
> Sergey Burladyan <eshkinkot(at)gmail(dot)com> writes:
>
>> # 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;
>> QUERY PLAN
>> ----------------------------------------------------------------------------------------------
>> Nested Loop Left Join (cost=0.00..397.14 rows=1 width=16)
>> -> Index Scan using items_item_ux on items i (cost=0.00..358.84 rows=1 width=16)
>> Index Cond: (item_id = 169946840)
>> -> Index Only Scan using users_user_id_pkey on users u (cost=0.00..38.30 rows=1 width=8)
>> Index Cond: (user_id = i.user_id)
>>
>> time: 55919.910 ms
>
> While running this EXPLAIN backend use disk for a long time:
> TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
> 21638 be/4 postgres 2.10 M/s 9.45 M/s 0.00 % 69.04 % postgres: postgres xxxxx xxx.xxx.xxx.xxx(50987) EXPLAIN
>
> Why it read and write to disk 10 megabytes per second for EXPLAIN query? Cannot understand what is going on here :(

I'd use strace to find what file handle is being read and written, and
lsof to figure out what file that is.

It looks like it is more write than read, which does seem strange.

Any chance you can create a self-contained test case?

Cheers,

Jeff