MB it will be useful for somebody
what I found :
@ashtop sql_id,event,CURRENT_OBJ#,CURRENT_FILE#,CURRENT_BLOCK#,CURRENT_ROW#
sql_id='9nhb1y0actmt4' sysdate-5/1440 sysdate
Total | | | |
| | | | |
| |
Seconds | AAS | %This | SQL_ID | Event
| CURRENT_OBJ# | CURRENT_FILE# | CURRENT_BLOCK# | CURRENT_ROW# |
FIRST_SEEN | LAST_SEEN |
COUNT(DISTINCTSQL_EXEC_START||':'||SQL_EXEC_ID)
--------- | ------- | ------- | ------------- |
---------------------------------------- | ------------ | ------------- |
-------------- | ------------ | -------------------- | -------------------- |
-----------------------------------------------
290 | 1.0 | 50% | | 9nhb1y0actmt4 | enq: TX - row lock contention
| 112104 | 1024 | 113703418 | 1 |
2016-07-20 16:25:46 | 2016-07-20 16:30:45 |
9
280 | .9 | 49% | | 9nhb1y0actmt4 | enq: TX - row lock contention
| 112104 | 1024 | 9827499 | 0 |
2016-07-20 16:25:46 | 2016-07-20 16:30:45 |
9
2 | .0 | 0% | | 9nhb1y0actmt4 | <NULL>
| -1 | 0 | 0 | 0 |
2016-07-20 16:29:19 | 2016-07-20 16:30:34 |
2
1 | .0 | 0% | | 9nhb1y0actmt4 | db file sequential read
| 0 | 29 | 466441 | 0 |
2016-07-20 16:27:17 | 2016-07-20 16:27:17 |
1
1 | .0 | 0% | | 9nhb1y0actmt4 | direct path read
| -1 | 0 | 0 | 0 |
2016-07-20 16:27:34 | 2016-07-20 16:27:34 |
1
1 | .0 | 0% | | 9nhb1y0actmt4 | direct path read
| 112109 | 8 | 120187909 | 0 |
2016-07-20 16:27:08 | 2016-07-20 16:27:08 |
1
1 | .0 | 0% | | 9nhb1y0actmt4 | <NULL>
| -1 | 8 | 133674656 | 0 |
2016-07-20 16:27:23 | 2016-07-20 16:27:23 |
1
1 | .0 | 0% | | 9nhb1y0actmt4 | <NULL>
| -1 | 1024 | 9827499 | 0 |
2016-07-20 16:27:47 | 2016-07-20 16:27:47 |
1
there are 2 blocks for which we faced with contention ( current_block# )
113703418 + 9827499
select dbms_rowid.rowid_create (1, 112104, 1024, 113703418, 1) from dual;
AAAbXoAAbAABvn6AAB
and
select dbms_rowid.rowid_create (1, 112104, 1024, 9827499, 0) from dual;
AAAbXoAACAAFfSrAAA
next I’m going to dump this blocks
first find block number for this rowid
SELECT dbms_rowid.rowid_relative_fno(rowid) REL_FNO,
dbms_rowid.rowid_block_number(rowid) BLOCKNO,
dbms_rowid.rowid_row_number(rowid) ROWNO
from esia.req where rowid='AAAbXoAACAAFfSrAAA';
REL_FNO | BLOCKNO | ROWNO
---------- | ---------- | ----------
2 | 1438891 | 0
next dump this block
alter session set tracefile_identifier='LOCK_BLOCK';
alter system dump datafile 2 block 1438891;
Start dump data blocks tsn: 1 file#:2 minblk 1438891 maxblk 1438891
Block dump from cache:
Dump of buffer cache at level 4 for pdb=0 tsn=1 rdba=9827499
Block dump from disk:
buffer tsn: 1 rdba: 0x0095f4ab (2/1438891)
scn: 0x32.32a3de66 seq: 0x01 flg: 0x04 tail: 0xde660601
frmt: 0x02 chkval: 0x3f1b type: 0x06=trans data
Hex dump of block: st=0, typ_found=1
====skipped====
Block header dump: 0x0095f4ab
Object id on Block? Y
seg/obj: 0x3415 csc: 0x32.32a3de66 itc: 2 flg: E typ: 1 - DATA
brn: 0 bdba: 0x95f400 ver: 0x01 opc: 0
inc: 0 exflg: 0
Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x0020.01d.000383f3 0x00c08c76.4f9c.04 C-U- 0 scn 0x0032.32a3889a
0x02 0x0000.000.00000000 0x00000000.0000.00 ---- 0 fsc 0x0000.00000000
bdba: 0x0095f4ab
data_block_dump,data header at 0x7f5df4800064
===============
tsiz: 0x1f98
hsiz: 0x132
pbl: 0x7f5df4800064
76543210
====skipped====
block_row_dump:
tab 0, row 0, @0x1176
tl: 52 fb: --H-FL-- lb: 0x0 cc: 16
====skipped====all rows look the same ( fb: --H-FL-- ) no chained rows ( header
first + last )
lock byte (lck) is null ( means no lock )
header block flag description
status of the Transaction as under:
---- = transaction is active or committed pending cleanout
C--- = transaction has been committed and locks cleaned out
-B-- = this undo record contains the undo for this ITL entry
--U- = transaction committed (maybe long ago);
row block flag description:
K = Cluster Key
C = Cluster table member
H = Head piece of row
D = Deleted row
F = First data piece
L = Last data piece
P = First column continues from previous piece N = Last column continues in
next piece
As I found rowid, I reproduce lock with trace info ( 10046 +10704 )
=====================
PARSING IN CURSOR #140288347057592 len=61 dep=0 uid=5 oct=6 lid=5
tim=11385667871443 hv=4089727858 ad='12228edde0' sqlid='b18v0m3tw8kvk'
update my_table set STU='A' where rowid='AAAbXoAACAAFfSrAAA'
END OF STMT
PARSE
#140288347057592:c=0,e=144,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2332114778,tim=11385667871442
*** 2016-07-19 18:32:46.944
ksqgtl *** TM-0001B5E8-00000000-00000000-00000000 mode=3 flags=0x401
timeout=21474836 ***
ksqgtl: xcb=0x1dd9b93138, ktcdix=2147483647, topxcb=0x1dd9b93138
ktcipt(topxcb)=0x0
ksqgtl:
ksqlkdid: 0001-0100-00AF5BD8
ksqgtl: RETURNS 0
WAIT #140288347057592: nam='enq: TX - row lock contention' ela= 25145630
name|mode=1415053318 usn<<16 | slot=2490381 sequence=588209 obj#=112104
tim=11385693017386
WAIT #140288347057592: nam='enq: TX - row lock contention' ela= 136575
name|mode=1415053318 usn<<16 | slot=1835030 sequence=1110521 obj#=112104
tim=11385693154148
WAIT #140288347057592: nam='Disk file operations I/O' ela= 4 FileOperation=2
fileno=31 filetype=2 obj#=-1 tim=11385693154313
WAIT #140288347057592: nam='db file sequential read' ela= 160 file#=31
block#=184300 blocks=1 obj#=0 tim=11385693154512
EXEC
#140288347057592:c=3104,e=25283167,p=1,cr=5,cu=6,mis=0,r=1,dep=0,og=1,plh=2332114778,tim=11385693154642
STAT #140288347057592 id=1 cnt=0 pid=0 pos=1 obj=0 op='UPDATE REQ (cr=5 pr=1
pw=0 time=25283061 us)'
STAT #140288347057592 id=2 cnt=1 pid=1 pos=1 obj=112104 op='TABLE ACCESS BY
USER ROWID REQ (cr=3 pr=0 pw=0 time=120 us cost=1 size=36 card=1)'
WAIT #140288347057592: nam='SQL*Net message to client' ela= 1 driver
id=1413697536 #bytes=1 p3=0 obj#=0 tim=11385693154785
WAIT #140288347057592: nam='SQL*Net message from client' ela= 3105 driver
id=1413697536 #bytes=1 p3=0 obj#=0 tim=11385693157905
PARSE
#140288347396824:c=0,e=21,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=11385693157964
but there is nothing helpful for me =(
keep digging
On 18 Jul 2016, at 18:04, Anton Bushmelev <djeday84@xxxxxxxxx> wrote:
Hi all, faced with enq: TX - row lock contention
but no booking session info in gv$session or ash =\
select count
(*),event,BLOCKING_SESSION,BLOCKING_SESSION_SERIAL#,blocking_inst_id from
gv$active_session_history where event like '%TX%' and sample_time>
sysdate-1/24 group by
bLOCKING_SESSION,BLOCKING_SESSION_SERIAL#,blocking_inst_id,event;
| | BLOCKING |
|
COUNT(*) | Event | SID |
BLOCKING_SESSION_SERIAL# | BLOCKING_INST_ID
---------- | ---------------------------------------- | ---------- |
------------------------ | ----------------
3520 | enq: TX - row lock contention | |
|
1 | enq: TX - index contention | 10908 |
33849 | 1
5 | enq: TX - row lock contention | 2259 |
3041 | 1
what can it be ?
ps: Bug 5010879 - V$SESSION slow and does not show any BLOCKING_SESSION
column data (Doc ID 5010879.8)
not my case, we use 12.1.0.2.16.01.2016
