Re: Strange behaviour of Cramer query
Date: Wed, 24 Jun 2009 06:41:06 -0700 (PDT)
Message-ID: <d897f3a1-d7c7-4aa2-ae68-3fc066a261db_at_33g2000vbe.googlegroups.com>
On Jun 24, 8:41 am, HansP <hans-peter.sl..._at_atosorigin.com> wrote:
> OS: Solaris 5.10
> Oracle: 10.2.0.2
> Application: Cramer see http://en.wikipedia.org/wiki/Cramer_Systems
>
> I was ask to look at a performance issue on a database used for
> Cramer.
>
> A stored procedure is executed which executes a couple of queries and
> returns some data.
>
> Like :
> PL/SQL procedure successfully completed.
>
> Elapsed: 00:00:01.33
>
> After a couple of tries the Elapsed time goes up to 20 minutes. So no
> caching issues. Because
> After cancelling the next execution is quick again.
>
> I did traced both cases.
> The strange thing is that execution plan is in both cases the same
> except for the numer of rows returned by the steps.
> The explain plan is 228 lines long so I will not copy in the complete
> plan but just the last lines.
>
> Fast execution:
> 0 BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)
> 0 INDEX FAST FULL SCAN CC_UK (cr=0 pr=0 pw=0 time=0 us)(object id
> 191358)
> 0 TABLE ACCESS BY INDEX ROWID CIRCUIT (cr=0 pr=0 pw=0 time=0 us)
> 0 INDEX UNIQUE SCAN CCT_PK (cr=0 pr=0 pw=0 time=0 us)(object id
> 191354)
> 3 TABLE ACCESS BY INDEX ROWID SERVICEOBJECT (cr=12 pr=0 pw=0 time=116
> us)
> 3 INDEX RANGE SCAN SEROBJ_OBJ_I (cr=9 pr=0 pw=0 time=69 us)(object id
> 192668)
> 3 TABLE ACCESS BY INDEX ROWID SERVICE (cr=9 pr=0 pw=0 time=60 us)
> 3 INDEX UNIQUE SCAN SERV_PK (cr=6 pr=0 pw=0 time=38 us)(object id
> 192658
>
> Slow execution:
> 9112536 BUFFER SORT (cr=149 pr=18090 pw=90 time=1151263 us)
> 45336 INDEX FAST FULL SCAN CC_UK (cr=149 pr=0 pw=0 time=70 us)(object
> id 191358)
> 9112536 TABLE ACCESS BY INDEX ROWID CIRCUIT (cr=18225074 pr=0 pw=0
> time=68090494 us)
> 9112536 INDEX UNIQUE SCAN CCT_PK (cr=9112538 pr=0 pw=0 time=31488868
> us)(object id 191354)
> 3 TABLE ACCESS BY INDEX ROWID SERVICEOBJECT (cr=12 pr=0 pw=0 time=269
> us)
> 3 INDEX RANGE SCAN SEROBJ_OBJ_I (cr=9 pr=0 pw=0 time=110 us)(object id
> 192668)
> 3 TABLE ACCESS BY INDEX ROWID SERVICE (cr=9 pr=0 pw=0 time=87 us)
> 3 INDEX UNIQUE SCAN SERV_PK (cr=6 pr=0 pw=0 time=56 us)(object id
> 192658)
>
> v$sql_plan shows only 1 plan.
>
> Does anyone have clue?
> Statistics cannot be the issue because the remain the same between
> executions.
>
> regards HansP
I did not study your post in detail but skewed data can result in drastically different run times for the same plan with different data. Example. There is an index on a column with only a few distinct values, say 6. One value is 80% of the data. If the query uses the index on any of the 5 other values the response is very fast, 5 seconds. However, query on the one value that is 80% of the data and the run time is now 1.5 minutes. The reason is that indexed access is not the best access for the one data value but is for the other 5 values.
What we did to fix the issue was place an if test in the code for the one value and in that case we ran the sql the way the CBO wanted to (full scan) and for all other values we added an index hint.
You should try to determine if the jump in rows processed is due to the data values being searched on. Being a canned product you may not be able to change the code but you still need to know what/why this is happening. You might be able to use a SQL Profile or Outline to manipulate the SQL.
Look at the query plan and try to determine if a better join order would avoid the issue or you may have to rewrite the query to follow the best path for the worst case data and lose some performance for most of the value but get a consistent response time from the query. You can then contact the vendor with you test results and see if you can get help.
If you do have access to the source then you could potentially implement any fix you find.
HTH -- Mark D Powell -- Received on Wed Jun 24 2009 - 08:41:06 CDT