4 Replies Latest reply: Oct 2, 2013 3:08 PM by Jonathan Lewis RSS

    Global Enqueue Services Deadlock detected.

    user10188639

      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:---------------------------------

        • 2. Re: Global Enqueue Services Deadlock detected.
          Jonathan Lewis

          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

            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


              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