Re: catsearch and latch: cache buffers chains waits

  • From: Tanel Poder <tanel@xxxxxxxxxx>
  • To: oracledbaquestions@xxxxxxxxx
  • Date: Sat, 27 Feb 2010 00:08:31 +0800

First I'd ask that how big % of your session's response time was wasted
waiting for latches? Sometimes people troubleshoot the wrong symptom (like
cases where 99% of response time was spent on CPU and 1% waiting for
latches).

In addition to bad design, like running some PL/SQL lookup function for each
row in SQL resultset,  cache buffers chains latch contention often happens
due an execution plan flip, where some SQL starts hammering a small set of
data blocks due a wrongly ordered nested loop plan. Of course it always
takes more than 1 process/session to have any kind of latch (or lock)
contention, at least one holder of the lock and at least one waiter.

Btw, if you want to systematically troubleshoot any latch contention, then
you can use my latchprofx script for drilling down to details:

http://blog.tanelpoder.com/2010/02/15/new-versions-of-latchprof-and-latchprofx-for-latch-contention-troubleshooting-and-tuning/

--
Tanel Poder
http://tech.e2sn.com
http://blog.tanelpoder.com



On Fri, Feb 26, 2010 at 10:23 PM, Dba DBA <oracledbaquestions@xxxxxxxxx>wrote:

> I am trying to tune a query that uses the catsearch function and this
> appears to be the problem. I first looked at the event in v$session and
> noticed latch: cache buffers chains. This typically indicates excess
> parsing, but this is just 1 query?
>
> So I am running a 10046 trace and I am seeing something interesting. It
> appears that catsearch execute a query over and over again. Similiar to
> having a function in your query.
>
> I am also noticing that it executes for each row returned for each keyword.
> This is causing excess parsing.
>
> has anyone used catsearch before? This does not seem to be very efficient.
> It is using my ctxcat index. Here is a sample of one of the parses in the
> 10046 trace. This happens over and over again in my trace file.
>
>
> PARSING IN CURSOR #8 len=247 dep=1 uid=13686 oct=3 lid=13686
> tim=25146063685495 hv=2206871408 ad='c5437b70'
> select /*+ INDEX_ASC(i "DR$MYPOLICY$X") */ dr$rowid     from
> "DR$MYPOLICY$I" i  where dr$token = :token    and dr$token_type = :ttype
> and DR$ROWID >= :r01  order by dr$token ASC, dr$token_type ASC,  dr$rowid
> ASC
> END OF STMT
> PARSE #8:c=0,e=73,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=25146063685490
> BINDS #8:
>  bind 0: dty=1 mxl=128(64) mal=00 scl=00 pre=00 oacflg=00 oacfl2=0000
> size=184 offset=0
>    bfp=ffffffff7b991790 bln=128 avl=10 flg=05
>    value="TOWNAME"
>  bind 1: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=00 oacfl2=0000 size=0
> offset=128
>    bfp=ffffffff7b991810 bln=22 avl=01 flg=01
>    value=0
>  bind 2: dty=1 mxl=32(18) mal=00 scl=00 pre=00 oacflg=00 oacfl2=0000 size=0
> offset=152
> ^C   bfp=ffffffff7b991828 bln=32 avl=18 flg=01
>    value="AAa8Q5ADYAAAAUQAAn"
> EXEC #8:c=0,e=156349,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=25146063956032
> FETCH #8:c=0,e=250,p=0,cr=3,cu=0,mis=0,r=215,dep=1,og=1,tim=25146064003460
> FETCH #8:c=0,e=241,p=0,cr=1,cu=0,mis=0,r=215,dep=1,og=1,tim=25146064022705
> STAT #8 id=1 cnt=0 pid=0 pos=1 obj=7062703 op='INDEX RANGE SCAN
> DR$MYPOLICY$X (cr=0 pr=0 pw=0 time=0 us)'
>

Other related posts: