otak-otak | favorite evening food

August 14, 2008

trace 10046 analyzer

Filed under: sql tuning — ora62 @ 7:07 pm

generating trace 10046 quite interesting in analysis.

from the 10046 trace raw contents, we actually can do analysis, but internal recursive sql sometimes makes our live harder :)

metalink note 224270.1 give us a tool to analyze the trace easily, but again got problem when I need to know the history by mean of step-by-step application make database calls. I cannot see control transaction on the trace file.

we can only find “XCTEND rlbk=<number>, rd_only=<number>”, based on metalink note 371984.1:

rlbk 1 if a rollback was performed, 0 if no rollback (commit).
rd_only 1 if transaction was read only, 0 if changes occurred.
the harder part of the raw data of trace 10046 those transaction control is reside at the middle of cursor parsing :(

FETCH #10:c=0,e=35,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=49665367470
WAIT #10: nam=’SQL*Net message from client’ ela= 472 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=49665367990
STAT #10 id=1 cnt=1 pid=0 pos=1 obj=0 op=’FAST DUAL  (cr=0 pr=0 pw=0 time=1 us)’
WAIT #12: nam=’SQL*Net message to client’ ela= 1 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=49665368337
WAIT #12: nam=’SQL*Net message from client’ ela= 376 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=49665368739
XCTEND rlbk=0, rd_only=1
WAIT #0: nam=’SQL*Net message to client’ ela= 1 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=49665368872
*** 2008-08-14 12:06:51.980
WAIT #0: nam=’SQL*Net message from client’ ela= 53635836 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=49719004740
WAIT #0: nam=’SQL*Net message to client’ ela= 3 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=49719005053
WAIT #0: nam=’SQL*Net message from client’ ela= 6340 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=49719011426

even when I tried to make a trick by generating new cursor parsing by replacing the XCTEND bla..bla…bla with something like this:

:%s/XCTEND rlbk=0, rd_only=1/^M=====================^MPARSING IN CURSOR #10 len=27 dep=0 uid=57 oct=3 lid=57 tim=49665366604 hv=824003789 ad=’ca1c6268’^Mcommit

———————————————

Note to get ^M use following
Hold down the Ctrl, and press v m
DO NOT USE Shift+6 and Shift+M
———————————————

still from the trace analyzer output give me a confusing (the order of transaction control still doen’t make any sense – it totally wrong order).

anyway good tools to analyze execution plan, due to the parameter that makes CBO work are in one place with the explain plan gathered.

Ujang| Indonesia | Jakarta

Advertisements

August 13, 2008

TM deadlock and FK indexing

Filed under: troubleshoot — ora62 @ 8:19 am

this RAC deadlock message in udump directory:

*** 2008-08-13 12:54:39.383
ENQUEUE DUMP REQUEST: from 0.26495 on [0x23a9][0x0],[TM] for reason 2 mtype 0
DUMP LOCAL BLOCKER/HOLDER: block level 5 res [0x23a9][0x0],[TM]
———-resource 0x3cb43d330———————-
resname       : [0x23a9][0x0],[TM]
Local node    : 1
dir_node      : 1
master_node   : 1
hv idx        : 8
hv last r.inc : 4
current inc   : 4
hv status     : 0
hv master     : 1
open options  : dd cached
grant_bits    : KJUSERNL KJUSEREX
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX
count         : 1         0         0         0         0         1
val_state     : KJUSERVS_NOVALUE
valblk        : 0x00000000000000000000000000000000 .
access_node   : 1
vbreq_state   : 0
state         : x0
resp          : 3cb43d330
On Scan_q?    : N
Total accesses: 1017
Imm.  accesses: 885
Granted_locks : 1
Cvting_locks  : 1
value_block:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
GRANTED_Q :
lp 3d613b9d0 gl KJUSEREX rp 3cb43d330 [0x23a9][0x0],[TM]
master 1 gl owner 3db861760 possible pid 25585 xid 2013-013F-00000022 bast 0 rseq 2 mseq 0 history 0xa51449a5
open opt KJUSERDEADLOCK
CONVERT_Q:
lp 3d828b628 gl KJUSERNL rl KJUSEREX rp 3cb43d330 [0x23a9][0x0],[TM]
master 1 owner 0  bast 1 rseq 5 mseq 0x560056 history 0xd8d7d8da
convert opt KJUSERGETVALUE KJUSERNOTDDVICTIM
———-enqueue 0x3d613b9d0————————
lock version     : 3199
Owner node       : 1
grant_level      : KJUSEREX
req_level        : KJUSEREX
bast_level       : KJUSERNL
notify_func      : 0
resp             : 3cb43d330
procp            : 3dbc1c070
pid              : 25585
proc version     : 15
oprocp           : 0
opid             : 0
group lock owner : 3db861760
possible pid     : 25585
xid              : 2013-013F-00000022
dd_time          : 0.0 secs
dd_count         : 0
timeout          : 0.0 secs
On_timer_q?      : N
On_dd_q?         : N
lock_state       : GRANTED
Open Options     : KJUSERDEADLOCK
Convert options  : KJUSERGETVALUE KJUSERNOTDDVICTIM
History          : 0xa51449a5
Msg_Seq          : 0x0
res_seq          : 2
valblk           : 0x00000000000000000000000000000000 .
Potential blocker (pid=25585) on resource TM-000023A9-00000000
DUMP LOCAL BLOCKER: initiate state dump for TIMEOUT
possible owner[319.25585]
Submitting asynchronized dump request [28]

your friend should be calculator with hexa to decimal conversion :)

the first time to investiage this by converting TM-000023A9-00000000, 23A9 to decimal and then query the dba_objects to find the object name, object type.if you sure that the object is child from master-detail table relationship, make sure the column which designate as foreign key should be indexed.

Ujang | Jakarta | Indonesia

swingbench – RAC

Filed under: benchmark — ora62 @ 2:10 am

I feel I have new toys with this….swingbench 2.3

scenario:

1. SOE schema (standard) – reach 20 tps

2. tuning storage design – reach 120 tps

3. tuning network – reach 140tps

4. add memory – reach 200 tps :)

will upload another fact and details.

Ujang | Jakarta | Indonesia

Create a free website or blog at WordPress.com.