| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
 |
 | |||
| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
|
| |||
Home -> Community -> Mailing Lists -> Oracle-L -> RE: Cursor Pin S and TKPROF anomaly?
We've also seen many such waits, often (presumably) associated with
DBMS_STATS processes. As soon as I've cleared my desk of other items on
which I'm working currently, my next task is to delve into these issues.
We're on various combinations of 10gR1 and 10gR2, on Solaris 64-bit
platforms.
Any suggestions as to where to look first would be greatly appreciated.
FAX: 734-930-7611 E-Mail: jim.silverman_at_thomson.com
-----Original Message-----
From: oracle-l-bounce_at_freelists.org
[mailto:oracle-l-bounce_at_freelists.org] On Behalf Of Khemmanivanh,
Somckit
Sent: Wednesday, May 23, 2007 12:13 PM
To: oracle-l_at_freelists.org
Subject: Cursor Pin S and TKPROF anomaly?
Hi,
My Oracle version is 10gR2. The mystery occurs when we have many jobs executing concurrently. CPU usage spikes and jobs slow down considerably.
This just started occurring after an upgrade from 9i to 10gR2...it seems like the new mutex feature in 10gR2 is the culprit?
Here's what looks to be the pattern from the trace file:
16158 WAIT #225: nam='cursor: pin S wait on X' ela= 15829 idn=688875006 value=3637837299712 where|
sleeps=12897830798 obj#=149934 tim=13839593792889
BINDS #225: kkscoacd
Bind#0
1oacdty=01 mxl=32(03) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1000000 frm=01 csi=02 siz=96 off=0
kxsbbbfp=800003f78004a228 bln=32 avl=03 flg=05
value="100"
Bind#1
oacdty=01 mxl=32(10) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1000000 frm=01 csi=02 siz=0 off=32
kxsbbbfp=800003f78004a248 bln=32 avl=10 flg=01
value="0011940619"
Bind#2
oacdty=01 mxl=32(04) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1000000 frm=01 csi=02 siz=0 off=64
kxsbbbfp=800003f78004a268 bln=32 avl=04 flg=01
value="0060"
2) Execute the SQL statement:
EXEC
#225:c=0,e=16717,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=13839593793270
3) Fetch the row:
FETCH
#225:c=0,e=85,p=0,cr=4,cu=0,mis=0,r=1,dep=0,og=1,tim=13839593793395
--Below is the TKPROF output (193 executes and fetches -- the CPU time
is 5 seconds and the ELAPSED time is 35 seconds for the *execute*)
--There are over 7000 waits for cursor pin S but total waited time is
near ZERO...where did all the time go?
call count cpu elapsed disk query current rows
Parse 0 0.00 0.00 0 0 0 0
Execute 193 5.00 35.46 0 0 0 0
Fetch 193 0.08 9.28 0 2271 0 188
total 386 5.08 44.74 0 2271 0 188
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 18
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
cursor: pin S 7374 0.00 0.00
SQL*Net message to client 193 0.00 0.00
SQL*Net message from client 193 1.09 3.20
latch: cache buffers chains 49 0.60 3.80
latch free 22 0.55 1.44
--Thanks for your help!
--
http://www.freelists.org/webpage/oracle-l
Received on Wed May 23 2007 - 12:49:37 CDT
 |
 |