Big Data and Privacy

I am writing an editorial (which is unusual for me). This was caused by a conversation I had with my Dad about how the world is changing with big data, and how much retiree's (like him) should know.  So here goes.

Dear Dad,

  I know you are involved in college education for Older folks that have a passion to learn.  An interesting topic would be "Big Data".  For someone outside the IT field, I would tell you that Big Data describes the plethora of new data that is generated in today's society.
Where does it come from ??

• Logs from webservers 
• Cell phones (including location data).
• Search data
• Medical data
• Machine generated data (like from your computer in your car)
• Sales data

All this can be tied together in new ways, that most people didn't think were possible years ago.  My favorite example is... You are walking in the mall past past a store, and you get a text on your phone.  The store's computer system has texted you a 30% offer for a new sweater, good for 2 hours.  The store knows ...

• Your location from phone
• That you have a ski trip planned for the next week, from your search history, and purchase history
• That you are looking for a new sweater from your facebook, and twitter posts.

Amazing huh ?

All these things can open up miraculous possibilities. The day may come when your doctor calls you to schedule a preventive test.  Medical history gathered from a large group of people has shown that others with a similar medical history as yours have had a issue that can be tested for and prevented. Wow. really amazing things.

They can predict something that may go wrong on your car given all the information the computer has gathered.

Target (the department store), has even predicted when a woman is pregnant based on purchase history.. 

All these things are amazing possiblities, but they are also scary.

I find this topic very exciting, but I'm sure for a lot of people these ideas are very scary. Where do you cross the line and enter privacy issues.

This is going to be a interesting battle. Who ones all this data ? what data is public, and what data is private ?

But the most interesting thing is what can be done with the data....

Me, I'm an optimist so I can all the good that can come out of all this new data.

At the very least, the students would at least have a better idea what is going on in the world (behind the scenes), and they would understand why Target things "grandma" is pregnant.

ODI Monitoring scripts

I have included some usefule ODI monitoring scripts (if you want the abridged version of this blog post).

I haven't been blogging in a while (it's been crazy), but I wanted to share some information on ODI.

I have been working on trying to monitor ODI (Oracle Data Integrator).  ODI is a somewhat recent Oracle purchase, and it has a client GUI that is used by the developers.

Me (like many of you), are DBA's, and we want to go into the database to see what is happening.  We eithor don't have access to the GUI, or we don't want access. 

ODI is a great tool used for transforming data.  It can be used to build sql statments that are executed directly in the database.  This makes it a bit different from a tool like Datastage that runs sql remotely.

Here is the first sql I was able to come up with.  It will tell you information about the load plans that have been run. You need to qualify the tables with the owner of the ODI repository..

SELECT SLI.I_LP_INST AS "Load Plan Instance #"
     , SLR.NB_RUN AS "Load Plan Run #"
     , SLI.LOAD_PLAN_NAME AS "Load Plan Name"
     , SLR.CONTEXT_CODE AS "Source System"
     , SLR.STATUS AS "Load Plan Status"
     , SLR.RETURN_CODE AS "error code"
     , CASE WHEN SLR.END_DATE IS NULL 
            THEN TRUNC(ROUND((NVL(SLR.END_DATE , SYSDATE) - SLR.START_DATE)*86400) / 3600) || ':' || 
                 LPAD(TRUNC(MOD(ROUND((NVL(SLR.END_DATE , SYSDATE) - SLR.START_DATE)*86400), 3600) / 60), 2, 0) || ':' || 
                 LPAD(MOD(ROUND((NVL(SLR.END_DATE , SYSDATE) - SLR.START_DATE)*86400), 60), 2, 0)
            ELSE TRUNC(SLR.DURATION / 3600) || ':' || LPAD(TRUNC(MOD(SLR.DURATION, 3600) / 60), 2, 0) || ':' || LPAD(MOD(SLR.DURATION, 60), 2, 0) 
       END AS "Load Time"
     , SLR.START_DATE
     , SLR.END_DATE
     , substr(to_char(SLR.START_DATE,'mm/dd/yy:hh24'),1,11) start_date_hour
  FROM SNP_LP_INST SLI
  JOIN SNP_LPI_RUN SLR ON SLI.I_LP_INST = SLR.I_LP_INST
where 'JRNL_LOAD'=sli.load_plan_name

I was able to include this in an apex report, and it display some of the history.

The next SQL igives you detail of the scenarios, for the load plan. The input is the Load plan

SELECT SLI.Load_plan_name as "Load Plan Name",
      SUBSTR(SLR.CONTEXT_CODE, 9, 5) AS "Source System",
      SLS.LP_STEP_NAME AS "Target Table",
      SLS.scen_name as "scenario name",
     TRUNC(SUM(SSTL.TASK_DUR) / 3600) || ':' ||
             LPAD(TRUNC(MOD(SUM(SSTL.TASK_DUR), 3600) / 60), 2, 0) || 
            ':' || LPAD(MOD(SUM(SSTL.TASK_DUR), 60), 2, 0) AS "Load Time"
     , SST.SESS_NO AS "Session Number"
     , SLSL.start_date as "Start Time"
     , SLSL.End_date as "End Time"
     , sum(sstl.nb_ins) as "Rows Inserted"
     , sum(sstl.nb_upd) as "Rows Updated"
     , sum(sstl.nb_del) as "Rows Deleted"
     , sum(sstl.nb_err) as "Rows Errors"
     , case 
        when (sum(sstl.nb_ins) + sum(sstl.nb_upd)) > 0 then trunc(sum(sstl.task_dur)/(sum(sstl.nb_ins) + sum(sstl.nb_upd)) ,4)
        else 0
       end as "Throughput"
  FROM SNP_LP_INST SLI
  JOIN SNP_LPI_STEP SLS 
                  ON SLI.I_LP_INST = SLS.I_LP_INST
  JOIN SNP_LPI_STEP_LOG SLSL
        ON SLS.I_LP_STEP = SLSL.I_LP_STEP
      AND SLS.I_LP_INST = SLSL.I_LP_INST
  JOIN SNP_SESS_TASK SST
            ON SST.SESS_NO = SLSL.SESS_NO
  JOIN SNP_SESS_TASK_LOG SSTL
            ON SSTL.SCEN_TASK_NO = SST.SCEN_TASK_NO 
           AND SST.SESS_NO = SSTL.SESS_NO
  JOIN SNP_LPI_RUN  SLR 
            on SLI.I_LP_INST = SLR.I_LP_INST
 WHERE (1=1)
  AND SLSL.I_LP_INST = :P6_SCENARIO
   AND SLS.LP_STEP_TYPE = 'RS'
--   AND SLSL.STATUS IN ('M','D')
 GROUP BY SUBSTR(SLR.CONTEXT_CODE, 9, 5),
           SLSL.start_date,SLSL.end_date,SLI.load_plan_name,
          SLS.scen_name,SLS.LP_STEP_NAME, SST.SESS_NO

Finally, this is the last query. This query takes the task number as an input, and will display the detail for all the tasks contained in a scenario.

SELECT SST.TASK_NAME2 AS "Session Name"
     , SST.TASK_NAME3 AS "Task Name"
     , CASE WHEN SSTL.TASK_END IS NULL 
            THEN TRUNC(ROUND((NVL(SSTL.TASK_END , SYSDATE) - SSTL.TASK_BEG)*86400) / 3600) || ':' || 
                 LPAD(TRUNC(MOD(ROUND((NVL(SSTL.TASK_END , SYSDATE) - SSTL.TASK_BEG)*86400), 3600) / 60), 2, 0) || ':' || 
                 LPAD(MOD(ROUND((NVL(SSTL.TASK_END , SYSDATE) - SSTL.TASK_BEG)*86400), 60), 2, 0)
            ELSE TRUNC(TASK_DUR / 3600) || ':' || LPAD(TRUNC(MOD(TASK_DUR, 3600) / 60), 2, 0) || ':' || LPAD(MOD(TASK_DUR, 60), 2, 0) 
       END AS "Load Time"
     , substr(sst.def_context_code,9,5) "Context"
     , SSTL.TASK_BEG AS "Start Time"
     , SSTL.TASK_END AS "End Time"
     , SSTL.NB_DEL AS "Rows Deleted"
     , SSTL.NB_UPD AS "Rows Updated"
     , SSTL.NB_INS AS "Rows Inserted"
     , SSTL.NB_ERR AS "# Of Errors"
     , SST.SESS_NO 
     , sst.scen_task_no
/* UNCOMMENT TO GET SQL EXECUTED FOR THIS STEP */
  FROM SNP_SESS_TASK SST,
      SNP_SESS_TASK_LOGv SSTL 
 WHERE (1=1)
   AND SST.SESS_NO =:P7_TASK   
   AND SSTL.TASK_STATUS IN ('D','M','R')
   AND SSTL.SCEN_TASK_NO = SST.SCEN_TASK_NO 
   AND SST.SESS_NO = SSTL.SESS_NO
 

Anayzing query Cost example

Well,
  Here is the issue I've been dealing with.  The query cost doesn't stay consistent, and I was wondering if a profile would help keep it stable, and if it keeps things better or worse.

  I'm sure you have all run into this.  For some reason your cardinality can't be well estimated, the optimizer changes plans on you, and you want to know if a profile will help or hurt.

  The good news I had the perfect test case.  The query was part of a data load, and there was a driving table with a varying number of rows in it.  This is how I went about analyzing.

First I created a table to store the results.

create table bgrenn.mytable
 (ROW_COUNT                                          NUMBER,
 PLAN_HASH_VALUE                                    VARCHAR2(15)
 COST                                               number);

Next I took a copy of my driving table ( a full size table). I used this to create a smaller copy of the table.

declare


row_count number:= 0;
v_statement_id varchar2(10);
v_plan_hash_value varchar2(15);
v_cost number;
v_statement varchar2(4000);

begin

for row_count in 0..100000  loop


execute immediate 'drop table BGRENN.TMP_DRIVER purge';
execute immediate 'create table   BGRENN.TMP_DRIVERT as select * from  BGRENN.TMP_DRIVERB where rownum<' ||  to_char(row_count,'9999999');

dbms_stats.gather_table_stats('BGRENN','TMP_DRIVERT');

v_statement_id := to_char(row_count,'99999');

v_statement := 'explain plan SET STATEMENT_ID = ''' || v_statement_id || '''  for ' ||
'select   * ' ||
' from BGRENN.TMP_DRIVERT TMP_DRIVERA  ' ||
' INNER JOIN BGRENN.TABA TABA ON TMP_DRIVERA.ID=TABA.ID  ' ||
' INNER JOIN BGRENN.TABB ON TABA.GCC_ID=TABA.ID AND TABA.LOCN <> 8031431  ' ||
' INNER JOIN BGRENN.TABC TABC ON TABA.ID=TABC.ID AND TABC.id = 1168583  ' ||
' INNER JOIN BGRENN.TABD TABD ON TABA.ID=TABD.ID  ' ||
' INNER JOIN BGRENN.TABE TABE ON TABD.ID=TABE.ID  ' ||
' INNER JOIN BGRENN.TABF TABF ON TABD.ID=TABF.ID  ' ||
' INNER JOIN BGRENN.TABG TABG ON TABF.ID=TABG.ID  ' ||
' INNER JOIN BGRENN.TABH TABH ON TABG.ID=TABH.ID AND TABH.SEQ_NBR < 500  ' ||
' INNER JOIN BGRENN.TABI ON TABC.ID=ID  ' ||
' INNER JOIN BGRENN.TABJ TABJ ON TABC.ID=TABJ.ID  ' ||
' INNER JOIN BGRENN.TABK TABK ON TABJ.ID=TABK.ID and TABK.id in ( 1221589, 1219009, 1191882, 1221590, 1171956)  ' ||
' LEFT OUTER JOIN ERD.TABL TABL ON TABH.ID=TABL.ID  ' ||
' LEFT OUTER JOIN ERD.TABM TABM ON TABE.ID=TABM.ID  ' ||
' where (1=1)';

dbms_output.put_line(v_statement);

execute immediate v_statement;



SELECT substr(plan_table_output,18,12) into v_plan_hash_value  FROM TABLE(dbms_xplan.display(statement_id => v_statement_id)) where rownum <2;
select cost into v_cost from plan_table where id=0 and rownum<2 and statement_id=v_statement_id;

insert into bgrenn.mytable values(row_count,v_plan_hash_value,v_cost);

delete from plan_table where statement_id=v_statement_id;
commit;
end loop;

end;
/                                            number);

This produced a set of rows in the table with the cost.

I then copied the table, installed a profile and reran.

After joining the 2 tables on row count I created an "r" program and analyzed the results.
Here is the program.

# open Libarary psych for functions
library(psych)

#  open file
query_data <- read.table("c:/r/data/query_output.txt", header=T)

#what are the variables
describe (query_data)


pdf("c:/r/data/querydata.pdf")
plot(query_data$ROW_COUNT,query_data$orig_cost,type='l',col="red")
lines(query_data$ROW_COUNT,query_data$new_cost,type='l',col="green")
dev.off()

And here is the output ..  The red is the orginal plan, and the green is the plan with the profile. I can see that the cost of the profile plan remains more consistent. and is probably a better choice.

"enq: CR - block range reuse ckpt" and the recycle bin

I decided to write this blog entry because we ran into an issue over the weekend.  The process that normally runs fine, was running slow.. "like molasses" was the comment from one of the folks.  After digging into an AWR report I found one of the top waits for the sql was


enq: CR - block range reuse ckpt

OK.. what is that, and why ?   I didn't find a whole lot except that it indiciated contention on blocks from multiple processes trying to update blocks.. hmmm..

I looked further in the AWR and saw the top Segment for Logical reads was "RECYCLEBIN$"

and one of the top queries was.

"delete from RecycleBin$ where bo=:1"


Well since the process was finished I did my own test.. I created a tablespace and created an object in it.. dropped the object, added the to table, then dropped the table.. over and over again, until the number of objects in  the tablespace remained constant.  I then created the table again, and started to let it grow (so it would have to free up the recycle bin to get space)... And what I saw in the top 5 wait events was again.....

enq: CR - block range reuse ckpt

I wanted to document this for others that may hit this.. If a search for this wait event brought you to my blog, Please check your recycle bin and make sure that it isn't cleaning itself out to make room causing this wait event ...

Recognize the magic optimizer numbers

Well I figured I document some of the magic numbers that the optimizer uses to help remember them, and help others. The back ground of this is simple.

I was looking through a query that was running for a long, long time, and the cardinality looked wrong.  I know the developers were using a table operation (looping over a LOB that was treated like  table). 

The Cardinality estimate for the step was 8168, and I thought hmmmm I've seen that before when dynamic sampling didn't happen.  Well after some digging I came across this page. Cardinality

The page contained this handy chart below...  These are important numbers to remember because when you see a cardinality matching this chart it is probably because the optimizer couldn't estimate the correct cardinality, and it couldn't dynamically sample.  Below is a snippet from the query I was investigating. Notice the cardinality on the first line.

0  0  0   COLLECTION ITERATOR PICKLER FETCH PARSE_DYNAMIC_COLS 

                    (cr=0 pr=0 pw=0 time=0 us cost=29 size=16336 card=8168)
0  0  0 HASH JOIN RIGHT OUTER (cr=0 pr=0 pw=0 time=0 us cost=8757 size=233200 card=100)
0  0  0  VIEW  (cr=0 pr=0 pw=0 time=0 us cost=8614 size=14 card=1)
0  0  0   HASH UNIQUE (cr=0 pr=0 pw=0 time=0 us cost=8614 size=2069 card=1)
0  0  0    FILTER  (cr=0 pr=0 pw=0 time=0 us)
0  0  0      NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us)
0  0  0      NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=8613 size=2069 card=1)
0  0  0       HASH JOIN  (cr=0 pr=0 pw=0 time=0 us cost=8612 size=2044 card=1)

Default cardinality for database objects

The following table demonstrates the estimated cardinalities (using a 8K blocksize) of various objects which have had no statistics generated for them :

Object Type	Estimated Cardinality
Heap Table	82
Global Temporary Table	8168
Index-Organized Table	1
System Generated Materialized View (such as the output of the TABLE operator)	8168

Exadata sizing updated for 3tb drives 1/2 rack SATA

OK, Now I new Exadata coming in that has 3tb drives, and the first question asked is .. How much disk to I have to configure on it ?  Well I'm going to expand on a previous entry I did on sizing .

1/2 Rack. Sata drives. normal redundancy

This means we have

• 7 storage cells
• Each storage cell contains 12 disks
• each disk is 3tb (which is about 2.794 tb usable)  *** This is calculated using base 1024 
• The first 2 disks in each storage cell has 29.103g already partitioned for the OS (which is mirrored).
• The rest of the disks in the group are used for DBFS

Given this, I am going to calculate out the total disk available then subtract out the 29.103g (for OS and DBFS).

First 12 disks * 7 cells x 2.794 = 234.696 tb of total raw storage/
Subtract out 29g* 2 disks * 7 cells = 406g    ----- OS
Subtract out 29g * 10 disks * 7 cells = 2.03tb  -----   DBFS
Available raw is 234.696 - 2.436 = 232.26  

Now I said we were running Normal Redundancy.. This means that we loose 1/2

DBFS = 1.015tb
OS        29g
Remaining for Data and Reco = 116.13

But of course we need to account for cell being off line.  This takes out 1/7 of the storage.

DBFS   === .870 tb (29g * 10 * 6)/2
Everything else  ===  ( 2.765 * 12 disks * 6 cells)/2   == 99.54

So now we have 99.54 raw storage available for Data and Reco.

This is now easy to figure out now.. You have really 100tb raw storage (with normal redundancy) to split up between Data and Reco.

Now a full rack is easy to do.

2.765 * 12 disks * 13 cells) / 2 =  215.67tb 

What extended stats do I have on my database?

I've been starting to work with Extended statistics to help the optimizer find the best plan. This is a great feature that is outlined by @sqlmaria (Maria Coogan) here.

But once you create extended statistics, how do you know what is there ?  I wrote this query to find out what function based indexes, what extended statistics, and what their definition are. 

Here is my script.

column table_owner alias "owner" format a15
column table_name alias  "Table Name" format  a30
column function_index alias  "F Index" format  a8
column Index_name  alias  "Index Name"  format a30
column data_default alias  "Definition"  format a50
set pagesize 1000
select table_owner,
         table_name,
        nvl2(index_name,'YES','NO') function_index,
        index_name,
        data_default
        from
        (
select owner table_owner,table_name,
(select distinct index_name from dba_ind_columns b where a.column_name=b.column_name and a.owner=b.index_owner and a.table_name=b.table_name) index_name
,data_default
-- ,     DBMS_LOB.SUBSTR( to_lob(data_default),100,1)
 from dba_tab_cols a
  where virtual_column='YES' and hidden_column='YES'  and (owner not in ('SYS','WMSYS','XDB','SYSMAN','MDSYS','EXFSYS','PR_MDS') and owner not like 'APEX_%')
  )
order by table_owner,table_name;

and this is what the output looks like..

TABLE_OWNER     TABLE_NAME                     FUNCTION INDEX_NAME                     DATA_DEFINITION
--------------- ------------------------------ -------- ------------------------------ --------------------------------------------------
BGRENN          TAB_SCHR_PERD                      NO                                  COALESCE("COL1","COL2")
BGRENN          TAB2                              YES   IDX_TAB2                       "COL1"||' '||"COL2"
BGRENN          TAB3                               NO                                  COALESCE("COL1","COL2")
BGRENN          TAB4                              YES   IDX_TAB4                       COALESCE("COL1","COL2",0)
BGRENN          TAB4                              YES   IDX_TAB4                       COALESCE("COL3",0)
BGRENN          TAB5                              YES   IDX_TAB5                       COALESCE("COL1","COL2",0)
BGRENN          TAB6                              YES   IDX_TAB6                       NVL("COL1",(-1))
BGRENN          TAB6                              YES   IDX_TAB6                       NVL("COL2",(-1))
BGRENN          TAB6                              YES   IDX_TAB6                       NVL("COL3",(-1))
BGRENN          TAB6                              YES   IDX_TAB6                       NVL("COL4",'x')
BGRENN          TAB7                              YES   IDX_COMPOSITE                  "COL1"
BGRENN          TAB7                              YES   IDX_COMPOSITE                  "COL3"

Notice the Function colunmn. This is a "YES" or "NO" depending on if this is a function based index, or just extended statistics.

This should help tell where your extended statistics are in your database.

Exadata tips

I wanted to write up an Exadata tip that I learned.

Background :  I wanted to do a simple "select count(1) from mytable".  mytable has a primary key on it.  The count seemed to be taking a long time for an Exadata.

First the "select count(1) from mytable". You can see that it uses an index storage fast full scan.  The top wait event is "cell multiblock physical read".  The query does  2 Million Disk reads in 3 Minutes 28 seconds.

But this seems slow...

select count(1)
from
     MYTABLE MYTABLE

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2     56.46     208.27    2030378    2031797         20           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4     56.46     208.27    2030378    2031797         20           1

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

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  SORT AGGREGATE (cr=2031797 pr=2030378 pw=0 time=208276577 us)
 592848893  592848893  592848893   INDEX STORAGE FAST FULL SCAN PK_MYTABLE (cr=2031797 pr=2030378 pw=0 time=245927651 us cost=523897 size=0 card=572441788)(object id 312310)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  library cache lock                              4        0.00          0.00
  Disk file operations I/O                       42        0.00          0.00
  library cache pin                               2        0.00          0.00
  SQL*Net message to client                       2        0.00          0.00
  cell single block physical read                15        0.00          0.00
  cell list of blocks physical read               2        0.00          0.00
  cell multiblock physical read               15959        0.26        152.20
  latch: object queue header operation            1        0.00          0.00
  SQL*Net message from client                     2       10.38         10.38
********************************************************************************

Next I did a FTS.

"select /*+full(MYTABLE) */ count(1) from  MYTABLE MYTABLE ;

You can see this did 2.2 Million disk reads (more than the index scan), but the wait event is sql_net. With the "cell smart table scan", there were very few waits, and the wait was much shorter.

select /*+full(MYTABLE) */ count(1)
from
     MYTABLE MYTABLE  

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2     65.11      66.48    2224642    2225028         21           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4     65.11      66.48    2224642    2225028         21           1

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

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  SORT AGGREGATE (cr=2225028 pr=2224642 pw=0 time=66486729 us)
 592848893  592848893  592848893   PARTITION RANGE ALL PARTITION: 1 33 (cr=2225028 pr=2224642 pw=0 time=140325566 us cost=533066 size=0 card=572441788)
 592848893  592848893  592848893    TABLE ACCESS STORAGE FULL MYTABLE PARTITION: 1 33 (cr=2225028 pr=2224642 pw=0 time=54479242 us cost=533066 size=0 card=572441788)


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                      129        0.00          0.00
  gc current block 2-way                         65        0.00          0.00
  enq: KO - fast object checkpoint              101        0.00          0.02
  reliable message                               33        0.09          0.30
  gc current block 3-way                         13        0.00          0.00
  cell smart table scan                        1403        0.03          1.01
  gc cr block 3-way                               1        0.00          0.00
  gc current grant busy                          18        0.00          0.00
  gc cr block 2-way                              17        0.00          0.00
  gc cr multi block request                       5        0.00          0.00
  cell single block physical read                11        0.00          0.00
  cell list of blocks physical read               2        0.00          0.00
  gc cr grant 2-way                               3        0.00          0.00
  SQL*Net message from client                     2        9.62          9.62

Bottom line, if you want to a count on a table use the "FULL" hint.  The exadata is built for table scans, and this example shows that.

It also should make you rethink when to use indexes for an application, you see they can hurt you in some cases.

What happened to my sql (sql_id) ?

While finishing up a few things, I ran across a query that wasn't playing nicely. It had 4 different plans over the course of the last couple of days, and I wanted to see what happend.. I came up with the nifty query below.  If you plug in a sql_id, it will go through the AWR history, and return (ordered by date last executed), the plans grouped by plan_hash_value. Within each plan_hash_value it will give you the objects in the plan, and when they were last analyzed.  By using this you should see what plans are good, when they were last executed, and if anything was analyzed to change the plan.

set linesize 160
set pagesize 1000
break on plan_hash_value skip 1 nodup  on last_executed skip 1 nodup  on avg_exec_time skip 1
select object_owner ||'.'|| object_name object_name,
object_type,
a.plan_hash_value,
case object_type
  when 'INDEX' then (select last_analyzed from dba_indexes b where owner=object_owner and index_name=object_name)
  when 'TABLE'  then (select last_analyzed from dba_tables b where owner=object_owner and table_name=object_name)
 else null 
end last_analyzed,
 to_char((select max(end_interval_time) from dba_hist_snapshot b,
                                           dba_hist_sqlstat c 
                            where c.sql_id=a.sql_id and 
                                  c.plan_hash_value=a.plan_hash_value and 
                              b.snap_id=c.snap_id),'mm/dd/yy hh24:mi') last_Executed,
to_char((select sum(elapsed_time_delta)/sum(executions_delta) from dba_hist_sqlstat d where d.sql_id=a.sql_id and d.plan_hash_value=a.plan_hash_value)/1024/1024,'999.99') avg_exec_time
 from DBA_HIST_SQL_PLAN  a
where a.SQL_ID='gbug7dg8adhgh'
 and object_type in ('INDEX','TABLE')
order by last_executed desc ,a.plan_hash_value , last_analyzed desc;

Here is an example of the output

              OBJECT_NAME                                 OBJECT_TYPE          PLAN_HASH_VALUE LAST_ANALYZED       LAST_EXECUTED  AVG_EXE
-------------------------------------------------------------- -------------------- --------------- ------------------- -------------- -------
MY_SCHEMA.SNP_CDC_SUBS                                     TABLE                     2518369181 2012-07-06 09:25:15 07/06/12 10:00  791.37
MY_SCHEMA.SNP_CDC_SUBS                                     TABLE                                2012-07-06 09:25:15
MY_SCHEMA.D$TAB_REG                                        TABLE                                2012-07-06 09:25:06
MY_SCHEMA.J$TAB_REG                                        TABLE                                2012-07-06 09:24:50
MY_SCHEMA.J$TAB_REG                                        TABLE                                2012-07-06 09:24:50
MY_SCHEMA.J$TAB_REG                                        TABLE                                2012-07-06 09:24:50
MY_SCHEMA.J$TAB_REG                                        TABLE                                2012-07-06 09:24:50
ERD.DIM_TABS_COMP_PLCY_AGMT                                TABLE                                2012-07-06 00:39:33
MY_SCHEMA.TAB_COMP_PLCY_AGMT                               TABLE                                2012-05-25 09:20:39
MY_SCHEMA.IDX_WCPA_AGMT_ID                                 INDEX                                2012-05-25 09:20:39
MY_SCHEMA.TAB_COMP_PLCY_ST_CLSF_VT                         TABLE                                2012-05-15 18:49:43
MY_SCHEMA.TAB_COMP_PLCY_ST_CLSF                            TABLE                                2012-05-15 18:49:43
MY_SCHEMA.WPTD_COMP_PER_TAX                                TABLE                                2012-05-15 18:39:30
MY_SCHEMA.TAB_REG                                          TABLE                                2012-05-15 18:31:18
MY_SCHEMA.CO_TAB                                           TABLE                                2012-05-15 18:27:50
MY_SCHEMA.TAB_PAYR                                         TABLE                                2012-05-15 18:26:47
MY_SCHEMA.AGMT_REG                                         TABLE                                2012-05-15 18:21:09



MY_SCHEMA.SNP_CDC_SUBS                                     TABLE                     1903861587 2012-07-06 09:25:15 07/06/12 09:00  882.94
MY_SCHEMA.SNP_CDC_SUBS                                     TABLE                                2012-07-06 09:25:15
MY_SCHEMA.D$TAB_REG                                        TABLE                                2012-07-06 09:25:06
MY_SCHEMA.J$TAB_REG                                        TABLE                                2012-07-06 09:24:50
MY_SCHEMA.J$TAB_REG                                        TABLE                                2012-07-06 09:24:50
MY_SCHEMA.J$TAB_REG                                        TABLE                                2012-07-06 09:24:50
MY_SCHEMA.J$TAB_REG                                        TABLE                                2012-07-06 09:24:50
ERD.DIM_TABS_COMP_PLCY_AGMT                                TABLE                                2012-07-06 00:39:33
MY_SCHEMA.TAB_COMP_PLCY_AGMT                               TABLE                                2012-05-25 09:20:39
MY_SCHEMA.IDX_WCPA_AGMT_ID                                 INDEX                                2012-05-25 09:20:39
MY_SCHEMA.TAB_COMP_PLCY_ST_CLSF_VT                         TABLE                                2012-05-15 18:49:43
MY_SCHEMA.TAB_COMP_PLCY_ST_CLSF                            TABLE                                2012-05-15 18:49:43
MY_SCHEMA.WPTD_COMP_PER_TAX                                TABLE                                2012-05-15 18:39:30
MY_SCHEMA.TAB_REG                                          TABLE                                2012-05-15 18:31:18
MY_SCHEMA.CO_TAB                                           TABLE                                2012-05-15 18:27:50
MY_SCHEMA.TAB_PAYR                                         TABLE                                2012-05-15 18:26:47
MY_SCHEMA.AGMT_REG                                         TABLE                                2012-05-15 18:21:09

AWR compare report

I came across this while doing some dbreplays, and found it very useful.

First, lets say you have a RAC cluster,  and you want to do some performance comparisons .. What's one of the issues you run into ?  For me it is trying to figure out which nodes I care about, and running the AWR report for that node. This is exasperated with a Full Rack Exadata.  8 nodes to compare.  Well this is what I use to compare 2 time periods across all nodes.  I also increase some of the reporting thresholds..

First the script to gather the report. (here)

To get this to work change the following

dbid  - dbid for the first time period
begin_snap - begin snap first time period
end_snap - end snap first time period

dbid2 - dbid for the second time period
begin_snap2 - begin snap second time period
end_snap2 - end snap second time period

Also notice that I changed top_n_** values to give me more data

Rem    NAME
Rem      awr_full.sql - Workload Repository Global Compare Periods Report
Rem
Rem    DESCRIPTION
Rem      RAC Version of Compare Period Report
Rem
Rem
Rem    NOTES
Rem      Run as SYSDBA.  Generally this script should be invoked by awrgdrpt,
Rem      unless you want to pick a database and/or specific instances
Rem      other than the default.
Rem
Rem      If you want to use this script in an non-interactive fashion,
Rem      without executing the script through awrgdrpt, then
Rem      do something similar to the following:
Rem
      define  num_days     = 0;
      define  dbid         =2415508472; 
      define  instance_numbers_or_ALL    = 'ALL';
      define  begin_snap   = 35727;
      define  end_snap     = 35728;
      define  num_days2    = 0;
      define  dbid2        = 2415508472;
      define  instance_numbers_or_ALL2    = 'ALL';
      define  begin_snap2  = 35728;
      define  end_snap2    = 35729; 
      define  report_type  = 'html';
      define  report_name  = /tmp/awr_report.html
      define top_n_files        = 50;
      define top_n_segments     = 50;
      define top_n_services     = 50;
      define top_n_sql          = 100;
      @@?/rdbms/admin/awrgdrpi
!./mail_full.sql
exit

The second to last line of the script is to mail the report, and the script is here.

echo "From: replay_report@oracle.com"  > /tmp/mailfilebsg
echo "To: raddba@oracle.com"   >> /tmp/mailfilebsg
echo "Subject: DBREPLAY output "   >> /tmp/mailfilebsg
echo "Mime-Version: 1.0"      >> /tmp/mailfilebsg
echo 'Content-Type: multipart/mixed; boundary="DMW.Boundary.605592468"'   >> /tmp/mailfilebsg
echo "--DMW.Boundary.605592468" >> /tmp/mailfilebsg
echo " " >> /tmp/mailfilebsg
echo " dbreplay output " >> /tmp/mailfilebsg
echo " " >> /tmp/mailfilebsg
echo "--DMW.Boundary.605592468" >> /tmp/mailfilebsg
echo 'Content-Disposition: inline; filename="dbreplay.html"' >> /tmp/mailfilebsg
echo "Content-Transfer-Encoding: 7bit" >> /tmp/mailfilebsg
cat /tmp/awr_report.html >> /tmp/mailfilebsg
echo "--DMW.Boundary.605592468" >> /tmp/mailfilebsg
/usr/sbin/sendmail bryan..grenn@oracle.com < /tmp/mailfilebsg

The second script will mail you the output as an attachement.  So when using it, be sure to make the E-mail address yours, and change the subject, and filename to be what you want.

Enjoy. 

Taking a career change

Well, I have decided to make a change and take a job with oracle.  I am very excited about this move, and I look forward to being more involved in big data.  As any of you know (who have read my blog posts), I have taken a strong interest in this area.  I know I'm not the only one.  You probably have heard the terms  "Data Scientist"...   Hadoop...  R..  These are all the areas that I'm going to be delving into in my new position.
  I will continue to blog, probably mostly about the same topics I blog about now.  I am looking forward to this change, and becoming part of this evolution.  Many people are saying that Big Data is the next big change (like the internet),  whether this is true or not, we shall see. 

Problem debugging for DBFS

In trying to find out the cause of a DBFS issue, I learned what is expected (or helpful) when working with Support on DBFS issues.

1)  Logon trigger for dbfs user to create a trace file..

CREATE OR REPLACE TRIGGER DBFS_LOGON
AFTER LOGON
ON DATABASE
declare
username VARCHAR2(30);
BEGIN
  username:=SYS_CONTEXT('USERENV','SESSION_USER');
  IF username like 'FOO' then
    dbms_dbfs_content.setTrace(3);
    execute immediate 'alter session set events ''45050 trace name context forever, level 0xfffff'' ';
  END IF;
EXCEPTION
   WHEN OTHERS THEN
      NULL;
END;
/ 

2) Start the DBFS client with tracing turned on.  (-otrace_file=,trace_level=2,trace_size=0). (see How to trace DBFS when any failure happens [ID 1320683.1])

Remember if you are running DBFS, you are probably on a multi-node clustered environment, so you only need to do these steps on one of the nodes to gather the data.  I turned the logon trigger on, remounted the FS with tracing..  reproduced issue. Verified the log files were created, disabled trigger, remounted without tracing..  I did this on only one node, and gathered what I needed with minimal issues.

Where is my space on DBFS

I just ran into an issue on DBFS where I ran out of space.

First here is the df -k

Filesystem           1K-blocks      Used Available Use% Mounted on
dbfs-dbfs_admin2@:/   20983808  11443696   9540112  55% /dbfs/dba

OK, everything looks good.. I am using 11g and I have 9.5g available.

I go to copy a file on the os (you can see it is 240m).  Lots of room

 ls -al bsg.out
-rw-r--r-- 1 oracle oinstall 240794862 May 18 11:37 bsg.out

cp bsg.out bsg.out1
cp: writing `bsg.out1': No space left on device
cp: closing `bsg.out1': No space left on device

So where is my space.  ?? I find this query..

set serveroutput on;
declare
v_segment_size_blocks number;
v_segment_size_bytes number;
v_ number;
v_used_blocks number;
v_used_bytes number;
v_expired_blocks number;
v_expired_bytes number;
v_unexpired_blocks number;
v_unexpired_bytes number;
begin
dbms_space.space_usage ('DBFS_OWNER', 'LOB_SFS$_FST_12345', 'LOB', 
v_segment_size_blocks, v_segment_size_bytes,
v_used_blocks, v_used_bytes, v_expired_blocks, v_expired_bytes, 
v_unexpired_blocks, v_unexpired_bytes );
dbms_output.put_line('Segment Size blocks = '||v_segment_size_blocks);
dbms_output.put_line('Segment Size bytes = '||v_segment_size_bytes);
dbms_output.put_line('Used blocks = '||v_used_blocks);
dbms_output.put_line('Used bytes = '||v_used_bytes);
dbms_output.put_line('Expired Blocks = '||v_expired_blocks);
dbms_output.put_line('Expired Bytes = '||v_expired_bytes);
dbms_output.put_line('UNExpired Blocks = '||v_unexpired_blocks);
dbms_output.put_line('UNExpired Bytes = '||v_unexpired_bytes);
end;
/

And I see this output

Segment Size blocks = 2619024
Segment Size bytes = 21455044608
Used blocks = 1425916
Used bytes = 11681103872
Expired Blocks = 1190111
Expired Bytes = 9749389312
UNExpired Blocks = 0
UNExpired Bytes = 0

So.. according to this.. The segment is 21.4 g

11.7g is used space
  9.7g is Expired space
   0g   is unexpired space.

So if I have 9.7g of Expired space why can't I use it ??  My file is only 244m, and I should have 9.7 g available.

So my questions out of this are (if anyone knows the answer).

1) How does this happen and how do I avoid it ?

2) How do I size tablespaces for DBFS ?  They need more space to be available then I need for the file system.

3) How do I monitor the sizing since the DF -k does not report unexpired bytes that are available to be used ?

4) How does the clause "retention" fit into this ?  retention defaults to "auto" rather than "none".  Can I set it to "none", but what happens and does this solve my problem ?


Oh, and I wanted to make sure that I included the ouput of  whats in the tablespace.

SEGMENT_NAME                                             SEGMENT_TYPE       SEGMENT_SIZE
-------------------------------------------------------- ------------------ ------------
LOB_SFS$_FST_12345                                       LOBSEGMENT                20461
T_ADMIN                                                  TABLE                        17
IP_SFS$_FST_12345                                        INDEX                         4
IPG_SFS$_FST_12345                                       INDEX                         3
IG_SFS$_FST_12345                                        INDEX                         2
SYS_IL0000095835C00007$$                                 LOBINDEX                      0

UPDATE (6/13/12)  --

After working with support on this, it was filed as a bug.  This occured because I was using DBFS as a filesytem for my dbreplay capture.  After thinking about it the dbcapture is probably the most intensive workload I could throw at DBFS.  Not only does it simultaneously write to multiple files, but it writes to those files across multiple nodes.  In my capture there were 4 nodes writing to 100's of files at the same time.
   I will be testing the patch, and see if it corrects the problem.  Support is telling me that the writing across multiple nodes is causing some of the issues..

Analytical functions

I have been working on a query that is uses an analytical function..
I’m not familiar with them, but using my usual query tuning got me into some trouble..

This is the query.

WITH
SACOMMON71991 AS (select T17189.SUR_REF_TIME_PERD_ID as SUR_REF_TIME_PERD_ID,
    T17189.RTP_CAL_DT as c4,
    T17189.RTP_CAL_YR as c5,
    ROW_NUMBER() OVER (PARTITION BY T17189.RTP_CAL_YR ORDER BY
T17189.RTP_CAL_YR DESC) as c6,
    ROW_NUMBER() OVER (PARTITION BY T17189.RTP_CAL_YR,
T17189.SUR_REF_TIME_PERD_ID ORDER BY T17189.RTP_CAL_YR DESC,
T17189.SUR_REF_TIME_PERD_ID DESC) as c7
from
    REF_TIME_PERD T17189 /* Dim_TIME_PERD_D_Check_Date */ )
select * from SACOMMON71991 where SUR_REF_TIME_PERD_ID=20240213

The data in the table looks like this.

SUR_REF_TIME_PERD_ID    varchar(8)
RPT_CAL_DT                      date
RPT_CAL_YR                      varchar(4)

Some example values are.

SUR_REF_TIME_PERD_ID            RPT_CAL_DT              RPT_CAL_YR
19000101                                         01/01/1900                    1900
…
20120101                                         01/01/2012                    2012
-..
--
20120125                                          01/25/2012                    2012
..
20120430                                          04/30/2012                    2012
..
20240213                                          02/13/2024                    2024
..
47121231                                           12/31/4712                   4712


Now back to my query..

WITH
SACOMMON71991 AS (select T17189.SUR_REF_TIME_PERD_ID as SUR_REF_TIME_PERD_ID,
    T17189.RTP_CAL_DT as c4,
    T17189.RTP_CAL_YR as c5,
    ROW_NUMBER() OVER (PARTITION BY T17189.RTP_CAL_YR ORDER BY T17189.RTP_CAL_YR DESC) as c6,
    ROW_NUMBER() OVER (PARTITION BY T17189.RTP_CAL_YR,T17189.SUR_REF_TIME_PERD_ID ORDER BY T17189.RTP_CAL_YR DESC,T17189.SUR_REF_TIME_PERD_ID DESC) as c7
from
    REF_TIME_PERD T17189 /* Dim_TIME_PERD_D_Check_Date */ )
select * from SACOMMON71991 where SUR_REF_TIME_PERD_ID=20240213

I noticed that the query did a full table scan of 219,000 rows.

  I figured, well I only wanted 1 row, so why can’t I just change the
query ??

select T17189.SUR_REF_TIME_PERD_ID as SUR_REF_TIME_PERD_ID,
     T17189.RTP_CAL_DT as c4,
     T17189.RTP_CAL_YR as c5,
     ROW_NUMBER() OVER (PARTITION BY T17189.RTP_CAL_YR ORDER BY T17189.RTP_CAL_YR DESC) as c6,
     ROW_NUMBER() OVER (PARTITION BY T17189.RTP_CAL_YR, T17189.SUR_REF_TIME_PERD_ID ORDER BY T17189.RTP_CAL_YR DESC, T17189.SUR_REF_TIME_PERD_ID DESC) as c7
from 
     V_REF_TIME_PERD T17189  where SUR_REF_TIME_PERD_ID=20240213

My plan looks much better

But the answer is different ??

The first query returns.

SUR_REF_TIME_PERD_ID C4                            C5         C6         C7
-------------------- --------------------- ---------- ---------- ----------
            20240213 2024-02-13 00:00:00         2024         44          1

The second query returns

SUR_REF_TIME_PERD_ID C4                            C5         C6         C7
-------------------- --------------------- ---------- ---------- ----------
            20240213 2024-02-13 00:00:00         2024          1          1

So what exactly is the query doing ???

The query is actually analyzing more data than just my row.  After examining the query, I noticed the 4th column (C6) is actually the day of the year.  2/13 is the 44th day of the year.

So what exactly is the query doing to get this ???

It is starting with all rows in the table, then sorting them by RPT_CAL_YR, and SUR_REF_TIME_PERD_ID.  This is column c7 in table.. If we look back we see this column is

ROW_NUMBER() OVER (PARTITION BY T17189.RTP_CAL_YR, T17189.SUR_REF_TIME_PERD_ID ORDER BY T17189.RTP_CAL_YR DESC, T17189.SUR_REF_TIME_PERD_ID DESC) as c7

This column does the sorting to get the result.. Now if you look at C6, you see that it is a row_number over just the 1 column RPT_CAL_YR.  Since the rows are now sorted in data order (thanks to c7), C6 is just  the row number for the value passed to the query..

I know it gets kind of complicated.. The lesson learned from this, is that analytical functions sometimes need to do FTS to do their work.  By giving it the key value within the select, I removed the queries ability to look at the full tables data.

I also learned that by properly limiting the values in the right spot, you can eliminate rows.  Here is a better query. I am limiting the analytical function to just look at the current year.

   WITH
SACOMMON71991 AS (select T17189.SUR_REF_TIME_PERD_ID as SUR_REF_TIME_PERD_ID,
    T17189.RTP_CAL_DT as c4,
    T17189.RTP_CAL_YR as c5,
    ROW_NUMBER() OVER (PARTITION BY T17189.RTP_CAL_YR ORDER BY
T17189.RTP_CAL_YR DESC) as c6,
    ROW_NUMBER() OVER (PARTITION BY T17189.RTP_CAL_YR,
T17189.SUR_REF_TIME_PERD_ID ORDER BY T17189.RTP_CAL_YR DESC,
T17189.SUR_REF_TIME_PERD_ID DESC) as c7
from
    REF_TIME_PERD T17189 /* Dim_TIME_PERD_D_Check_Date */ 
    where RTP_CAL_YR='2024')
select * from SACOMMON71991 where SUR_REF_TIME_PERD_ID=20240213

The plan is going through less data, but the appropriate data to get the right answer.

Hyperthreading with Oracle (update)

After my first post on hyperthreading, and all the hits I've been getting I've decided to update it..

My first post was pased on testing with a DL980.. This is an 8 socket server with   X7560  @ 2.27GHz processes.

My currently updated post is on a new 2 socket server with the E7- 2870 @ 2.40GHz chipset.

The servers I tested on were

2 Socket
10 Core (dual threaded)
11.2.0.3 Oracle
Linux RHEL  2.6.18-274.17.1.el5
132g of ram.


I tested by using Kevin Clossons SLOB test which can be found here.

I tested using multiple process settings, and you see how these  servers scaled up with the processes.

I warmed up with 15 processes.  Looking at the LIO count, we are doing 7.2 million. output

Load Profile              Per Second    Per Transaction   Per Exec   Per Call
~~~~~~~~~~~~         ---------------    --------------- ---------- ----------
      DB Time(s):               14.4               24.9       0.00       4.60
       DB CPU(s):               14.3               24.7       0.00       4.56
       Redo size:           13,974.5           24,137.1
   Logical reads:        7,259,470.5       12,538,708.3
   Block changes:               32.9               56.8
  Physical reads:               69.9              120.8
 Physical writes:               15.8               27.2
      User calls:                3.1                5.4
          Parses:                3.8                6.6
     Hard parses:                0.0                0.0
W/A MB processed:                0.4                0.7
          Logons:                0.1                0.2
        Executes:           28,206.8           48,719.3
       Rollbacks:                0.0                0.0
    Transactions:                0.6

Then 20 processes.  8.7 million still looking good.  output

Load Profile              Per Second    Per Transaction   Per Exec   Per Call
~~~~~~~~~~~~         ---------------    --------------- ---------- ----------
      DB Time(s):               18.9              127.0       0.00      10.83
       DB CPU(s):               18.9              126.8       0.00      10.82
       Redo size:           15,073.6          101,207.6
   Logical reads:        8,714,693.4       58,512,431.8
   Block changes:               39.2              263.4
  Physical reads:                2.1               13.9
 Physical writes:               13.0               87.0
      User calls:                1.8               11.7
          Parses:                3.8               25.6
     Hard parses:                0.0                0.1
W/A MB processed:                0.4                2.5
          Logons:                0.1                0.4
        Executes:           33,859.7          227,341.5
       Rollbacks:                0.0                0.0
    Transactions:                0.2

Now lets try 25.. see how we go past the number of cores .  9.4 million.. Hyperthreading is scaling nicely. output

Load Profile              Per Second    Per Transaction   Per Exec   Per Call
~~~~~~~~~~~~         ---------------    --------------- ---------- ----------
      DB Time(s):               23.1               91.7       0.00       9.26
       DB CPU(s):               23.0               91.6       0.00       9.24
       Redo size:           21,634.2           86,063.7
   Logical reads:        9,406,658.2       37,420,998.8
   Block changes:               68.2              271.4
  Physical reads:                3.7               14.8
 Physical writes:                5.7               22.5
      User calls:                2.5                9.9
          Parses:                3.3               13.3
     Hard parses:                0.1                0.3
W/A MB processed:                0.4                1.6
          Logons:                0.1                0.5
        Executes:           36,544.7          145,380.0
       Rollbacks:                0.0                0.0
    Transactions:                0.3

Next 35.. Still scaling... output

Load Profile              Per Second    Per Transaction   Per Exec   Per Call
~~~~~~~~~~~~         ---------------    --------------- ---------- ----------
      DB Time(s):               33.5              310.9       0.00      18.74
       DB CPU(s):               33.5              310.3       0.00      18.70
       Redo size:            9,379.2           86,997.8
   Logical reads:       11,039,158.6      102,395,221.3
   Block changes:               17.7              164.4
  Physical reads:                1.3               12.0
 Physical writes:                4.0               36.9
      User calls:                1.8               16.6
          Parses:                2.0               18.9
     Hard parses:                0.1                1.0
W/A MB processed:                0.2                2.2
          Logons:                0.1                0.6
        Executes:           42,882.8          397,765.4
       Rollbacks:                0.0                0.0
    Transactions:                0.1

Finally the number of threads.  This appears to be the peak. output

Load Profile              Per Second    Per Transaction   Per Exec   Per Call
~~~~~~~~~~~~         ---------------    --------------- ---------- ----------
      DB Time(s):               38.3              387.0       0.00      17.48
       DB CPU(s):               37.6              380.4       0.00      17.18
       Redo size:            9,207.1           93,060.2
   Logical reads:       11,577,951.1      117,023,088.1
   Block changes:               16.4              166.1
  Physical reads:                1.1               11.5
 Physical writes:                4.5               45.1
      User calls:                2.2               22.1
          Parses:                2.0               19.9
     Hard parses:                0.1                0.6
W/A MB processed:                0.2                2.5
          Logons:                0.1                0.9
        Executes:           44,975.6          454,587.0
       Rollbacks:                0.0                0.0
    Transactions:                0.1

Now lets go up to 45 ...   things start dropping off.  output

oad Profile              Per Second    Per Transaction   Per Exec   Per Call
~~~~~~~~~~~~         ---------------    --------------- ---------- ----------
      DB Time(s):               40.7              482.9       0.00      16.78
       DB CPU(s):               36.0              427.5       0.00      14.86
       Redo size:            8,205.8           97,318.2
   Logical reads:       11,100,719.6      131,651,002.6
   Block changes:               14.0              165.9
  Physical reads:                0.9               10.3
 Physical writes:                3.2               38.3
      User calls:                2.4               28.8
          Parses:                2.3               27.5
     Hard parses:                0.1                0.6
W/A MB processed:                0.3                3.6
          Logons:                0.1                1.4
        Executes:           43,122.5          511,418.6
       Rollbacks:                0.0                0.0
    Transactions:                0.1

So if you look at the throughput..

20 processes    8,7 Million LIO's
40 Processes   11.6 Million LIO's

Not quite linaear progression, but things don't really top off until I get to the number of threads..  This scaled much better, and it seems that hyperthreading is helpgin push more workload through.

Analyzing the last query run

I don't know how many times I find myself trying to tune a query, and going through the same tasks.

I run the sql in my session (most likely on sqlplus on the unix server), but I then try to track down the sql_id, and finally (if I am lucky) find the SQL Monitor report (tuning pack license required).

So I came up with a script that I am putting on all my severs. post_execute.sql

This script can be executed in your shell as the next step after running the query in question.. but first.

If you want to use the SQL Monitor output, you are best adding the /*+monitor */ hint to your query just to be sure it is captured.

Well this is what the script does.

1) run your query.. I used this query for my example.

select /*+monitor */ a.owner,b.table_name ,sum(bytes) from dba_segments a,
                                     dba_tables b
where a.owner=b.owner and 
      a.segment_name=b.table_name 
group by a.owner,b.table_name
order by a.owner,b.table_name;

2) It captures the dbms_xplan.display_cursor output for the last run sql.. Here is snippet of what the output looked like..

Plan information for current query




SQL_ID  208ttrm2nbt0u, child number 0
-------------------------------------
select /*+monitor */ a.owner,b.table_name ,sum(bytes) from dba_segments 
a,                                      dba_tables b where 
a.owner=b.owner and       a.segment_name=b.table_name group by 
a.owner,b.table_name order by a.owner,b.table_name
 
Plan hash value: 1601540958
 
--------------------------------------------------------------------------------------------------------------
| Id  | Operation                                   | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                            |                |       |       | 14425 (100)|          |
|   1 |  SORT GROUP BY                              |                |     6 |  2184 | 14425   (1)| 00:02:54 |
|*  2 |   HASH JOIN OUTER                           |                |     6 |  2184 | 14424   (1)| 00:02:54 |
|   3 |    NESTED LOOPS OUTER                       |                |     6 |  2160 | 14422   (1)| 00:02:54 |
|   4 |     NESTED LOOPS OUTER                      |                |     6 |  2106 | 14410   (1)| 00:02:53 |
|   5 |      NESTED LOOPS OUTER                     |                |     6 |  2070 | 14408   (1)| 00:02:53 |
|   6 |       NESTED LOOPS                          |                |     6 |  1998 | 14396   (1)| 00:02:53 |
|   7 |        NESTED LOOPS                         |                |     6 |  1974 | 14390   (1)| 00:02:53 |
|*  8 |         HASH JOIN                           |                |    67 | 19899 | 14318   (1)| 00:02:52 |
|*  9 |          HASH JOIN                          |                |  5095 |  1298K| 13638   (1)| 00:02:44 |
|  10 |           MERGE JOIN CARTESIAN              |                |   131 | 11135 |     5  (20)| 00:00:01 |
|* 11 |            HASH JOIN                        |                |     1 |    68 |     1 (100)| 00:00:01 |
|* 12 |             FIXED TABLE FULL                | X$KSPPI        |     1 |    55 |     0   (0)|          |
|  13 |             FIXED TABLE FULL                | X$KSPPCV       |   100 |  1300 |     0   (0)|          |
|  14 |            BUFFER SORT                      |                |   131 |  2227 |     5  (20)| 00:00:01 |
|  15 |             TABLE ACCESS STORAGE FULL       | USER$          |   131 |  2227 |     4   (0)| 00:00:01 |
|  16 |           VIEW                              | SYS_DBA_SEGS   |  5095 |   875K| 13633   (1)| 00:02:44 |
|  17 |            UNION-ALL                        |                |       |       |            |          |
|* 18 |             HASH JOIN RIGHT OUTER           |                |   672 |   103K| 12305   (1)| 00:02:28 |
|  19 |              TABLE ACCESS STORAGE FULL      | USER$          |   131 |  2227 |     4   (0)| 00:00:01 |
|* 20 |              HASH JOIN                      |                |   672 | 94752 | 12301   (1)| 00:02:28 |
|  21 |               NESTED LOOPS                  |                |   672 | 68544 | 11623   (1)| 00:02:20 |
|* 22 |                HASH JOIN                    |                |   672 | 63168 | 11623   (1)| 00:02:20 |
|  23 |                 TABLE ACCESS STORAGE FULL   | TS$            |   167 |  1336 |    48   (0)| 00:00:01 |
|* 24 |                 HASH JOIN                   |                |   672 | 57792 | 11574   (1)| 00:02:19 |
|  25 |                  TABLE ACCESS STORAGE FULL  | SEG$           | 16421 |   449K|   821   (1)| 00:00:10 |
|  26 |                  VIEW                       | SYS_OBJECTS    | 21369 |  1210K| 10752   (1)| 00:02:10 |
|  27 |                   UNION-ALL                 |                |       |       |            |          |
|* 28 |                    TABLE ACCESS STORAGE FULL| TAB$           |  7284 |   177K|  2681   (1)| 00:00:33 |
|  29 |                    TABLE ACCESS STORAGE FULL| TABPART$       |  1525 | 28975 |    12   (0)| 00:00:01 |
|  30 |                    TABLE ACCESS STORAGE FULL| CLU$           |    10 |   140 |  2680   (1)| 00:00:33 |
|* 31 |                    TABLE ACCESS STORAGE FULL| IND$           |  9647 |   188K|  2681   (1)| 00:00:33 |
|  32 |                    TABLE ACCESS STORAGE FULL| INDPART$       |  1322 | 25118 |    12   (0)| 00:00:01 |
|* 33 |                    TABLE ACCESS STORAGE FULL| LOB$           |  1547 | 32487 |  2680   (1)| 00:00:33 |
|  34 |                    TABLE ACCESS STORAGE FULL| TABSUBPART$    |    32 |   448 |     2   (0)| 00:00:01 |
|  35 |                    TABLE ACCESS STORAGE FULL| INDSUBPART$    |     1 |    52 |     2   (0)| 00:00:01 |
|  36 |                    TABLE ACCESS STORAGE FULL| LOBFRAG$       |     1 |    17 |     2   (0)| 00:00:01 |
|* 37 |                INDEX UNIQUE SCAN            | I_FILE2        |     1 |     8 |     0   (0)|          |
|  38 |               TABLE ACCESS STORAGE FULL     | OBJ$           | 88138 |  3356K|   677   (1)| 00:00:09 |
|  39 |             NESTED LOOPS                    |                |    34 |  3638 |   450   (1)| 00:00:06 |
|  40 |              NESTED LOOPS                   |                |    34 |  3366 |   450   (1)| 00:00:06 |
|* 41 |               HASH JOIN OUTER               |                |    34 |  3094 |   416   (1)| 00:00:05 |
|  42 |                NESTED LOOPS                 |                |    34 |  2516 |   411   (0)| 00:00:05 |
|* 43 |                 TABLE ACCESS STORAGE FULL   | UNDO$          |   204 |  8568 |     3   (0)| 00:00:01 |
|* 44 |                 TABLE ACCESS CLUSTER        | SEG$           |     1 |    32 |     2   (0)| 00:00:01 |
|* 45 |                  INDEX UNIQUE SCAN          | I_FILE#_BLOCK# |     1 |       |     1   (0)| 00:00:01 |
|  46 |                TABLE ACCESS STORAGE FULL    | USER$          |   131 |  2227 |     4   (0)| 00:00:01 |
|  47 |               TABLE ACCESS CLUSTER          | TS$            |     1 |     8 |     1   (0)| 00:00:01 |
|* 48 |                INDEX UNIQUE SCAN            | I_TS#          |     1 |       |     0   (0)|          |
|* 49 |              INDEX UNIQUE SCAN              | I_FILE2        |     1 |     8 |     0   (0)|          |
|* 50 |             HASH JOIN                       |                |  4389 |   321K|   878   (1)| 00:00:11 |
|  51 |              TABLE ACCESS STORAGE FULL      | FILE$          |   569 |  6828 |     3   (0)| 00:00:01 |
|* 52 |              HASH JOIN RIGHT OUTER          |                |  4389 |   270K|   874   (1)| 00:00:11 |
|  53 |               TABLE ACCESS STORAGE FULL     | USER$          |   131 |  2227 |     4   (0)| 00:00:01 |
|* 54 |               HASH JOIN                     |                |  4389 |   197K|   870   (1)| 00:00:11 |
|  55 |                TABLE ACCESS STORAGE FULL    | TS$            |   167 |  1336 |    48   (0)| 00:00:01 |
|* 56 |                TABLE ACCESS STORAGE FULL    | SEG$           |  4389 |   162K|   821   (1)| 00:00:10 |
|* 57 |          TABLE ACCESS STORAGE FULL          | OBJ$           | 88138 |  3098K|   679   (1)| 00:00:09 |
|* 58 |         TABLE ACCESS CLUSTER                | TAB$           |     1 |    32 |     2   (0)| 00:00:01 |
|* 59 |          INDEX UNIQUE SCAN                  | I_OBJ#         |     1 |       |     1   (0)| 00:00:01 |
|  60 |        TABLE ACCESS CLUSTER                 | TS$            |     1 |     4 |     1   (0)| 00:00:01 |
|* 61 |         INDEX UNIQUE SCAN                   | I_TS#          |     1 |       |     0   (0)|          |
|  62 |       TABLE ACCESS CLUSTER                  | SEG$           |     1 |    12 |     2   (0)| 00:00:01 |
|* 63 |        INDEX UNIQUE SCAN                    | I_FILE#_BLOCK# |     1 |       |     1   (0)| 00:00:01 |
|* 64 |      INDEX RANGE SCAN                       | I_OBJ1         |     1 |     6 |     2   (0)| 00:00:01 |
|* 65 |     INDEX RANGE SCAN                        | I_OBJ1         |     1 |     9 |     2   (0)| 00:00:01 |
|  66 |    INDEX FULL SCAN                          | I_USER2        |   131 |   524 |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   2 - access("CX"."OWNER#"="CU"."USER#")
   8 - access("SEGMENT_NAME"="O"."NAME" AND "O"."OWNER#"="U"."USER#")
   9 - access("OWNER"="U"."NAME")
  11 - access("KSPPI"."INDX"="KSPPCV"."INDX")
  12 - filter("KSPPI"."KSPPINM"='_dml_monitoring_enabled')
  18 - access("O"."OWNER#"="U"."USER#")
  20 - access("O"."OBJ#"="SO"."OBJECT_ID" AND "O"."TYPE#"="SO"."OBJECT_TYPE_ID")
  22 - access("S"."TS#"="TS"."TS#")
  24 - access("S"."FILE#"="SO"."HEADER_FILE" AND "S"."BLOCK#"="SO"."HEADER_BLOCK" AND 
              "S"."TS#"="SO"."TS_NUMBER" AND "S"."TYPE#"="SO"."SEGMENT_TYPE_ID")
  28 - filter(BITAND("T"."PROPERTY",1024)=0)
  31 - filter(("I"."TYPE#"=1 OR "I"."TYPE#"=2 OR "I"."TYPE#"=3 OR "I"."TYPE#"=4 OR "I"."TYPE#"=6 OR 
              "I"."TYPE#"=7 OR "I"."TYPE#"=8 OR "I"."TYPE#"=9))
  33 - filter((BITAND("L"."PROPERTY",64)=0 OR BITAND("L"."PROPERTY",128)=128))
  37 - access("S"."TS#"="F"."TS#" AND "S"."FILE#"="F"."RELFILE#")
  41 - access("S"."USER#"="U"."USER#")
  43 - storage("UN"."STATUS$"<>1)
       filter("UN"."STATUS$"<>1)
  44 - filter(("S"."TYPE#"=1 OR "S"."TYPE#"=10))
  45 - access("S"."TS#"="UN"."TS#" AND "S"."FILE#"="UN"."FILE#" AND "S"."BLOCK#"="UN"."BLOCK#")
  48 - access("S"."TS#"="TS"."TS#")
  49 - access("UN"."TS#"="F"."TS#" AND "UN"."FILE#"="F"."RELFILE#")
  50 - access("S"."TS#"="F"."TS#" AND "S"."FILE#"="F"."RELFILE#")
  52 - access("S"."USER#"="U"."USER#")
  54 - access("S"."TS#"="TS"."TS#")
  56 - filter(("S"."TYPE#"<>6 AND "S"."TYPE#"<>5 AND "S"."TYPE#"<>8 AND "S"."TYPE#"<>10 AND 
              "S"."TYPE#"<>1))
  57 - storage(BITAND("O"."FLAGS",128)=0)
       filter(BITAND("O"."FLAGS",128)=0)
  58 - filter(BITAND("T"."PROPERTY",1)=0)
  59 - access("O"."OBJ#"="T"."OBJ#")
  61 - access("T"."TS#"="TS"."TS#")
  63 - access("T"."TS#"="S"."TS#" AND "T"."FILE#"="S"."FILE#" AND "T"."BLOCK#"="S"."BLOCK#")
  64 - access("T"."BOBJ#"="CO"."OBJ#")
  65 - access("T"."DATAOBJ#"="CX"."OBJ#")

3) It captures some execution statistics that I like to look at .. Here is the output below.

Summary of query stats





 ************** plan_hash_value       = 1188305021
 ************** sql_id               = 208ttrm2nbt0u

avg_elapsed_time      = 2.59
total_executions      = 2
avg_rows_processed    = 5372
avg_disk_reads        = 202
avg_buffer_gets       = 189970
avg_cpu_time          = 2426631
avg_iowait            = 99965
avg_cluster_wait      = 245947
avg_direct_writes     = 0
avg_plssql_exec_time  = 162398
avg_cell_offload      = 0

And finally it creates the beautiful sql_monitor output we are all used to.

Pretty cool huh ?  It creates these 3 pieces based on the last sql executed in the session.. Now this is the best part.. At the end of the script is this code.

!echo "From: bryan.grenn@oracle.com"  > /tmp/file
!echo "To: bryan.grenn@oracle.com"   >> /tmp/file
!echo "Subject: analyze output sql_monitor"   >> /tmp/file
!echo "Mime-Version: 1.0"      >> /tmp/file
!echo 'Content-Type: multipart/mixed; boundary="DMW.Boundary.605592468"'   >> /tmp/file
!echo "--DMW.Boundary.605592468" >> /tmp/file
!echo " " >> /tmp/file
!echo " analyze report sql_monitor " >> /tmp/file
!echo " " >> /tmp/file
!echo "--DMW.Boundary.605592468" >> /tmp/file
!echo 'Content-Disposition: inline; filename="analyze_dbms_xplan.txt"' >> /tmp/file
!echo "Content-Transfer-Encoding: 7bit" >> /tmp/file
!cat /tmp/analyze_dbms_xplan.txt >> /tmp/file
!echo "--DMW.Boundary.605592468" >> /tmp/file

!echo 'Content-Disposition: inline; filename="analyze_query_stats.txt"' >> /tmp/file
!echo "Content-Transfer-Encoding: 7bit" >> /tmp/file
!cat /tmp/analyze_query_stats.txt >> /tmp/file
!echo "--DMW.Boundary.605592468" >> /tmp/file

!echo 'Content-Disposition: inline; filename="analyze_sql_monitor.htm"' >> /tmp/file
!echo "Content-Transfer-Encoding: 7bit" >> /tmp/file
!cat /tmp/analyze_html.htm >> /tmp/file
!echo "--DMW.Boundary.605592468" >> /tmp/file

!/usr/sbin/sendmail bryan.grenn@oracle.com < /tmp/file

This code will take the 3 output files, and mail them to you as attachments.  Notice my e-mail is in the script, so change it to what you need to get it going.  

I'm going to use the often, by putting it on all my servers and just running it after any stubborn sql show up. I will be instantly e-mailed the mail pieces I need to figure out what is going on with the sql.

R and visualing your execution times

Well, I think I'm a little late to the party..   I know Greg Rahn did a great post on utilizing R to visual your ash data.  I figure I would do a simple example of how to build something myself to show how easy it is to utilyze R to visualize query execution times..

Well first I stated by downloading R from cran.r-project.org.

Once I downloaded R, I went to one of my databases, and found a query that had different execution times I wanted to play with.  I created an output file from the query.. Here is the script I used..

set pagesize 10000
set feedback off
spool rtest.txt

select trunc((elapsed_time_delta/executions_delta)/1000000,4) avg_execution_time "AVG_EXECUTION_TIME",
       PLAN_HASH_VALUE "PLAN_HASH_VALUE",
       execution_date "EXECUTION_DATE"
from
(
select sum(elapsed_time_delta) elapsed_time_delta,
       sum(executions_delta) executions_delta,
              PLAN_HASH_VALUE,
              to_char(trunc(end_interval_time),'mm/dd/yy') execution_date
from dba_hist_sqlstat a,
     dba_hist_snapshot b
 where sql_id='19sqmxkc58wqm'
and a.snap_id=b.snap_id
and a.instance_number=b.instance_number
--and executions_delta>0
group by plan_hash_value,to_char(trunc(end_interval_time),'mm/dd/yy')
)
where executions_delta > 0
order by execution_date;
spool off

This script created a file I brought over to my pc and cleaned up the format. Here is part of the file..

AVG_EXECUTION_TIME PLAN_HASH_VALUE execution_date                                     
           20.4368       566875892 01/01/12                                     
           50.3253      4009342004 01/01/12                                     
           21.4655       566875892 01/02/12                                     
           19.8312      4009342004 01/02/12                                     
           69.9299      4009342004 01/03/12                                     
          135.7153      4009342004 01/04/12                                     
           39.3972      4009342004 01/05/12                                     
           65.2833      4009342004 01/06/12                                     
           39.8093      4009342004 01/07/12                                     
           35.8615      4009342004 01/08/12                                     
           18.7553       566875892 01/09/12                                     
          134.7431      4009342004 01/09/12                                     
           76.2954      4009342004 01/10/12                                     
          115.8707      4009342004 01/11/12                                     
           60.0754      4009342004 01/12/12                                     
          102.6432      4009342004 01/13/12                                     
           22.2528       566875892 01/14/12                                     
          119.8541      4009342004 01/14/12                                     
           21.8552       566875892 01/15/12                                     
           18.5785      4009342004 01/15/12                                     
           19.3179       566875892 01/16/12                                     
            80.794      4009342004 01/16/12                                     
           67.0872      4009342004 01/17/12                                     
          107.1604      4009342004 01/18/12                                     
           28.9797      4009342004 01/19/12                                     
          

I put this file into c:\r and named it query_performance .txt.

I then went into R and ran the following commands.

setwd("c:\\r")
query_data <- read.table("query_performance.txt",header=T)


max_num <- max(query_data$AVG_EXECUTION_TIME)

hist(query_data$AVG_EXECUTION_TIME,col=heat.colors(max_num),breaks=max_num,xlim=c(0,max_num),
     right=F,main="Execution Time Histogram",las=1)

You can see I just ran a few simple commands...

setwd --- set the working directory to c:\r
read.table --- read in my space delimitted table (there is a read.csv for a comma separated file)
max_num  --- is set to the maximum execution time in the file

hist   -- creates a histogram of the execution times.. Check out below what comes out. Sweet !!

This was easy, and gives me a great picture of the variance in execution times. 

I am going to work more with this file since it had 2 different plans I want to visual the differences.