DomainKey-Signature: a=rsa-sha1; s=beta; d=google.com; c=nofws; q=dns;
	h=dkim-signature:message-id:date:from:user-agent:
	mime-version:to:cc:subject:references:in-reply-to:content-type:x-system-of-record;
	b=JVrWfANku63CImU5VF2hQaPOQSvFoMAslWxfLtYmXBTNI9LB4A71MoEK/sraRfoMc
	DUqlowsWf1wRcplHDp+YQ==
Message-ID: <4EAEAC21.5080209@google.com>
Date: Mon, 31 Oct 2011 15:09:37 +0100
From: =?ISO-8859-1?Q?S=F6ren_Meyer-Eppler?= <soerenme@google.com>
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64;
	rv:7.0.1) Gecko/20110929 Thunderbird/7.0.1
MIME-Version: 1.0
To: Tom Lane <tgl@sss.pgh.pa.us>
CC: pgsql-performance@postgresql.org
Subject: Re: PostgreSQL 9.0.4 blocking in lseek?
References: <4EA82B7C.1040008@google.com> <9398.1319761978@sss.pgh.pa.us>
In-Reply-To: <9398.1319761978@sss.pgh.pa.us>
Content-Type: multipart/mixed; boundary="------------000502060102070803060803"

This is a multi-part message in MIME format.
--------------000502060102070803060803
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 8bit

> embedded in often-executed plpgsql functions, for instance.  Can you
> identify which table the lseeks are issued against?

I wouldn't know how? I'm just using htop and "s" on the postgres process 
to find these...

> (Now, having said that, I don't see how that type of theory explains no
> CPU load.

My bad sorry. I was relaying information from the guy administering the 
server. It turns out that "no CPU load" really meant: only one of the 
cores is being utilized. On a 16 core machine that looks like "no load" 
but of course for the individual query still means 100%.

> But you're really going to need to provide more info before
> anyone can explain it, and finding out what the lseeks are on would be
> one good step.)

I have attached two of the offending execution plans. Anything obviously 
wrong with them?

thank you for looking into it!

     Sören

--------------000502060102070803060803
Content-Type: text/plain;
 name="execution_plans.txt"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
 filename="execution_plans.txt"

"Insert  (cost=51.21..51.24 rows=1 width=26) (actual time=0.016..0.016 rows=0 loops=1)"
"  ->  Subquery Scan on "*SELECT*"  (cost=51.21..51.24 rows=1 width=26) (actual time=0.014..0.014 rows=0 loops=1)"
"        ->  Sort  (cost=51.21..51.22 rows=1 width=8) (actual time=0.014..0.014 rows=0 loops=1)"
"              Sort Key: basic_blocks.id"
"              Sort Method:  quicksort  Memory: 25kB"
"              ->  Nested Loop  (cost=0.00..51.20 rows=1 width=8) (actual time=0.010..0.010 rows=0 loops=1)"
"                    ->  Nested Loop  (cost=0.00..42.33 rows=1 width=20) (actual time=0.010..0.010 rows=0 loops=1)"
"                          Join Filter: (bn_functions.address = bn_function_views.function)"
"                          ->  Index Scan using bn_functions_pkey on bn_functions  (cost=0.00..8.34 rows=1 width=8) (actual time=0.009..0.009 rows=0 loops=1)"
"                                Index Cond: (module_id = 82)"
"                                Filter: (type <> 'import'::function_type)"
"                          ->  Index Scan using bn_function_views_module_id_idx on bn_function_views  (cost=0.00..33.77 rows=18 width=12) (never executed)"
"                                Index Cond: (bn_function_views.module_id = 82)"
"                    ->  Index Scan using ex_82_basic_blocks_parent_function_idx on ex_82_basic_blocks basic_blocks  (cost=0.00..8.63 rows=19 width=12) (never executed)"
"                          Index Cond: (basic_blocks.parent_function = bn_functions.address)"
"Total runtime: 0.082 ms"


"Insert  (cost=14581.76..19565.92 rows=11146 width=8) (actual time=2426.967..2426.967 rows=0 loops=1)"
"  ->  Merge Join  (cost=14581.76..19565.92 rows=11146 width=8) (actual time=187.650..537.181 rows=166905 loops=1)"
"        Merge Cond: (destination_function.function = callgraph.destination)"
"        ->  Index Scan using bn_function_nodes_module_id_function_idx on bn_function_nodes destination_function  (cost=0.00..4667.05 rows=43094 width=12) (actual time=0.068..15.326 rows=43346 loops=1)"
"              Index Cond: (module_id = 94)"
"        ->  Sort  (cost=14534.90..14643.30 rows=43360 width=12) (actual time=187.365..225.911 rows=166905 loops=1)"
"              Sort Key: callgraph.destination"
"              Sort Method:  quicksort  Memory: 13968kB"
"              ->  Merge Join  (cost=46.54..11195.29 rows=43360 width=12) (actual time=0.016..121.661 rows=166905 loops=1)"
"                    Merge Cond: (source_function.function = callgraph.source)"
"                    ->  Index Scan using bn_function_nodes_module_id_function_idx on bn_function_nodes source_function  (cost=0.00..4667.05 rows=43094 width=12) (actual time=0.007..14.936 rows=41149 loops=1)"
"                          Index Cond: (module_id = 94)"
"                    ->  Index Scan using ex_94_callgraph_source_idx on ex_94_callgraph callgraph  (cost=0.00..5773.07 rows=166905 width=16) (actual time=0.006..60.455 rows=166905 loops=1)"
"Total runtime: 2434.736 ms"

--------------000502060102070803060803--