Re: Oracle Locator performance issue (10046 trace data)

From: Stefan Koehler <contact_at_soocs.de>
Date: Fri, 25 Oct 2019 13:30:44 +0200 (CEST)
Message-ID: <1933283454.471136.1572003044503_at_ox.hosteurope.de>


Hello Chris,

> Trace data shows a single fetch call accounts for vast majority of response time. I don't know if this is due to lack of instrumentation w/ locator or something else.

Might it be possible that you have traced the PX COORDINATOR only? You have a PQ and so it is very like that the elapsed time of "FETCH #140556737969632:c=70530,e=580279740" is spent in its slaves :)

I think the best way would be to run the SQL as unique statement with rowsource statistics enabled (e.g. gather_plan_statistics, statistics_level, _rowsource_execution_statistics) and then use DBMS_XPLAN without last option. Afterwards you can go deeper with traces if still needed :-)

Best Regards
Stefan Koehler

Independent Oracle performance consultant and researcher Website: http://www.soocs.de
Twitter: _at_OracleSK

> Chris Stephens <cstephens16_at_gmail.com> hat am 24. Oktober 2019 um 21:01 geschrieben:
>
> We are starting to mess with Oracle Locator some and immediately hit performance issue. Trace data shows a single fetch call accounts for vast majority of response time. I don't know if this is due to lack of instrumentation w/ locator or something else. Does anyone have experience w/ this kind of this that might be able to provide some insight?
> Oracle 12.2 
> *** 2019-10-24T12:57:20.329694-05:00
> FETCH #140556737969632:c=70530,e=580279740,p=0,cr=0,cu=0,mis=0,r=20,dep=0,og=1,plh=2353454263,tim=10624057091673
> STAT #140556737969632 id=1 cnt=20 pid=0 pos=1 obj=0 op='COUNT STOPKEY (cr=0 pr=0 pw=0 str=1 time=580294149 us)'
> STAT #140556737969632 id=2 cnt=20 pid=1 pos=1 obj=0 op='PX COORDINATOR  (cr=0 pr=0 pw=0 str=1 time=580294109 us)'
> STAT #140556737969632 id=3 cnt=0 pid=2 pos=1 obj=0 op='PX SEND QC (ORDER) :TQ10001 (cr=0 pr=0 pw=0 str=0 time=0 us cost=24196 size=64309407 card=691499)'
> STAT #140556737969632 id=4 cnt=0 pid=3 pos=1 obj=0 op='VIEW  (cr=0 pr=0 pw=0 str=0 time=0 us cost=24196 size=64309407 card=691499)'
> STAT #140556737969632 id=5 cnt=0 pid=4 pos=1 obj=0 op='SORT ORDER BY STOPKEY (cr=0 pr=0 pw=0 str=0 time=0 us cost=24196 size=43564437 card=691499)'
> STAT #140556737969632 id=6 cnt=0 pid=5 pos=1 obj=0 op='PX RECEIVE  (cr=0 pr=0 pw=0 str=0 time=0 us cost=13731 size=43564437 card=691499)'
> STAT #140556737969632 id=7 cnt=0 pid=6 pos=1 obj=0 op='PX SEND RANGE :TQ10000 (cr=0 pr=0 pw=0 str=0 time=0 us cost=13731 size=43564437 card=691499)'
> STAT #140556737969632 id=8 cnt=0 pid=7 pos=1 obj=0 op='PX PARTITION RANGE ALL PARTITION: 1 16 (cr=0 pr=0 pw=0 str=0 time=0 us cost=13731 size=43564437 card=691499)'
> STAT #140556737969632 id=9 cnt=0 pid=8 pos=1 obj=0 op='SORT ORDER BY STOPKEY (cr=0 pr=0 pw=0 str=0 time=0 us)'
> STAT #140556737969632 id=10 cnt=0 pid=9 pos=1 obj=714991 op='TABLE ACCESS BY LOCAL INDEX ROWID Y6A1_LOCATOR PARTITION: 1 16 (cr=0 pr=0 pw=0 str=0 time=0 us cost=13731 size=43564437 card=691499)'
> STAT #140556737969632 id=11 cnt=0 pid=10 pos=1 obj=715087 op='DOMAIN INDEX (SEL: 0.100000 %) Y6A1_LOCATOR_GEO_BTX (cr=0 pr=0 pw=0 str=0 time=0 us cost=5 size=0 card=0)'
> EXEC #140556737964464:c=87,e=87,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=10624057093221
> XCTEND rlbk=0, rd_only=1, tim=10624057093262

--
http://www.freelists.org/webpage/oracle-l
Received on Fri Oct 25 2019 - 13:30:44 CEST

Original text of this message