ASM Script to map disks with partner disks on Exadata

Script and output:

SQL> column "Partnerdisk" heading "Partner|Disks" format a30
SQL> column "PartnerdiskCell" heading "Partnerdisk|Cell" format a30
SQL> set pages 200
SQL>
  1  SELECT disk,
  2    cell,
  3    LISTAGG(NUMBER_KFDPARTNER, ',') WITHIN GROUP (ORDER BY NUMBER_KFDPARTNER) AS "Partnerdisk",
  4    LISTAGG(pd, ',') WITHIN GROUP (ORDER BY pd) AS "PartnerdiskCell",
  5    CASE
  6      WHEN instr(LISTAGG(pd, ',') WITHIN GROUP (ORDER BY pd),cell ) =0    THEN 'OK'
  7      WHEN instr(LISTAGG(pd, ',') WITHIN GROUP (ORDER BY pd),cell ) >0    THEN 'ERROR'
  8    END AS status
  9  FROM
 10    (SELECT disk,
 11      CASE
 12        WHEN DISK>= 0 AND DISK <=11 THEN 1
 13        WHEN DISK>=12 AND DISK <=23 THEN 2
 14        WHEN DISK>=24 AND DISK <=35 THEN 3
 15        WHEN DISK>=36 AND DISK <=47 THEN 4
 16        WHEN DISK>=48 AND DISK <=59 THEN 5
 17        WHEN DISK>=60 AND DISK <=71 THEN 6
 18        WHEN DISK>=72 AND DISK <=83 THEN 7
 19      END AS cell,
 20      NUMBER_KFDPARTNER,
 21      CASE
 22        WHEN NUMBER_KFDPARTNER>= 0 AND NUMBER_KFDPARTNER <=11 THEN 1
 23        WHEN NUMBER_KFDPARTNER>=12 AND NUMBER_KFDPARTNER <=23 THEN 2
 24        WHEN NUMBER_KFDPARTNER>=24 AND NUMBER_KFDPARTNER <=35 THEN 3
 25        WHEN NUMBER_KFDPARTNER>=36 AND NUMBER_KFDPARTNER <=47 THEN 4
 26        WHEN NUMBER_KFDPARTNER>=48 AND NUMBER_KFDPARTNER <=59 THEN 5
 27        WHEN NUMBER_KFDPARTNER>=60 AND NUMBER_KFDPARTNER <=71 THEN 6
 28        WHEN NUMBER_KFDPARTNER>=72 AND NUMBER_KFDPARTNER <=83 THEN 7
 29      END AS pd
 30    FROM V$ASM_DISK A,
 31         X$KFDPARTNER B
 32    WHERE B.NUMBER_KFDPARTNER = A.DISK_NUMBER
 33    AND GRP                   =1
 34    AND name LIKE 'DATA%'
 35    ORDER BY 1 ASC
 36    )
 37* GROUP BY disk,cell

                      Partner                        Partnerdisk
      DISK       CELL Disks                          Cell                           STATU
---------- ---------- ------------------------------ ------------------------------ -----
         0          1 29,30,32,66,71,78,79,83        3,3,3,6,6,7,7,7                OK
         1          1 28,31,34,62,68,70,76,82        3,3,3,6,6,6,7,7                OK
         2          1 27,29,66,67,68,72,73,77        3,3,6,6,6,7,7,7                OK
         3          1 16,28,30,33,35,70,74,80        2,3,3,3,3,6,7,7                OK
         4          1 27,28,33,35,60,66,76,80        3,3,3,3,6,6,7,7                OK
         5          1 12,24,65,67,70,75,76,83        2,3,6,6,6,7,7,7                OK
         6          1 25,26,31,68,69,71,72,82        3,3,3,6,6,6,7,7                OK
         7          1 12,18,19,20,22,26,27,82        2,2,2,2,2,3,3,7                OK
         8          1 16,22,23,64,68,69,71,76        2,2,2,6,6,6,6,7                OK
         9          1 22,25,29,66,69,73,76,81        2,3,3,6,6,7,7,7                OK
        10          1 21,26,28,33,64,73,79,81        2,3,3,3,6,7,7,7                OK
        11          1 13,17,18,19,21,32,67,70        2,2,2,2,2,3,6,6                OK
        12          2 5,7,36,45,46,81,82,83          1,1,4,4,4,7,7,7                OK
        13          2 11,38,41,44,74,78,79,82        1,4,4,4,7,7,7,7                OK
        14          2 38,42,44,47,74,76,79,80        4,4,4,4,7,7,7,7                OK
        15          2 29,35,42,45,76,78,81,82        3,3,4,4,7,7,7,7                OK
        16          2 3,8,29,44,46,47,73,78          1,1,3,4,4,4,7,7                OK
        17          2 11,36,42,45,46,72,81,82        1,4,4,4,4,7,7,7                OK
        18          2 7,11,41,44,47,74,79,83         1,1,4,4,4,7,7,7                OK
        19          2 7,11,44,45,72,79,80,81         1,1,4,4,7,7,7,7                OK
        20          2 7,36,42,43,47,78,80,83         1,4,4,4,4,7,7,7                OK
        21          2 10,11,42,45,72,73,81,83        1,1,4,4,7,7,7,7                OK
        22          2 7,8,9,24,30,38,43,47           1,1,1,3,3,4,4,4                OK
        23          2 8,30,31,32,33,43,79,80         1,3,3,3,3,4,7,7                OK
        24          3 5,22,37,44,47,48,50,59         1,2,4,4,4,5,5,5                OK
        25          3 6,9,36,42,52,53,56,59          1,1,4,4,5,5,5,5                OK
        26          3 6,7,10,38,41,55,57,58          1,1,1,4,4,5,5,5                OK
        27          3 2,4,7,39,40,41,49,59           1,1,1,4,4,4,5,5                OK
        28          3 1,3,4,10,40,41,56,57           1,1,1,1,4,4,5,5                OK
        29          3 0,2,9,15,16,36,37,43           1,1,1,2,2,4,4,4                OK
        30          3 0,3,22,23,39,51,56,58          1,1,2,2,4,5,5,5                OK
        31          3 1,6,23,36,40,50,52,54          1,1,2,4,4,5,5,5                OK
        32          3 0,11,23,37,38,44,48,49         1,1,2,4,4,4,5,5                OK
        33          3 3,4,10,23,37,46,52,58          1,1,1,2,4,4,5,5                OK
        34          3 1,39,42,45,49,50,51,56         1,4,4,4,5,5,5,5                OK
        35          3 3,4,15,39,48,50,51,53          1,1,2,4,5,5,5,5                OK
        36          4 12,17,20,25,29,31,56,63        2,2,2,3,3,3,5,6                OK
        37          4 24,29,32,33,48,56,61,62        3,3,3,3,5,5,6,6                OK
        38          4 13,14,22,26,32,55,66,70        2,2,2,3,3,5,6,6                OK
        39          4 27,30,34,35,53,57,65,68        3,3,3,3,5,5,6,6                OK
        40          4 27,28,31,55,58,60,63,69        3,3,3,5,5,6,6,6                OK
        41          4 13,18,26,27,28,59,67,68        2,2,3,3,3,5,6,6                OK
        42          4 14,15,17,20,21,25,34,62        2,2,2,2,2,3,3,6                OK
        43          4 20,22,23,29,53,60,63,64        2,2,2,3,5,6,6,6                OK
        44          4 13,14,16,18,19,24,32,63        2,2,2,2,2,3,3,6                OK
        45          4 12,15,17,19,21,34,54,71        2,2,2,2,2,3,5,6                OK
        46          4 12,16,17,33,49,54,57,58        2,2,2,3,5,5,5,5                OK
        47          4 14,16,18,20,22,24,50,62        2,2,2,2,2,3,5,6                OK
        48          5 24,32,35,37,60,66,78,83        3,3,3,4,6,6,7,7                OK
        49          5 27,32,34,46,64,65,67,73        3,3,3,4,6,6,6,7                OK
        50          5 24,31,34,35,47,62,65,69        3,3,3,3,4,6,6,6                OK
        51          5 30,34,35,62,64,70,74,75        3,3,3,6,6,6,7,7                OK
        52          5 25,31,33,61,65,70,72,75        3,3,3,6,6,6,7,7                OK
        53          5 25,35,39,43,60,67,74,75        3,3,4,4,6,6,7,7                OK
        54          5 31,45,46,63,64,68,75,77        3,4,4,6,6,6,7,7                OK
        55          5 26,38,40,60,61,63,71,73        3,4,4,6,6,6,6,7                OK
        56          5 25,28,30,34,36,37,60,61        3,3,3,3,4,4,6,6                OK
        57          5 26,28,39,46,62,63,77,78        3,3,4,4,6,6,7,7                OK
        58          5 26,30,33,40,46,63,66,71        3,3,3,4,4,6,6,6                OK
        59          5 24,25,27,41,61,69,74,77        3,3,3,4,6,6,7,7                OK
        60          6 4,40,43,48,53,55,56,72         1,4,4,5,5,5,5,7                OK
        61          6 37,52,55,56,59,75,78,82        4,5,5,5,5,7,7,7                OK
        62          6 1,37,42,47,50,51,57,74         1,4,4,4,5,5,5,7                OK
        63          6 36,40,43,44,54,55,57,58        4,4,4,4,5,5,5,5                OK
        64          6 8,10,43,49,51,54,73,75         1,1,4,5,5,5,7,7                OK
        65          6 5,39,49,50,52,72,77,83         1,4,5,5,5,7,7,7                OK
        66          6 0,2,4,9,38,48,58,81            1,1,1,1,4,5,5,7                OK
        67          6 2,5,11,41,49,53,76,77          1,1,1,4,5,5,7,7                OK
        68          6 1,2,6,8,39,41,54,79            1,1,1,1,4,4,5,7                OK
        69          6 6,8,9,40,50,59,75,77           1,1,1,4,5,5,7,7                OK
        70          6 1,3,5,11,38,51,52,80           1,1,1,1,4,5,5,7                OK
        71          6 0,6,8,45,55,58,77,80           1,1,1,4,5,5,7,7                OK
        72          7 2,6,17,19,21,52,60,65          1,1,2,2,2,5,6,6                OK
        73          7 2,9,10,16,21,49,55,64          1,1,1,2,2,5,5,6                OK
        74          7 3,13,14,18,51,53,59,62         1,2,2,2,5,5,5,6                OK
        75          7 5,51,52,53,54,61,64,69         1,5,5,5,5,6,6,6                OK
        76          7 1,4,5,8,9,14,15,67             1,1,1,1,1,2,2,6                OK
        77          7 2,54,57,59,65,67,69,71         1,5,5,5,6,6,6,6                OK
        78          7 0,13,15,16,20,48,57,61         1,2,2,2,2,5,5,6                OK
        79          7 0,10,13,14,18,19,23,68         1,1,2,2,2,2,2,6                OK
        80          7 3,4,14,19,20,23,70,71          1,1,2,2,2,2,6,6                OK
        81          7 9,10,12,15,17,19,21,66         1,1,2,2,2,2,2,6                OK
        82          7 1,6,7,12,13,15,17,61           1,1,1,2,2,2,2,6                OK
        83          7 0,5,12,18,20,21,48,65          1,1,2,2,2,2,5,6                OK

84 rows selected.

Above output is from half rack Exadata with normal ASM disk group redundancy. Basically it shows that for a particular disk, mirrored extent will be created on one of eight partner disks listed and Partnerdisk Cell column shows on which cell partner disks are located. Status column will show whether Exadata will survive cell failure or not (OK if it will, ERROR if it may not).

Hash Join Performance Bug on 11.2.0.2 AIX 6.1 64bit

Problem

Development ETL team started complaining about performance after upgrading development database to 11.2.0.2 on AIX 64 bit. Good news was not everything is slow but few steps in ETL job was taking longer in 11g compared to that of 10g.  QA environment was on 10g with same amount of data as Development and I was able to reproduce slowness in 11g.

Trobleshooting

I first created a test case to reproduce and run some test quickly with smaller data set. Create tables in either 10g and 11g and them move data from 10g to 11g or vice a versa.

DROP TABLE hash_big; 

CREATE TABLE hash_big
  (
     uniq_n NUMBER,
     var_n  VARCHAR2(100),
     geozip VARCHAR2(3),
     proc   VARCHAR2(1)
  )
tablespace users; 

INSERT /*+append*/ INTO hash_big
SELECT ROWNUM,
       dbms_random.String('A', 20),
       Round(dbms_random.VALUE(0, 999)),
       'C'
FROM   dual
CONNECT BY LEVEL <= 11111111
/

DROP TABLE hash_small; 

CREATE TABLE hash_small
  (
     geozip VARCHAR2(3),
     begzip VARCHAR2(3),
     endzip VARCHAR2(3),
     proc   VARCHAR2(1)
  )
tablespace users; 

insert into hash_small values ('001','001','099','C');
insert into hash_small values ('101','101','199','C');
insert into hash_small values ('201','201','299','C');
insert into hash_small values ('301','301','399','C');
insert into hash_small values ('401','401','499','C');
insert into hash_small values ('501','501','599','C');
insert into hash_small values ('601','601','699','C');
insert into hash_small values ('701','701','799','C');
insert into hash_small values ('801','801','899','C');
insert into hash_small values ('901','901','999','C');
commit;

exec dbms_stats.gather_table_Stats('SYSTEM','HASH_SMALL');
exec dbms_stats.gather_table_Stats('SYSTEM','HASH_BIG');

select segment_name,blocks,bytes/1024/1024 from dba_segments
where segment_name in ('HASH_SMALL','HASH_BIG');

SEGMENT_NAME                                 BLOCKS BYTES/1024/1024
---------------------------------------- ---------- ---------------
HASH_BIG                                      29184             456
HASH_SMALL                                        8            .125

--Populate tables with data in only one database and then move data to another version of database to maintain consistency.
--Tables size in blocks and MB must be same in 10g and 11g

Test Queries:

select /*+ ordered parallel (s,4) parallel (b,4) */ count(1) from hash_small s, hash_big b
where s.proc=b.proc
and b.geozip between s.begzip and s.endzip;

select count(1) from hash_small s, hash_big b
where s.proc=b.proc
and b.geozip BETWEEN s.begzip and s.endzip;

I ran above select statments in parallel and serial mode 5 times from same session with autotrace on.

10g Parallel:

Elapsed          Consistent   Physical   Parse
00:00:16.43      29441        28813       Hard
00:00:15.05      28977        28761       Soft
00:00:14.73      28977        28761       Soft
00:00:14.76      28977        28761       Soft
00:00:15.75      28977        28761       Soft                                                                                             

11g Parallel:

Elapsed          Consistent Physical    Parse
00:00:22.48      29538      28813       Hard
00:00:20.01      29191      28763       Soft
00:00:19.83      29191      28763       Soft
00:00:19.99      29191      28763       Soft
00:00:19.82      29191      28763       Soft

10g Serial:

Elapsed          Consistent Physical    Parse
00:00:24.65      29043      28792       Hard
00:00:22.26      28783          0       Soft
00:00:22.85      28783          0       Soft
00:00:24.93      28783          0       Soft
00:00:22.34      28783          0       Soft

11g Serial:

Elapsed          Consistent Physical    Parse
00:00:32.68      29069      28800       Hard
00:00:32.75      28778      28763       Soft
00:00:32.56      28778      28763       Soft
00:00:32.45      28778      28763       Soft
00:00:32.25      28778      28763       Soft

From above results it shows queries in 11g are approximately 25% slower compared to that of 10g. In 11g serial mode physical reads remain high and that was due to _serial_direct_read=TRUE in 11g. Lets first filter through obvious things.

10g serial trace:

select count(1) from hash_small s, hash_big b
where s.proc=b.proc
and b.geozip BETWEEN s.begzip and s.endzip

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.07          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2     15.23      30.26      28768      28783          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4     15.24      30.34      28768      28783          0           1

Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: 5

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT AGGREGATE (cr=28783 pr=28768 pw=0 time=30268579 us)
10805391   HASH JOIN  (cr=28783 pr=28768 pw=0 time=32424435 us)
     10    TABLE ACCESS FULL HASH_SMALL (cr=7 pr=6 pw=0 time=4061 us)
11111111    TABLE ACCESS FULL HASH_BIG (cr=28776 pr=28762 pw=0 time=4057 us)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       2        0.00          0.00
  db file sequential read                         2        0.00          0.00
  db file scattered read                        918        0.05          6.78
  SQL*Net message from client                     2        0.00          0.00

11g serial trace:

select count(1) from hash_small s, hash_big b
where s.proc=b.proc
and b.geozip BETWEEN s.begzip and s.endzip

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.04       0.26         10         61          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2     20.63      35.33      28774      28778          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4     20.67      35.60      28784      28839          0           1

Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: 5
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  SORT AGGREGATE (cr=28778 pr=28774 pw=0 time=35338639 us)
  10805391   10805391   10805391   HASH JOIN  (cr=28778 pr=28774 pw=0 time=35226688 us cost=9624 size=444327376 card=27770461)
        10         10         10    TABLE ACCESS FULL HASH_SMALL (cr=6 pr=6 pw=0 time=7968 us cost=3 size=100 card=10)
  11111111   11111111   11111111    TABLE ACCESS FULL HASH_BIG (cr=28772 pr=28768 pw=0 time=5462617 us cost=9070 size=66666666 card=11111111)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       2        0.00          0.00
  Disk file operations I/O                        8        0.00          0.01
  db file sequential read                         4        0.00          0.00
  db file scattered read                          2        0.00          0.00
  direct path read                              116        0.04          1.32
  SQL*Net message from client                     2        0.00          0.00

From above its cleare that plans are same, cosistent and physical reads are almost same in 10g and 11g. Difference in elapsed time comes from CPU column during fetch. (15.24 seconds in 10g and 20.57 seconds in 11g). To rule out _serial_direct_read=TRUE, I increased _small_table_threshold to a large value and below were the results:

11g disable _serial_direct_read

SQL> alter session set "_small_table_threshold"=10000000;

Session altered.

Elapsed: 00:00:00.00
SQL> alter session set "_serial_direct_read"=false;

Session altered.

Elapsed: 00:00:00.01
SQL> select count(1) from hash_small s, hash_big b
  2  where s.proc=b.proc
  3  and b.geozip BETWEEN s.begzip and s.endzip;

  COUNT(1)
----------
  10805391

Elapsed: 00:00:49.15

Execution Plan
----------------------------------------------------------
Plan hash value: 753592804

----------------------------------------------------------------------------------
| Id  | Operation           | Name       | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |            |     1 |    16 |  9624   (8)| 00:02:15 |
|   1 |  SORT AGGREGATE     |            |     1 |    16 |            |          |
|*  2 |   HASH JOIN         |            |    27M|   423M|  9624   (8)| 00:02:15 |
|   3 |    TABLE ACCESS FULL| HASH_SMALL |    10 |   100 |     3   (0)| 00:00:01 |
|   4 |    TABLE ACCESS FULL| HASH_BIG   |    11M|    63M|  9070   (2)| 00:02:07 |
----------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("S"."PROC"="B"."PROC")
       filter("B"."GEOZIP">="S"."BEGZIP" AND "B"."GEOZIP"<="S"."ENDZIP")

Statistics
----------------------------------------------------------
         63  recursive calls
          0  db block gets
      28849  consistent gets
      28784  physical reads
          0  redo size
        210  bytes sent via SQL*Net to client
        236  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
         10  sorts (memory)
          0  sorts (disk)
          1  rows processed

SQL> /

  COUNT(1)
----------
  10805391

Elapsed: 00:00:34.39

Execution Plan
----------------------------------------------------------
Plan hash value: 753592804

----------------------------------------------------------------------------------
| Id  | Operation           | Name       | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |            |     1 |    16 |  9624   (8)| 00:02:15 |
|   1 |  SORT AGGREGATE     |            |     1 |    16 |            |          |
|*  2 |   HASH JOIN         |            |    27M|   423M|  9624   (8)| 00:02:15 |
|   3 |    TABLE ACCESS FULL| HASH_SMALL |    10 |   100 |     3   (0)| 00:00:01 |
|   4 |    TABLE ACCESS FULL| HASH_BIG   |    11M|    63M|  9070   (2)| 00:02:07 |
----------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("S"."PROC"="B"."PROC")
       filter("B"."GEOZIP">="S"."BEGZIP" AND "B"."GEOZIP"<="S"."ENDZIP")

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
      28788  consistent gets
          0  physical reads
          0  redo size
        227  bytes sent via SQL*Net to client
        236  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

In 11g with soft parse and no physical reads it took almost same amount of time so earlier increase in CPU seconds on 11g was not due to more physical reads. My test case run only for few seconds so I don’t want to run procstack from AIX on my test case. So lets take a look at original code.

alter session enable parallel dml;

insert --+ parallel(ii,8) append
              into repos_hi_lo_neg_clnup_geo ii
select --+ ordered parallel(t1,8) parallel(gt,8) full(t1) full(gt)
                    t1.RCN_ID,
                    t1.error_flag,
                    t1.job_id,
                    t1.scb_id,
                    t1.sub_id,
                    t1.proc_type,
                    t1.proc,
                    t1.mod1,
                    t1.mod2,
                    t1.mdr_flag,
                    t1.alm_flag,
                    t1.provider_key,
                    t1.bill_id_key,
                    t1.patient_id_key,
                    t1.repos_stamp,
                    t1.line_no,
                    t1.charge,
                    t1.allowed_amt,
                    t1.quarter,
                    t1.rend_zip,
                    gt.geozip,
                     t1.row_id
              from  geozip_mv gt,repos_hi_lo_neg_cleanup t1
                                  where t1.proc_type=gt.proc_type
                                 and  t1.sub_rend_zip between gt.begzip and gt.endzip;

As it was DEV/QA environment I was able to run actual ETL jobs. Samples of procstack on one of the parallel slaves from 10g and 11g are as follows:

10g procstack samples:

$ procstack 62193776 | head -5
62193776: ora_p012_CSPRDPP1
0x00000001000f6ce8  sskgpwpost(??, ??, ??, ??) + 0x28
0x00000001000f43f0  skgpwpost(??, ??, ??, ??) + 0x10
0x0000000100113ba8  kslpsprns(??, ??, ??) + 0x128
0x000000010016c5b4  kskpthr(??, ??, ??) + 0x194
$ procstack 62193776 | head -5
62193776: ora_p012_CSPRDPP1
0x00000001000f6ce8  sskgpwpost(??, ??, ??, ??) + 0x28
0x00000001000f43f0  skgpwpost(??, ??, ??, ??) + 0x10
0x0000000100113ba8  kslpsprns(??, ??, ??) + 0x128
0x000000010016c5b4  kskpthr(??, ??, ??) + 0x194
$ procstack 62193776 | head -5
62193776: ora_p012_CSPRDPP1
0x0000000102b4de54  kxhrPUcompare(??, ??, ??, ??) + 0x2b4
0x0000000103a1ead4  qerhjWalkHashBucket(??, ??, ??) + 0xb4
0x0000000103a1e540  qerhjInnerProbeHashTable(??, ??) + 0x2c0
0x0000000103b497dc  kdstf0000001kmP(??, ??, ??, ??, ??, ??, ??, ??) + 0xfdc
$ procstack 62193776 | head -5
62193776: ora_p012_CSPRDPP1
0x00000001000f6ce8  sskgpwpost(??, ??, ??, ??) + 0x28
0x00000001000f43f0  skgpwpost(??, ??, ??, ??) + 0x10
0x0000000100113ba8  kslpsprns(??, ??, ??) + 0x128
0x000000010016c5b4  kskpthr(??, ??, ??) + 0x194
$ procstack 62193776 | head -5
62193776: ora_p012_CSPRDPP1
0x00000001000f6ce8  sskgpwpost(??, ??, ??, ??) + 0x28
0x00000001000f43f0  skgpwpost(??, ??, ??, ??) + 0x10
0x0000000100113ba8  kslpsprns(??, ??, ??) + 0x128
0x000000010016c5b4  kskpthr(??, ??, ??) + 0x194
$ procstack 62193776 | head -5
62193776: ora_p012_CSPRDPP1
0x00000001000f6ce8  sskgpwpost(??, ??, ??, ??) + 0x28
0x00000001000f43f0  skgpwpost(??, ??, ??, ??) + 0x10
0x0000000100113ba8  kslpsprns(??, ??, ??) + 0x128
0x000000010016c5b4  kskpthr(??, ??, ??) + 0x194

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                          1,458          12.3
ksdxexeotherwait                  3,700,589          43      0    0.4      Other
db file parallel write                1,505           8      6    0.1 System I/O
direct path read                      6,778           7      1    0.1   User I/O
PX qref latch                     4,494,867           6      0    0.0      Other

11g procstack samples:

$ procstack 9175324 | head -5
9175324: ora_p007_CSPRDDV1
0x00000001052da81c  rworofprVeryFastUnpackRow(??, ??, ??, ??, ??) + 0x33c
0x00000001073f2f34  kxhrUnpack(??, ??, ??, ??, ??) + 0x94
0x00000001073eb79c  qerhjWalkHashBucket(??, ??, ??) + 0x2fc
0x00000001073ec948  qerhjInnerProbeHashTable(??, ??) + 0x4a8
$ procstack 9175324 | head -5
9175324: ora_p007_CSPRDDV1
0x00000001052da6d4  rworofprVeryFastUnpackRow(??, ??, ??, ??, ??) + 0x1f4
0x00000001073f2f34  kxhrUnpack(??, ??, ??, ??, ??) + 0x94
0x00000001073eb79c  qerhjWalkHashBucket(??, ??, ??) + 0x2fc
0x00000001073ec948  qerhjInnerProbeHashTable(??, ??) + 0x4a8
$ procstack 9175324 | head -5
9175324: ora_p007_CSPRDDV1
0x00000001060f8d14  expepr(??) + 0x3d4
0x00000001060f88f8  expeal(??) + 0x18
0x00000001073eb7b0  qerhjWalkHashBucket(??, ??, ??) + 0x310
0x00000001073ec948  qerhjInnerProbeHashTable(??, ??) + 0x4a8
$ procstack 9175324 | head -5
9175324: ora_p007_CSPRDDV1
0x0000000101edd08c  evareo(??) + 0x2c
0x00000001060f8cdc  expepr(??) + 0x39c
0x00000001060f92c8  evaiand(??) + 0x48
0x00000001060f88f8  expeal(??) + 0x18
$ procstack 9175324 | head -5
9175324: ora_p007_CSPRDDV1
0x00000001060f8d00  expepr(??) + 0x3c0
0x00000001060f88f8  expeal(??) + 0x18
0x00000001073eb7b0  qerhjWalkHashBucket(??, ??, ??) + 0x310
0x00000001073ec948  qerhjInnerProbeHashTable(??, ??) + 0x4a8
$  procstack 9175324 | head -5
9175324: ora_p007_CSPRDDV1
0x00000001073f45f4  kxhrPUcompare(??, ??, ??, ??) + 0x334
0x00000001073ec948  qerhjInnerProbeHashTable(??, ??) + 0x4a8
0x000000010561f2b4  kdstf00000010000kmP(??, ??, ??, ??, ??, ??, ??, ??) + 0xa54
0x00000001055fb684  kdsttgr(??, ??, ??, ??, ??, ??, ??, ??) + 0xece4

                                                           Avg
                                                          wait   % DB
Event                                 Waits     Time(s)   (ms)   time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
DB CPU                                            1,876          11.6
ksdxexeotherwait                        220         118    535     .7 Other
direct path read                        451          33     73     .2 User I/O
Disk file operations I/O                564          12     21     .1 User I/O
control file sequential read          2,496           4      2     .0 System I/O

Again, query spend more time on CPU in 11g compared to that of 10g. 11g stack shows following functions:

rworofprVeryFastUnpackRow
expepr
evareo
kxhrPUcompare

I ran more samples in real time and most of the time procstack top function in 11g was from one of the above. I tried to search in metalink but couldn’t find exact description but from the name it looks like some kind of expression evaluation functions (expepr, kxhrPUcompare) which will be used by equality join as well as between clause. Further I ran test case queries by removing between clause as well as changing joining column fields to number field but results were same. I created SR using all these details and Oracle was able to reproduce this issue on their internal systems. As of now Oracle has filed this as bug 11689561.

Blocking Lock script

Tool

I just learned from AOT training that v$session is a gold mine and has lot of information about blocking session and final blocking session. So it was time for me to modify my old blocking lock script.

If the script is run on 10g it will only display blocking session. If it is run on 11g it will display blocking and final blocking session.

Sample Output

                                                                                          final
                                                          blocking        blocking        blocking        final
                                                          instance        lockholder      instance        lockholder
Inst                           P2              P3         sid             name            sid             name
  Id  SID SERIAL# P1           ID1             ID2        status          mode            status          mode
---- ---- ------- ------------ --------------- ---------- --------------- --------------- --------------- ---------------
   1    9    6001 Name=TX mode usn<<16 | slot= sequence=3 1 10 VALID      Name=TX mode=6  1 591 VALID
                  =6 X         1245251         60                         X id1=1245251 i
                                                                          d2=360

   1   10    4925 Name=TX mode usn<<16 | slot= sequence=3 1 591 VALID     Name=TX mode=6  1 591 VALID     Name=TX mode=6
                  =6 X         1310780         56                         X id1=1310780 i                 X id1=1310780 i
                                                                          d2=356                          d2=356

SQL> @bl

                                                                                          final
                                                          blocking        blocking        blocking        final
                                                          instance        lockholder      instance        lockholder
Inst                           P2              P3         sid             name            sid             name
  Id  SID SERIAL# P1           ID1             ID2        status          mode            status          mode
---- ---- ------- ------------ --------------- ---------- --------------- --------------- --------------- ---------------
   1   10    4925 Name=TM mode object #=77657  table/part 1 591 VALID     Name=TM mode=3  1 591 VALID     Name=TM mode=3
                  =4 share                     ition=0                    row-X id1=77657                 row-X id1=77657
                                                                           id2=0                           id2=0

Download script