From: Tom Lane <tgl@sss.pgh.pa.us>
To: Rainer Pruy <Rainer.Pruy@Acrys.COM>
Cc: pgsql-performance@postgresql.org <pgsql-performance@postgresql.org>
Subject: Re: Query slowing down significantly??
Date: Mon, 01 Mar 2010 11:15:32 -0500
Message-ID: <17910.1267460132@sss.pgh.pa.us> (raw)
In-Reply-To: <4B8BB815.4060104@acrys.com>
References: <4B8BB815.4060104@acrys.com>
Rainer Pruy <Rainer.Pruy@Acrys.COM> writes:
> Normally the following Query behaves well:
> select c.*, h.*
> from Context c, Context_Hierarchy h
> where c.Idx = h.ContextIdx and c.ContextId='testID' and h.HierarchyName='InsuranceHierarchy' and h.ParentIdx=49292395
> ;
> QUERY PLAN
> ------------------------------------------------------------------------------------------------------------------------------------------------------
> Nested Loop (cost=0.00..43.57 rows=4 width=175) (actual time=0.291..0.293 rows=1 loops=1)
> -> Index Scan using uk_context_hierarchy_01 on context_hierarchy h (cost=0.00..14.76 rows=4 width=108) (actual time=0.169..0.169
> rows=1 loops=1)
> Index Cond: (((hierarchyname)::text = 'InsuranceHierarchy'::text) AND (parentidx = 49292395))
> -> Index Scan using pk_context on context c (cost=0.00..7.20 rows=1 width=67) (actual time=0.110..0.111 rows=1 loops=1)
> Index Cond: (c.idx = h.contextidx)
> Filter: ((c.contextid)::text = 'testID'::text)
> Total runtime: 0.388 ms
> (7 rows)
> (From a freshly started PG)
> However during a long term read-only transaction (actually just bout 15min)
> (the transaction is issuing about 10k-20k of such queries among others)
> PG is logging a number of the following:
> Mar 1 09:58:09 gaia postgres[20126]: [25-1] LOG: 00000: duration: 343.663 ms execute S_5: select c.*, h.Idx as h_Idx, h.WbuIdx as
> h_WbuIdx, h.OrigWbuIdx as h_OrigWbuIdx, h.Ts as h_Ts, h.
> UserId as h_UserId, h.ParentIdx as h_ParentIdx, h.ContextIdx as h_ContextIdx, h.HierarchyName as h_HierarchyName, h.HierarchyPath as
> h_HierarchyPath from Context c, Context_Hierarchy h wher
> e c.Idx = h.ContextIdx and c.ContextId=$1 and h.HierarchyName=$2 and h.ParentIdx=$3
> Mar 1 09:58:09 gaia postgres[20126]: [25-2] DETAIL: parameters: $1 = 'testID', $2 = 'InsuranceHierarchy', $3 = '49292395'
> Mar 1 09:58:09 gaia postgres[20126]: [25-3] LOCATION: exec_execute_message, postgres.c:1988
That's not the same query at all, and it may not be getting the same
plan. What you need to do to check the plan is to try PREPARE-ing
and EXPLAIN EXECUTE-ing the query with the same parameter symbols
as are actually used in the application-issued query.
You might be entertained by the recent thread on -hackers about
"Avoiding bad prepared-statement plans" ...
regards, tom lane
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: tgl@sss.pgh.pa.us, Rainer.Pruy@Acrys.COM
Subject: Re: Query slowing down significantly??
In-Reply-To: <17910.1267460132@sss.pgh.pa.us>
* 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