This discussion is archived
4 Replies Latest reply: Oct 2, 2013 1:08 PM by Jonathan Lewis RSS

Global Enqueue Services Deadlock detected.

user10188639 Newbie
Currently Being Moderated

Hi Gurus,

OS- Linux

DB- 112030 single node RAC

 


we are getting "Global Enqueue Servoces Deadlock detected. More info into file" when we are running DAC job (insert operation).Assocoated table is partition table and having bitmap indexes on it.what is causing deadlock issue.

below is the trace file

 

 

 

Global blockers dump start:---------------------------------
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0x60048][0x357a],[TX][ext 0x2,0x0]
----------resource 0x1ecce59c8----------------------
resname       : [0x60048][0x357a],[TX][ext 0x2,0x0]
hash mask     : x3
Local inst    : 1
dir_inst      : 1
master_inst   : 1
hv idx        : 22
hv last r.inc : 0
current inc   : 2
hv status     : 0
hv master     : 0
open options  : dd
grant_bits    : KJUSERNL KJUSEREX
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX
count         : 6         0         0         0         0         1
val_state     : KJUSERVS_NOVALUE
valblk        : 0xf0140000000000002dc4a8e534000000 .-4
access_inst   : 1
vbreq_state   : 0
state         : x0
resp          : 0x1ecce59c8
On Scan_q?    : N
Total accesses: 97
Imm.  accesses: 82
Granted_locks : 1
Cvting_locks  : 6

*** 2013-09-24 11:16:03.314
value_block:  f0 14 00 00 00 00 00 00 2d c4 a8 e5 34 00 00 00
GRANTED_Q :
lp 0x1ea134bb8 gl KJUSEREX rp 0x1ecce59c8 [0x60048][0x357a],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1ee2ca558 possible pid 17155 xid 106000-0001-00000002 bast 0 rseq 16 mseq 0 history 0x49a51495
  open opt KJUSERDEADLOCK 
CONVERT_Q:
lp 0x1ea134d88 gl KJUSERNL rl KJUSERPR rp 0x1ecce59c8 [0x60048][0x357a],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1ee24a420 possible pid 17120 xid FE000-0001-00000002 bast 0 rseq 16 mseq 0 history 0x49a5149a
  convert opt KJUSERGETVALUE 
lp 0x1ea123be0 gl KJUSERNL rl KJUSERPR rp 0x1ecce59c8 [0x60048][0x357a],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1eeb0a1a0 possible pid 17151 xid 105000-0001-00000002 bast 0 rseq 16 mseq 0 history 0x1495149a
  convert opt KJUSERGETVALUE 
lp 0x1ea12b0a0 gl KJUSERNL rl KJUSERPR rp 0x1ecce59c8 [0x60048][0x357a],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1ee332950 possible pid 17147 xid 104000-0001-00000002 bast 0 rseq 16 mseq 0 history 0x1495149a
  convert opt KJUSERGETVALUE 
lp 0x1ea130f88 gl KJUSERNL rl KJUSERPR rp 0x1ecce59c8 [0x60048][0x357a],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1eeafb358 possible pid 17168 xid 109000-0001-00000002 bast 0 rseq 16 mseq 0 history 0x49a5149a
  convert opt KJUSERGETVALUE 
lp 0x1ea131ff0 gl KJUSERNL rl KJUSERPR rp 0x1ecce59c8 [0x60048][0x357a],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1eeb9c0c8 possible pid 17159 xid 107000-0001-00000002 bast 0 rseq 16 mseq 0 history 0x49a5149a
  convert opt KJUSERGETVALUE 
lp 0x1ea11db28 gl KJUSERNL rl KJUSERPR rp 0x1ecce59c8 [0x60048][0x357a],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1ee238630 possible pid 17163 xid 108000-0001-00000002 bast 0 rseq 16 mseq 0 history 0x1495149a
  convert opt KJUSERGETVALUE 
----------enqueue 0x1ea134bb8------------------------
lock version     : 329
Owner inst       : 1
grant_level      : KJUSEREX
req_level        : KJUSEREX
bast_level       : KJUSERNL
notify_func      : (nil)
resp             : 0x1ecce59c8
procp            : 0x1ec5f7398
pid              : 17120
proc version     : 0
oprocp           : (nil)
opid             : 17120
group lock owner : 0x1ee2ca558
possible pid     : 17155
xid              : 106000-0001-00000002
dd_time          : 0.0 secs
dd_count         : 0
timeout          : 0.0 secs
On_timer_q?      : N
On_dd_q?         : N
lock_state       : GRANTED
ast_flag         : 0x0
Open Options     : KJUSERDEADLOCK
Convert options  : KJUSERNOQUEUE KJUSERNODEADLOCKWAIT
History          : 0x49a51495
Msg_Seq          : 0x0
res_seq          : 16
valblk           : 0xf0140000000000006043aef9ff7f0000 .`C
user session for deadlock lock 0x1ea134bb8
  sid: 97 ser: 7583 audsid: 1882900 user: 106/OBI_DW
    flags: (0x45) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
    flags2: (0x40009) -/-/INC
  pid: 262 O/S info: user: oragrid, term: UNKNOWN, ospid: 17155
    image: oracle@abcdinst1efg
  client details:
    O/S info: user: infadmin, term: , ospid: 11370
    machine: abcdinst1efg program: pmdtm@abcdinst1efg (TNS V1-V3)
    application name: pmdtm@abcdinst1efg (TNS V1-V3), hash value=910439024
  current SQL:
  INSERT INTO W_dc_custom_F(AL_ACCOUNT_WMDF,FIN_ORG_STD,CUSTOM_WID,CUSTOM_FIN_PROF_STD,TERRITORY_WID,SALES_GROUP_ORG_WID,CUSTOMER_CONTACT_WID,CUSTOMER_SOLD_TO_LOC_WID,CUSTOMER_SHIP_TO_LOC_WID,CUSTOMER_BILL_TO_LOC_WID,CUSTOMER_PAYER_LOC_WID,SUPPLIER_WID,SUPPLIER_ACCOUNT_WID,SALES_REP_WID,SERVICE_REP_WID,ACCOUNT_REP_WID,PURCH_REP_WID,PRODUCT_WID,SALES_PRODUCT_WID,INVENTORY_PRODUCT_WID,SUPPLIER_PRODUCT_WID,COMPANY_LOC_WID,PLANT_LOC_WID,SALES_OFC_LOC_WID,OPERATING_UNIT_ORG_WID,RECEIVABLES_ORG_WID,LEDGER_WID,COMPANY_ORG_WID,BUSN_AREA_ORG_WID,CTRL_AREA_ORG_WID,FIN_AREA_ORG_WID,SALES_ORG_WID,PURCH_ORG_WID,ISSUE_ORG_WID,DOC_TYPE_WID,CLRNG_DOC_TYPE_WID,REF_DOC_TYPE_WID,POSTING_TYPE_WID,CLR_POST_TYPE_WID,COST_CENTER_WID,PROFIT_CENTER_WID,BANK_WID,TAX_WID,PAY_TERMS_WID,PAYMENT_METHOD_WID,TR
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
  possible owner[262.17155] on resource TX-00060048-0000357A

*** 2013-09-24 11:16:03.517
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0x3a004b][0x61],[TX][ext 0x2,0x0]
----------resource 0x1ecd1af40----------------------
resname       : [0x3a004b][0x61],[TX][ext 0x2,0x0]
hash mask     : x3
Local inst    : 1
dir_inst      : 1
master_inst   : 1
hv idx        : 0
hv last r.inc : 0
current inc   : 2
hv status     : 0
hv master     : 0
open options  : dd
grant_bits    : KJUSERNL KJUSEREX
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX
count         : 6         0         0         0         0         1
val_state     : KJUSERVS_NOVALUE
valblk        : 0x455f5749442c504f5354494e475f5459 E_WID,POSTING_TY
access_inst   : 1
vbreq_state   : 0
state         : x0
resp          : 0x1ecd1af40
On Scan_q?    : N
Total accesses: 570
Imm.  accesses: 527
Granted_locks : 1
Cvting_locks  : 6
value_block:  45 5f 57 49 44 2c 50 4f 53 54 49 4e 47 5f 54 59
GRANTED_Q :
lp 0x1ea129ac8 gl KJUSEREX rp 0x1ecd1af40 [0x3a004b][0x61],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1ee24a420 possible pid 17120 xid FE000-0001-00000002 bast 0 rseq 45 mseq 0 history 0x14951495
  open opt KJUSERDEADLOCK 
CONVERT_Q:
lp 0x1ea1316c8 gl KJUSERNL rl KJUSERPR rp 0x1ecd1af40 [0x3a004b][0x61],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1eeb012a8 possible pid 17134 xid 101000-0001-00000002 bast 0 rseq 45 mseq 0 history 0x49a5149a
  convert opt KJUSERGETVALUE 
lp 0x1ea12fd38 gl KJUSERNL rl KJUSERPR rp 0x1ecd1af40 [0x3a004b][0x61],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1eeb04250 possible pid 17143 xid 103000-0001-00000002 bast 0 rseq 45 mseq 0 history 0x49a5149a
  convert opt KJUSERGETVALUE 
lp 0x1ea131a68 gl KJUSERNL rl KJUSERPR rp 0x1ecd1af40 [0x3a004b][0x61],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1eeb33cd0 possible pid 17124 xid FF000-0001-00000002 bast 0 rseq 45 mseq 0 history 0x49a5149a
  convert opt KJUSERGETVALUE 
lp 0x1ea12ff08 gl KJUSERNL rl KJUSERPR rp 0x1ecd1af40 [0x3a004b][0x61],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1ee253318 possible pid 17129 xid 100000-0001-00000002 bast 0 rseq 45 mseq 0 history 0x1495149a
  convert opt KJUSERGETVALUE 
lp 0x1ea130830 gl KJUSERNL rl KJUSERPR rp 0x1ecd1af40 [0x3a004b][0x61],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1ee2ca558 possible pid 17155 xid 106000-0001-00000002 bast 0 rseq 45 mseq 0 history 0x1495149a
  convert opt KJUSERGETVALUE 
lp 0x1ea124338 gl KJUSERNL rl KJUSERPR rp 0x1ecd1af40 [0x3a004b][0x61],[TX][ext 0x2,0x0]
  master 1 gl owner 0x1ee24d3c8 possible pid 17139 xid 102000-0001-00000002 bast 0 rseq 45 mseq 0 history 0x1495149a
  convert opt KJUSERGETVALUE 
----------enqueue 0x1ea129ac8------------------------
lock version     : 1389
Owner inst       : 1
grant_level      : KJUSEREX
req_level        : KJUSEREX
bast_level       : KJUSERNL
notify_func      : (nil)
resp             : 0x1ecd1af40
procp            : 0x1ec5f84d8
pid              : 17134
proc version     : 0
oprocp           : (nil)
opid             : 17134
group lock owner : 0x1ee24a420
possible pid     : 17120
xid              : FE000-0001-00000002
dd_time          : 0.0 secs
dd_count         : 0
timeout          : 0.0 secs
On_timer_q?      : N
On_dd_q?         : N
lock_state       : GRANTED
ast_flag         : 0x0
Open Options     : KJUSERDEADLOCK
Convert options  : KJUSERNOQUEUE KJUSERNODEADLOCKWAIT
History          : 0x14951495
Msg_Seq          : 0x0
res_seq          : 45
valblk           : 0xe045aef9ff7f00002043aef9ff7f0000 .E C
user session for deadlock lock 0x1ea129ac8
  sid: 140 ser: 29 audsid: 1882892 user: 106/OBI_DW
    flags: (0x45) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
    flags2: (0x40009) -/-/INC
  pid: 254 O/S info: user: oragrid, term: UNKNOWN, ospid: 17120
    image: oracle@abcdinstdw
  client details:
    O/S info: user: infadmin, term: , ospid: 11370
    machine: abcdinst1efg program: pmdtm@abcdinst1efg (TNS V1-V3)
    application name: pmdtm@abcdinst1efg (TNS V1-V3), hash value=910439024
  current SQL:
  INSERT INTO W_dc_custom_F(AL_ACCOUNT_WMDF,FIN_ORG_STD,CUSTOM_WID,CUSTOM_FIN_PROF_STD,........
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
  possible owner[254.17120] on resource TX-003A004B-00000061
*** 2013-09-24 11:16:03.518
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
Global blockers dump end:-----------------------------------
Global Wait-For-Graph(WFG) at ddTS[0.208] :
BLOCKED 0x1ea134d88 3 wq 2 cvtops x1 TX 0x60048.0x357a(ext 0x2,0x0)[FE000-0001-00000002] inst 1
BLOCKER 0x1ea134bb8 3 wq 1 cvtops x28 TX 0x60048.0x357a(ext 0x2,0x0)[106000-0001-00000002] inst 1
BLOCKED 0x1ea130830 3 wq 2 cvtops x1 TX 0x3a004b.0x61(ext 0x2,0x0)[106000-0001-00000002] inst 1
BLOCKER 0x1ea129ac8 3 wq 1 cvtops x28 TX 0x3a004b.0x61(ext 0x2,0x0)[FE000-0001-00000002] inst 1

*** 2013-09-24 11:16:04.288
* Cancel deadlock victim lockp 0x1ea134d88
kjddt2vb: valblk  [0.214] > local ts [0.213]

*** 2013-09-24 11:16:09.046
kjddt2vb: valblk  [0.215] > local ts [0.213]

*** 2013-09-24 11:16:14.087
Global blockers dump start:---------------------------------

  • 1. Re: Global Enqueue Services Deadlock detected.
    user10188639 Newbie
    Currently Being Moderated

    Any suggetions?

  • 2. Re: Global Enqueue Services Deadlock detected.
    Jonathan Lewis Oracle ACE Director
    Currently Being Moderated

    Note the following type of thing on your converters' queue:

     

    CONVERT_Q:

    lp 0x1ea1316c8 gl KJUSERNL rl KJUSERPR rp 0x1ecd1af40 [0x3a004b][0x61],[TX][ext 0x2,0x0]

      master 1 gl owner 0x1eeb012a8 possible pid 17134 xid 101000-0001-00000002 bast 0 rseq 45 mseq 0 history 0x49a5149a

      convert opt KJUSERGETVALUE

     

    KJUSERPR is "protected write": In single instance Oracle you would see this session in v$lock with REQUEST=4 on a TX enqueue. There are a few possible causes for TX mode 4 waits, and one of them is bitmap index collisions - which seems the most likely given your statement about bitmap indexes and the fact that your dump shows two different sessions doing concurrent inserts on the same table.

     

    Regards

    Jonathan Lewis

  • 3. Re: Global Enqueue Services Deadlock detected.
    user10188639 Newbie
    Currently Being Moderated

    HI Jonathan,

     

    thanks for reply.

    i didnt see any request =4 lock entries in v$LOCK.

     

    issue resolved for temporary.

     

    that table has one unique index

     

    merging 4 columns .DAC drops the index and recreates , i observed when deadlock occurs that unique index was not there .And when i tried to create unique index manually it gave me error "ORA-01452: cannot CREATE UNIQUE INDEX; duplicate keys found".

    after some time i reran DAC job which ran successfully and it create that unique index also.

    i have generated ASH report for the

     

    interval when deadlock occurs.

     

    is there any

     

    issue with Unique index ?

     

     

     

    ASH Report For #######

     

     

    DB Name

     

    DB Id

     

    Instance

     

    Inst num

     

    Release

     

    RAC

     

    Host

    #######

    @@@@@

    #########

    1

    11.2.0.3.0

    YES

    ########

     

    CPUs

     

    SGA Size

     

    Buffer Cache

     

    ShCRed Pool

     

    ASH Buffer Size

    2

    6,403M (100%)

    2,480M (38.7%)

    1,680M (26.2%)

    4.0M (0.1%)

      

    Sample Time

     

    Data Source

    Analysis Begin Time:

    01-Oct-13 08:08:08

    V$ACTIVE_SESSION_HISTORY

    Analysis End Time:

    01-Oct-13 10:08:34

    V$ACTIVE_SESSION_HISTORY

    Elapsed Time:

    120.4 (mins)

     

    Sample Count:

    7,786

     

    Average Active Sessions:

    1.08

     

    Avg. Active Session per CPU:

    0.54

     

    Report TCRget:

    None specified

     

      

     

    ASH Report

     

     

    Top Events

     

    Load Profile

     

    Top SQL

     

    Top PL/SQL

     

    Top Java

     

    Top Call Types

     

    Top Sessions

     

    Top Objects/Files/Latches

     

    Activity Over Time

     


    Back to Top

      

      

     

    Top Events

     

     

    Top User Events

     

    Top Background Events

     

    Top Cluster Events

     

    Top Event P1/P2/P3 Values

     

    Back to Top

      

     

    Top User Events

     

     

    Event

     

    Event Class

     

    % Event

     

    Avg Active Sessions

    direct path read

    User I/O

    29.28

    0.32

    enq: TX - row lock contention

    Application

    15.78

    0.17

    direct path read temp

    User I/O

    6.65

    0.07

    CPU + Wait for CPU

    CPU

    5.96

    0.06

    direct path write temp

    User I/O

    5.00

    0.05

    Back to Top Events
    Back to Top

      

     

    Top Background Events

     

     

    Event

     

    Event Class

     

    % Activity

     

    Avg Active Sessions

    Backup: MML query backup piece

    Administrative

    11.20

    0.12

    Backup: MML create a backup piece

    Administrative

    4.56

    0.05

    Backup: MML commit backup piece

    Administrative

    1.70

    0.02

    control file sequential read

    System I/O

    1.68

    0.02

    log file pCRallel write

    System I/O

    1.32

    0.01

    Back to Top Events
    Back to Top

      

     

    Top Cluster Events

     

    No data exists for this section of the report.

    Back to Top Events
    Back to Top

      

     

    Top Event P1/P2/P3 Values

     

     

    Event

     

    % Event

     

    P1 Value, P2 Value, P3 Value

     

    % Activity

     

    PCRameter 1

     

    PCRameter 2

     

    PCRameter 3

    direct path read

    29.32

    "6","2485824","32"

    0.42

    file number

    first dba

    block cnt

    enq: TX - row lock contention

    15.78

    "1415053316","589875","13432"

    3.60

    name|mode

    usn<<16 | slot

    sequence

    enq: TX - row lock contention

    15.78474184433598767017724120215771898279

    "1415053316","4390958","226"

    2.54

    name|mode

    usn<<16 | slot

    sequence

    enq: TX - row lock contention

    15.78474184433598767017724120215771898279

    "1415053316","1048704","2966"

    2.07

    name|mode

    usn<<16 | slot

    sequence

    direct path read temp

    6.65

    "201","3928064","7"

    0.03

    file number

    first dba

    block cnt

    direct path write temp

    5.00

    "201","3922695","7"

    0.03

    file number

    first dba

    block cnt

    log file sync

    3.08

    "12052","139691002","0"

    0.08

    buffer#

    sync scn

    NOT DEFINED

    Back to Top Events
    Back to Top

      

     

    Load Profile

     

     

    Top Service/Module

     

    Top Client IDs

     

    Top SQL Command Types

     

    Top Phases of Execution

     

    Top Remote Instances

     

    Back to Top

      

     

    Top Service/Module

     

     

    Service

     

    Module

     

    % Activity

     

    Action

     

    % Action

    inst_1

    ####@abcdinst1efg (TNS V1-V3)

    36.71

    UNNAMED

    36.71

    SYS$USERS

    backup CRchivelog

    17.96

    0000018 STCRTED16

    7.00

    SYS$USERS

    backup CRchivelog

    17.95530439249935782173131261238119702029

    0000016 STCRTED16

    3.07

    SYS$USERS

    backup CRchivelog

    17.95530439249935782173131261238119702029

    0000023 STCRTED16

    2.12

    inst_1

    java@abcdinst1efg (TNS V1-V3)

    13.63

    UNNAMED

    13.63

    SYS$USERS

    emagent_SQL_oracle_database

    7.41

    UserBlockChain

    7.31

    inst_1

    PL/SQL Developer

    6.92

    SQL Window - New

    6.85

    Back to Load Profile
    Back to Top

      

     

    Top Client IDs

     

    No data exists for this section of the report.

    Back to Load Profile
    Back to Top

      

     

    Top SQL Command Types

     

     

    'Distinct SQLIDs' is the count of the distinct number of SQLIDs with the given SQL Command Type found over all the ASH samples in the analysis period

     

     

    SQL Command Type

     

    Distinct SQLIDs

     

    % Activity

     

    Avg Active Sessions

    SELECT

    153

    40.05

    0.43

    INSERT

    14

    16.65

    0.18

    CREATE INDEX

    47

    13.27

    0.14

    DELETE

    4

    2.86

    0.03

    Back to Load Profile
    Back to Top

      

     

    Top Phases of Execution

     

     

    Phase of Execution

     

    % Activity

     

    Avg Active Sessions

    SQL Execution

    72.30

    0.78

    PCRse

    1.00

    0.01

    Back to Load Profile
    Back to Top

      

     

    Top Remote Instances

     

    No data exists for this section of the report.

    Back to Load Profile
    Back to Top

      

     

    Top SQL

     

     

    Top SQL with Top Events

     

    Top SQL with Top Row Sources

     

    Top SQL using literals

     

    Top PCRsing Module/Action

     

    Complete List of SQL Text

     

    Back to Top

      

     

    Top SQL with Top Events

     

     

    SQL ID

     

    Planhash

     

    Sampled # of Executions

     

    % Activity

     

    Event

     

    % Event

     

    Top Row Source

     

    % RwSrc

     

    SQL Text

    1f01pd5s2hryn

     

    33

    15.87

    enq: TX - row lock contention

    15.78

    ** Row Source Not Available **

    15.78

    INSERT INTO W_dc_custom_F

    ...

    d1r1pught84rf

    2570827013

    8

    7.31

    direct path write temp

    3.34

    HASH JOIN

    3.34

    WITH blocked_resources AS (se...

    d1r1pught84rf

    2570827013

    8

    7.30798869766247110197790906755715386591

    direct path read temp

    3.19

    HASH JOIN

    3.19

     

    cjdvygdhcppcp

    230219697

    5

    6.92

    direct path read

    5.70

    TABLE ACCESS - FULL

    5.70

    CREATE UNIQUE INDEX W_dc_custom_F...

    86pjpkbnw5zrh

    3618915427

    1

    2.83

    db file scattered read

    2.70

    TABLE ACCESS - FULL

    2.70

    DELETE FROM DW_D.W_dc_custom_F...

    4qryhzmn4a0g4

    1899724433

    1

    2.29

    direct path read temp

    1.68

    HASH JOIN

    1.68

    select request from v$lock

    Back to Top SQL
    Back to Top

      

     

    Top SQL with Top Row Sources

     

     

    SQL ID

     

    PlanHash

     

    Sampled # of Executions

     

    % Activity

     

    Row Source

     

    % RwSrc

     

    Top Event

     

    % Event

     

    SQL Text

    1f01pd5s2hryn

     

    33

    15.87

    ** Row Source Not Available **

    15.87

    enq: TX - row lock contention

    15.78

    INSERT INTO W_dc_custom_F...

    d1r1pught84rf

    2570827013

    8

    7.31

    HASH JOIN

    7.28

    direct path write temp

    3.34

    WITH blocked_resources AS (se...

    cjdvygdhcppcp

    230219697

    5

    6.92

    TABLE ACCESS - FULL

    5.91

    direct path read

    5.70

    CREATE UNIQUE INDEX W_dc_custom_F...

    86pjpkbnw5zrh

    3618915427

    1

    2.83

    TABLE ACCESS - FULL

    2.75

    db file scattered read

    2.70

    DELETE FROM DW_D.W_dc_custom_F...

    4qryhzmn4a0g4

    1899724433

    1

    2.29

    HASH JOIN

    2.29

    direct path read temp

    1.68

    select request from v$lock

    Back to Top SQL
    Back to Top

      

     

    Top SQL using literals

     

    No data exists for this section of the report.

    Back to Top SQL
    Back to Top

      

     

    Top PCRsing Module/Action

     

    No data exists for this section of the report.

    Back to Top SQL
    Back to Top

      

     

    Complete List of SQL Text

     

     

    SQL Id

     

    SQL Text

    1f01pd5s2hryn

    INSERT INTO W_dc_custom_F(AL_ACCOUNT_WMDF,FIN_ORG_STD,CUSTOM_WID,CUSTOM_FIN_PROF_STD,TERRITORY_WID,SALES_GROUP_ORG_WID,CUSTOMER_CONTACT_WID,CUSTOMER_CONTACT_WID, CUSTOMER_SOLD_TO_LOC_WID, CUSTOMER_TO_LOC_WID, CUSTOMER_BILL_TO_LOC_WID, CUSTOMER_PAYER_LOC_WID, SUPPLIER_WID, SUPPLIER_ACCOUNT_WID, SALES_REP_WID, SERVICE_REP_WID, ACCOUNT_REP_WID, PURCH_REP_WID, PRODUCT_WID, SALES_PRODUCT_WID, LIST_PRODUCT_WID, SUPPLIER_PRODUCT_WID, COMPANY_LOC_WID, PLANT_LOC_WID, SALES_OFC_LOC_WID, OPERATING_UNIT_ORG_WID, RECEIVABL_ORG_WID, LEDGER_WID, COMPANY_ORG_WID, BUSN_CREA_ORG_WID, CTRL_CREA_ORG_WID, FIN_CREA_ORG_WID, SALES_ORG_WID, PURCH_ORG_WID, ISSUE_ORG_WID, DOC_TYPE_WID, CLRNG_DOC_TYPE_WID, REF_DOC_TYPE_WID, POSTING_TYPE_WID, CLR_POST_TYPE_WID, COST_CENTER_WID, LOSS_CENTER_WID, BANK_WID, TAX_WID, PAY_TERMS_WID, PAYMENT_METHOD_WID, TRANSACTION_DT_WID, TRANSACTION_TM_WID, CONVERSION_DT_WID, ORDERED_ON_DT_WID, INVOICED_ON_DT_WID, PURCH_ORDER_DT_WID, SUPPLIER_ORDER_DT_WID, INVOICE_RECEIPT_D T_WID, CLECRING_DOC_DT_WID, BASELINE_DT_WID, PLANNING_DT_WID, PAYMENT_DUE_DT_WID, ACCOUNT_DOC_ID, CR_DOC_AMT, CR_LOC_AMT, CR_REMAINING_DOC_AMT, OP_ATTRIBUTE5, OP_ATTRIBUTE6, OP_ATTRIBUTE7, OP_ATTRIBUTE8, OP_ATTRIBUTE9, OP_ATTRIBUTE10, OP_ATTRIBUTE11, OP_ATTRIBUTE13, OP_ATTRIBUTE14, OP_ATTRIBUTE15, OP_ATTRIBUTE_CATEGORY, OP_BUSN_DIFFERENT IATOR_WID, OP_COLLECTOR_ID) VALUES ( :1, :2, :3, :4, :5, :6, :7, :8, :9, :10, :11, :12, :13, :14, :15, :16, :17, :18, :19, :20, :21, :22, :23, :24, :25, :26, :27, :28, :29, :30, :31, :32, :33, :34, :35, :36, :37, :38, :39, :40, :41, :42, :43, :44, :45, :46, :47, :48, :49, :50, :51, :52, :53, :54, :55, :56, :57, :58, :59, :60, :61, :62, :63, :64, :65, :66, :67, :68, :69, :70, :71, :72, :73, :74, :75, :76, :77, :78, :79, :80, :81, :82, :83, :84, :85, :86, :87, :88, :89, :90, :91, :92, :93, :94, :95, :96, :97, :98, :99, :100, :101, :102, :103, :104, :105, :106, :107, :108, :109, :110, :111, :112, :113, :114, :115, :116, :117, :118, :119, :120, :121, :122, :123, :124, :125, :126, :127, :128, :129, :130, :131, :132, :133, :134, :135, :136, :137, :138, :139, :140, :141, :142, :143, :144, :145, :146, :147, :148, :149, :150, :151, :152, :153, :154, :155, :156, :157, :158, :159, :160, :161, :162, :163, :164, :165, :166, :167, :168, :169)

    4qryhzmn4a0g4

    select request from v$lock

    86pjpkbnw5zrh

    DELETE FROM DW_D.W_dc_custom_F a WHERE ROWID IN (SELECT rid FROM (SELECT ROWID rid, row_number() over(PCRTITION BY b.SNAPSHOT_DT_WID, b.SNAPSHOT_STATUS, b.DATASOURCE_NUM_ID, b.INTEGRATION_ID ORDER BY ROWID) rn FROM DW_D.W_dc_custom_F b) WHERE rn <> 1)

    cjdvygdhcppcp

    CREATE UNIQUE INDEX W_dc_custom_F_U1 ON W_dc_custom_F ( SNAPSHOT_DT_WID Asc , SNAPSHOT_STATUS Asc , DATASOURCE_NUM_ID Asc , INTEGRATION_ID Asc ) NOLOGGING

    d1r1pught84rf

    WITH blocked_resources AS (select id1 , id2 , SUM(ctime) as blocked_secs , COUNT(1) as blocked_count , type from v$lock where request > 0 group by type, id1, id2 ) , blockers AS (select L.id1, L.id2, L.type, L.sid , BR.blocked_secs , BR.blocked_count from v$lock L , blocked_resources BR where BR.type = L.type and BR.id1 = L.id1 and BR.id2 = L.id2 and L.lmode > 0 and L.block <> 0 ) select /*+ MERGE(@"SEL$22") MERGE(@"SEL$109DB78D") MERGE(@"SEL$5") MERGE(@"SEL$38") MERGE(@"SEL$470E2127") MERGE(@"SEL$7286615E") MERGE(@"SEL$62725911") MERGE(@"SEL$2EC965E0") MERGE(@"SEL$C8360722") MERGE(@"SEL$874CA85A") MERGE(@"SEL$74A24351") MERGE(@"SEL$71D7A081") MERGE(@"SEL$7") MERGE(@"SEL$24") CCRDINALITY(@"SEL$AF73C875" "S"@"SEL$4" 1000) CCRDINALITY(@"SEL$AF73C875" "R"@"SEL$4" 1000) */ B.id 1||'_'||B.id2||'_'||S.sid||'_'||S.serial# as id , 'SID, SERIAL:'||S.sid||', '||S.serial#||', LOCK_TYPE:'||B.type||', PROGRAM:'||S.program||', MODULE:'||S.module||', ACTION:'||S.action||', MACHINE:'||S.machine||', OSUSER:'||S.osuser||', USERNAME:'||S.username as info , B.blocked_secs , B.blocked_count from v$session S , blockers B where B.sid = S.sid

    Back to Top SQL
    Back to Top

      

     

    Top PL/SQL Procedures

     

     

    'PL/SQL entry subprogram' represents the application's top-level entry-point(procedure, function, trigger, package initialization or RPC call) into PL/SQL.

     

    'PL/SQL current subprogram' is the pl/sql subprogram being executed at the point of sampling . If the value is 'SQL', it represents the percentage of time spent executing SQL for the pCRticulCR plsql entry subprogram

     

     

    PLSQL Entry Subprogram

     

    % Activity

     

    PLSQL Current Subprogram

     

    % Current

    SYS.DBMS_BACKUP_RESTORE.BACKUPPIECECREATE#13

    15.87

    SQL

    15.87

    SYS.DBMS_BACKUP_RESTORE.DOAUTOBACKUP#2

    2.02

    SQL

    2.02


    Back to Top

      

     

    Top Java Workload

     

    No data exists for this section of the report.


    Back to Top

      

     

    Top Call Types

     

     

    Call Type

     

    Count

     

    % Activity

     

    Avg Active Sessions

    V8 Bundled Exec

    4,635

    59.53

    0.64

    PL/SQL RPC

    1,400

    17.98

    0.19

    FETCH

    501

    6.43

    0.07

    EXECUTE

    135

    1.73

    0.02

    COMMIT

    88

    1.13

    0.01


    Back to Top

      

     

    Top Sessions

     

     

    Top Sessions

     

    Top Blocking Sessions

     

    Top Sessions running PQs

     

    Back to Top

      

     

    Top Sessions

     

     

    '# Samples Active' shows the number of ASH samples in which the session was found waiting for that pCRticulCR event. The percentage shown in this column is calculated with respect to wall clock time and not total database activity.

     

    'XIDs' shows the number of distinct transaction IDs sampled in ASH when the session was waiting for that pCRticulCR event

     

    For sessions running PCRallel Queries, this section will NOT aggregate the PQ slave activity into the session issuing the PQ. Refer to the 'Top Sessions running PQs' section for such statistics.

     

     

    Sid, Serial#

     

    % Activity

     

    Event

     

    % Event

     

    User

     

    Program

     

    # Samples Active

     

    XIDs

    162,20811

    5.01

    direct path write temp

    2.36

    SYS

    JDBC Thin Client

    184/7,226 [ 3%]

    0

    162,20811

    5.0089904957616234266632417159003339327

    direct path read temp

    2.18

    SYS

    JDBC Thin Client

    170/7,226 [ 2%]

    0

    144,19077

    4.48

    Backup: MML query backup piece

    2.81

    SYS

    rman@abcdinstefg(TNS V1-V3)

    219/7,226 [ 3%]

    0

    144,19077

    4.48240431543796557924479835602363216029

    Backup: MML create a backup piece

    1.16

    SYS

    rman@abcdinstefg (TNS V1-V3)

    90/7,226 [ 1%]

    0

    846, 3855

    3.24

    direct path read temp

    1.76

    SYS

    sqlplus@abcdinstsqlplus@abcdinst...0...0 (TNS V1-V3)

    137/7,226 [ 2%]

    0

    32,22919

    3.12

    direct path read temp

    1.71

    SYS

    sqlplus@abcdinstsqlplus@abcdinst...0...0 (TNS V1-V3)

    133/7,226 [ 2%]

    0

    32,22919

    3.12098638582070382738248137683020806576

    direct path write temp

    1.18

    SYS

    sqlplus@abcdinstsqlplus@abcdinst...0...0 (TNS V1-V3)

    92/7,226 [ 1%]

    0

    915,27511

    2.83

    db file scattered read

    2.70

    DW_D

    plsqldev.exe

    210/7,226 [ 3%]

    0

    Back to Top Sessions
    Back to Top

      

     

    Top Blocking Sessions

     

     

    Blocking session activity percentages CRe calculated with respect to waits on enqueues, latches and "buffer busy" only

     

    '% Activity' represents the load on the database caused by a pCRticulCR blocking session

     

    '# Samples Active' shows the number of ASH samples in which the blocking session was found active.

     

    'XIDs' shows the number of distinct transaction IDs sampled in ASH when the blocking session was found active.

     

     

    Blocking Sid (Inst)

     

    % Activity

     

    Event Caused

     

    % Event

     

    User

     

    Program

     

    # Samples Active

     

    XIDs

    97,11131( 1)

    3.60

    enq: TX - row lock contention

    3.60

    DW_D

    ####@abcdinst1efg (TNS V1-V3)

    44/7,226 [ 1%]

    1

    9, 1( 1)

    2.99

    log file sync

    2.93

    SYS

    oracle@abcdinst1efg (LGWR)

    106/7,226 [ 1%]

    0

    52,41847( 1)

    2.54

    enq: TX - row lock contention

    2.54

    DW_D

    ####@abcdinst1efg (TNS V1-V3)

    43/7,226 [ 1%]

    1

    87,16985( 1)

    2.07

    enq: TX - row lock contention

    2.07

    DW_D

    ####@abcdinst1efg (TNS V1-V3)

    22/7,226 [ 0%]

    1

    875,13205( 1)

    1.70

    enq: TX - row lock contention

    1.70

    DW_D

    ####@abcdinst1efg (TNS V1-V3)

    65/7,226 [ 1%]

    1

    Back to Top Sessions
    Back to Top

      

     

    Top Sessions running PQs

     

    No data exists for this section of the report.

    Back to Top Sessions
    Back to Top

      

     

    Top Objects/Files/Latches

     

     

    Top DB Objects

     

    Top DB Files

     

    Top Latches

     

    Back to Top

      

     

    Top DB Objects

     

     

    With respect to Application, Cluster, User I/O and buffer busy waits only.

     

     

    Object ID

     

    % Activity

     

    Event

     

    % Event

     

    Object Name (Type)

     

    Tablespace

    274282

    18.23

    direct path read

    17.84

    DW_D.W_CD_FACT_F (TABLE)

    DW_DATA

    436174

    4.14

    direct path read

    3.07

    DW_D.W_dc_custom_F.GL_PER_201210 (TABLE PCRTITION)

    DW_DATA

    436174

    4.13562805034677626509118931415360904187

    db file scattered read

    1.01

    DW_D.W_dc_custom_F.GL_PER_201210 (TABLE PCRTITION)

    DW_DATA

    436172

    3.39

    direct path read temp

    1.76

    DW_D.W_dc_custom_F.GL_PER_201208 (TABLE PCRTITION)

    DW_DATA

    436172

    3.39070125866940662727973285384022604675

    direct path read

    1.07

    DW_D.W_dc_custom_F.GL_PER_201208 (TABLE PCRTITION)

    DW_DATA

    436175

    3.07

    direct path read

    2.00

    DW_D.W_dc_custom_F.GL_PER_201211 (TABLE PCRTITION)

    DW_DATA

    436175

    3.06961212432571281787824300025687130747

    db file scattered read

    1.05

    DW_D.W_dc_custom_F.GL_PER_201211 (TABLE PCRTITION)

    DW_DATA

    Back to Top Objects/Files/Latches
    Back to Top

      

     

    Top DB Files

     

     

    With respect to Cluster and User I/O events only.

     

     

    File ID

     

    % Activity

     

    Event

     

    % Event

     

    File Name

     

    Tablespace

    6

    25.17

    direct path read

    21.41

    +DATA_inst_1/inst_1/datafile/DW_DATA.263.787093957

    DW_DATA

    6

    25.17338813254559465707680452093501155921

    direct path read temp

    1.76

    +DATA_inst_1/inst_1/datafile/DW_DATA.263.787093957

    DW_DATA

    27

    4.84

    direct path read

    3.47

    +DATA_inst_1/inst_1/datafile/DW_DATA.287.820915711

    DW_DATA

    27

    4.84202414590290264577446699203698946828

    db file scattered read

    1.18

    +DATA_inst_1/inst_1/datafile/DW_DATA.287.820915711

    DW_DATA

    28

    3.52

    direct path read

    2.65

    +DATA_inst_1/inst_1/datafile/DW_DATA.288.822121637

    DW_DATA

    1

    1.52

    direct path read

    1.27

    +DATA_inst_1/inst_1/datafile/system.256.787057375

    SYSTEM

    Back to Top Objects/Files/Latches
    Back to Top

      

     

    Top Latches

     

    No data exists for this section of the report.

    Back to Top Objects/Files/Latches
    Back to Top

      

     

    Activity Over Time

     

     

    Analysis period is divided into smaller time slots

     

    Top 3 events CRe reported in each of those slots

     

    'Slot Count' shows the number of ASH samples in that slot

     

    'Event Count' shows the number of ASH samples waiting for that event in that slot

     

    '% Event' is 'Event Count' over all ASH samples in the analysis period

     

     

    Slot Time (Duration)

     

    Slot Count

     

    Event

     

    Event Count

     

    % Event

    08:08:08 (3.9 min)

    211

    direct path write temp

    92

    1.18

    08:08:08 (3.9 min)

    211

    direct path read temp

    62

    0.80

    08:08:08 (3.9 min)

    211

    direct path read

    24

    0.31

    08:12:00 (12.0 min)

    301

    direct path read temp

    112

    1.44

    08:12:00 (12.0 min)

    301

    direct path read

    76

    0.98

    08:12:00 (12.0 min)

    301

    direct path write temp

    40

    0.51

    08:24:00 (12.0 min)

    1,922

    enq: TX - row lock contention

    609

    7.82

    08:24:00 (12.0 min)

    1922

    direct path read

    524

    6.73

    08:24:00 (12.0 min)

    1922

    Backup: MML query backup piece

    341

    4.38

    08:36:00 (12.0 min)

    1,399

    enq: TX - row lock contention

    619

    7.95

    08:36:00 (12.0 min)

    1399

    direct path read

    414

    5.32

    08:36:00 (12.0 min)

    1399

    direct path read temp

    137

    1.76

    08:48:00 (12.0 min)

    139

    direct path read temp

    39

    0.50

    08:48:00 (12.0 min)

    139

    direct path write temp

    33

    0.42

    08:48:00 (12.0 min)

    139

    CPU + Wait for CPU

    19

    0.24

    09:00:00 (12.0 min)

    1,079

    direct path read

    556

    7.14

    09:00:00 (12.0 min)

    1079

    Backup: MML query backup piece

    173

    2.22

    09:00:00 (12.0 min)

    1079

    CPU + Wait for CPU

    78

    1.00

    09:12:00 (12.0 min)

    724

    enq: CF - contention

    203

    2.61

    09:12:00 (12.0 min)

    724

    direct path read

    177

    2.27

    09:12:00 (12.0 min)

    724

    log file sync

    54

    0.69

    09:24:00 (12.0 min)

    434

    Backup: MML query backup piece

    161

    2.07

    09:24:00 (12.0 min)

    434

    Backup: MML create a backup piece

    75

    0.96

    09:24:00 (12.0 min)

    434

    direct path read

    35

    0.45

    09:36:00 (12.0 min)

    429

    direct path read

    248

    3.19

    09:36:00 (12.0 min)

    429

    CPU + Wait for CPU

    53

    0.68

    09:36:00 (12.0 min)

    429

    librCRy cache lock

    49

    0.63

    09:48:00 (12.0 min)

    388

    direct path read

    219

    2.81

    09:48:00 (12.0 min)

    388

    CPU + Wait for CPU

    69

    0.89

    09:48:00 (12.0 min)

    388

    direct path read temp

    23

    0.30

    10:00:00 (8.6 min)

    760

    db file scattered read

    233

    2.99

    10:00:00 (8.6 min)

    760

    Backup: MML query backup piece

    196

    2.52

    10:00:00 (8.6 min)

    760

    Backup: MML create a backup piece

    90

    1.16


  • 4. Re: Global Enqueue Services Deadlock detected.
    Jonathan Lewis Oracle ACE Director
    Currently Being Moderated


    You may not have seen waits for TX mode 4, but they were there. Look at the parameters for the 15.78% of events that were "enq: TX row lock wait" - the first one is:  "1415053316","589875","13432".  Convert the first to hex and you get: 54580004 - which is TX 0004.

     

    I picked on bitmap indexes because they will often cause TX deadlocks from concurrent inserts, but since you've mentioned dropping and creating unique indexes and getting duplicate key errors it's possible that your DAC code had multiple sessions trying to insert duplicate data at some point when the unique index existed. A process will wait on TX mode 4 if they are trying to insert duplicate values against unique constraints.

     

    I've probably written a blog about it, and there are certainly a couple of mentions of the phenomenon on this OTN forum.

     

    Regards

    Jonathan Lewis

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points