Re: Query slowing down significantly?? - Mailing list pgsql-performance
From | Rainer Pruy |
---|---|
Subject | Re: Query slowing down significantly?? |
Date | |
Msg-id | 4B8BFDEF.1080006@acrys.com Whole thread Raw |
In response to | Re: Query slowing down significantly?? (Tom Lane <tgl@sss.pgh.pa.us>) |
Responses |
Re: Query slowing down significantly??
Re: Query slowing down significantly?? |
List | pgsql-performance |
Thanks for the hint. I should have been considering that in the first place. (But the obvious is easily left unrecognised..) The prepared statement gives: QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------- Nested Loop (cost=0.00..25.18 rows=2 width=175) (actual time=36.116..49.998 rows=1 loops=1) -> Index Scan using x_context_01 on context c (cost=0.00..10.76 rows=2 width=67) (actual time=0.029..6.947 rows=12706loops=1) Index Cond: ((contextid)::text = $1) -> Index Scan using x_fk_context_hierarchy_02 on context_hierarchy h (cost=0.00..7.20 rows=1 width=108) (actual time=0.003..0.003 rows=0 loops=12706) Index Cond: (h.contextidx = c.idx) Filter: (((h.hierarchyname)::text = $2) AND (h.parentidx = $3)) Total runtime: 50.064 ms (7 rows) And that is quite a bad plan given the current distribution of values. Regards, Rainer Am 01.03.2010 17:15, schrieb Tom Lane: > 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.HierarchyPathas >> 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
pgsql-performance by date: