.
.
.
I am an Oracle Database Specialist in Singapore.
Please note that this site uses cookies.
30 April, 2011
SELECT FOR UPDATE with SubQuery (and "Write Consistency")
Just a quick post to provide a reference to a "bug" aka "expected behaviour if it is in the specification" that Jonathan Lewis has written about.
22 April, 2011
ArchiveLogs in the controlfile
RMAN's listing will only show those that RMAN has not obsoleted or deleted.
A number of ArchivedLogs were expected to be present on disk but couldn't be found. These are marked as EXPIRED.
(You might notice that I have done a RESETLOGS on 09-April, but that fact is irrelevant for the purpose of this blog entry about the *number* of ArchiveLog entries in the controlfile and RMAN listings).
After an SQL 'ALTER SYSTEM SWITCH LOGFILE;' I have :
V$ARCHIVED_LOG shows all the archivelogs that are registered in the controlfile. This list may well exceed the CONTROL_FILE_RECORD_KEEP_TIME. This list is not the same as that presented by RMAN.
Thus :
The controlfile has ArchiveLogs going back more than 142 days !
.....
There is a way to "clear" *ALL* the entries. NOT to be done on Production databases. NOT to be done on a Primary for a Standby or on a Standby -- unless you know precisely the potential consequences and how to deal with them.
*ALL* the entries have been purged from the controfile. Neither V$ARCHIVED_LOG nor RMAN lists any controlfiles.
Yet, the physical files do still exist :
Can I add these files back in ?
YES. Fortunately, I can "add" them back.
As I noted above, DO NOT try this on a Production database or on a Standby -- unless you know precisely the potential consequences and how to deal with them !
UPDATE 11-May-11 : MAXLOGHISTORY in the CREATE DATABASE (or CREATE CONTROLFILE) command also must be considered.
.
.
RMAN> crosscheck archivelog all;
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=41 device type=DISK
validation failed for archived log
archived log file name=/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_722_6t0vvymw_.arc RECID=549 STAMP=748046335
validation failed for archived log
archived log file name=/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_723_6t0xr7rg_.arc RECID=550 STAMP=748048264
validation failed for archived log
archived log file name=/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_724_6t0y14tl_.arc RECID=551 STAMP=748049471
validation failed for archived log
... entries deleted from this output ....
validation succeeded for archived log
archived log file name=/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_14_6v33hb8m_.arc RECID=565 STAMP=749168234
Crosschecked 17 objects
A number of ArchivedLogs were expected to be present on disk but couldn't be found. These are marked as EXPIRED.
RMAN> delete expired archivelog all;
released channel: ORA_DISK_1
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=41 device type=DISK
List of Archived Log Copies for database with db_unique_name ORCL
=====================================================================
Key Thrd Seq S Low Time
------- ---- ------- - ---------
549 1 722 X 07-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_722_6t0vvymw_.arc
550 1 723 X 09-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_723_6t0xr7rg_.arc
551 1 724 X 09-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_724_6t0y14tl_.arc
552 1 1 X 09-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_1_6t0zmypg_.arc
... entries deleted from this output ....
563 1 12 X 17-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_21/o1_mf_1_12_6v0j3111_.arc
564 1 13 X 21-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_13_6v339368_.arc
Do you really want to delete the above objects (enter YES or NO)? YES
deleted archived log
archived log file name=/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_722_6t0vvymw_.arc RECID=549 STAMP=748046335
deleted archived log
archived log file name=/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_723_6t0xr7rg_.arc RECID=550 STAMP=748048264
deleted archived log
archived log file name=/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_724_6t0y14tl_.arc RECID=551 STAMP=748049471
deleted archived log
archived log file name=/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_09/o1_mf_1_1_6t0zmypg_.arc RECID=552 STAMP=748050174
... entries deleted from this output ....
deleted archived log
archived log file name=/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_13_6v339368_.arc RECID=564 STAMP=749168038
Deleted 16 EXPIRED objects
(You might notice that I have done a RESETLOGS on 09-April, but that fact is irrelevant for the purpose of this blog entry about the *number* of ArchiveLog entries in the controlfile and RMAN listings).
After an SQL 'ALTER SYSTEM SWITCH LOGFILE;' I have :
RMAN> list archivelog all;
using target database control file instead of recovery catalog
List of Archived Log Copies for database with db_unique_name ORCL
=====================================================================
Key Thrd Seq S Low Time
------- ---- ------- - ---------
565 1 14 A 22-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_14_6v33hb8m_.arc
566 1 15 A 22-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_15_6v33j837_.arc
V$ARCHIVED_LOG shows all the archivelogs that are registered in the controlfile. This list may well exceed the CONTROL_FILE_RECORD_KEEP_TIME. This list is not the same as that presented by RMAN.
Thus :
SQL> show parameter control_file_record_keep_time
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
control_file_record_keep_time integer 7
SQL> select trunc(first_time), count(*)
2 from v$archived_log
3 group by trunc(first_time)
4 order by 1
5 /
TRUNC(FIR COUNT(*)
--------- ----------
01-DEC-10 1
08-JAN-11 6
09-JAN-11 275
13-JAN-11 1
14-JAN-11 2
15-JAN-11 11
... entries deleted from this output ....
15-APR-11 2
16-APR-11 3
17-APR-11 1
21-APR-11 1
22-APR-11 2
50 rows selected.
SQL>
SQL> select max(first_time)-min(first_time) from v$archived_log;
MAX(FIRST_TIME)-MIN(FIRST_TIME)
-------------------------------
142.657558
SQL>
The controlfile has ArchiveLogs going back more than 142 days !
.....
There is a way to "clear" *ALL* the entries. NOT to be done on Production databases. NOT to be done on a Primary for a Standby or on a Standby -- unless you know precisely the potential consequences and how to deal with them.
SQL> startup mount;
ORACLE instance started.
Total System Global Area 836976640 bytes
Fixed Size 1339740 bytes
Variable Size 201330340 bytes
Database Buffers 629145600 bytes
Redo Buffers 5160960 bytes
Database mounted.
SQL>
SQL> select * from v$controlfile_record_section
2 where type = 'ARCHIVED LOG';
TYPE RECORD_SIZE RECORDS_TOTAL RECORDS_USED FIRST_INDEX LAST_INDEX LAST_RECID
---------------------------- ----------- ------------- ------------ ----------- ---------- ----------
ARCHIVED LOG 584 1349 414 1270 334 566
SQL>
SQL> -- do *NOT* do this on Production
SQL> -- do *NOT* do this if you have a Standby database
SQL> -- the section number may not be documented to be the same in all versions
SQL> exec dbms_backup_restore.resetcfilesection(11);
PL/SQL procedure successfully completed.
SQL>
PL/SQL procedure successfully completed.
SQL> select * from v$controlfile_record_section
2 where type = 'ARCHIVED LOG';
TYPE RECORD_SIZE RECORDS_TOTAL RECORDS_USED FIRST_INDEX LAST_INDEX LAST_RECID
---------------------------- ----------- ------------- ------------ ----------- ---------- ----------
ARCHIVED LOG 584 1349 0 0 0 0
SQL>
SQL> select count(*) from v$archived_log;
COUNT(*)
----------
0
SQL>
RMAN> list archivelog all;
using target database control file instead of recovery catalog
specification does not match any archived log in the repository
RMAN> crosscheck archivelog all;
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=18 device type=DISK
specification does not match any archived log in the repository
RMAN>
*ALL* the entries have been purged from the controfile. Neither V$ARCHIVED_LOG nor RMAN lists any controlfiles.
Yet, the physical files do still exist :
[oracle@localhost 2011_04_22]$ pwd
/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22
[oracle@localhost 2011_04_22]$ ls -l
total 472
-rw-rw---- 1 oracle oracle 467968 Apr 22 22:17 o1_mf_1_14_6v33hb8m_.arc
-rw-rw---- 1 oracle oracle 5120 Apr 22 22:17 o1_mf_1_15_6v33j837_.arc
[oracle@localhost 2011_04_22]$
Can I add these files back in ?
RMAN> catalog start with '/addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22';
using target database control file instead of recovery catalog
searching for all files that match the pattern /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22
List of Files Unknown to the Database
=====================================
File Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_15_6v33j837_.arc
File Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_14_6v33hb8m_.arc
Do you really want to catalog the above files (enter YES or NO)? YES
cataloging files...
cataloging done
List of Cataloged Files
=======================
File Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_15_6v33j837_.arc
File Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_14_6v33hb8m_.arc
RMAN>
RMAN> list archivelog all;
List of Archived Log Copies for database with db_unique_name ORCL
=====================================================================
Key Thrd Seq S Low Time
------- ---- ------- - ---------
2 1 14 A 22-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_14_6v33hb8m_.arc
1 1 15 A 22-APR-11
Name: /addtl/oracle/flash_recovery_area/ORCL/archivelog/2011_04_22/o1_mf_1_15_6v33j837_.arc
RMAN>
SQL> select * from v$controlfile_record_section
2 where type = 'ARCHIVED LOG';
TYPE RECORD_SIZE RECORDS_TOTAL RECORDS_USED FIRST_INDEX LAST_INDEX LAST_RECID
---------------------------- ----------- ------------- ------------ ----------- ---------- ----------
ARCHIVED LOG 584 1349 2 1 2 2
SQL> select count(*) from v$archived_log;
COUNT(*)
----------
2
SQL> select thread#, sequence# from v$archived_log;
THREAD# SEQUENCE#
---------- ----------
1 15
1 14
SQL>
YES. Fortunately, I can "add" them back.
As I noted above, DO NOT try this on a Production database or on a Standby -- unless you know precisely the potential consequences and how to deal with them !
UPDATE 11-May-11 : MAXLOGHISTORY in the CREATE DATABASE (or CREATE CONTROLFILE) command also must be considered.
.
.
17 April, 2011
DETERMINISTIC Functions - 3
Returning to my thread on Deterministic Functions ......
Suppose that I have a (partitioned) SALES table with data like this :
And a SALES_TAX_RATES tables such as :
Since the Sales Tax Rate varies by Quantity, I need to factor the quantity when computing sales tax.
I have a function for the Year 2010 Sales Tax calculations as :
(Notice that I haven't defined it as DETERMINISTIC).
Excuting this function, it takes 190 seconds to compute the total Sales Tax for the Year 2010 :
The tkprof output for this run is :
(Apparently, the presentation of some of the executions is mangled as if these are different SQL statements. This could be a bug but it has no significant impact on my test).
Therefore, with a (default) Non-Deterministic Function, the Function (and the two SQLs therein) was executed once for each row fetched from the SALES table -- so we have two additional SQL (recursive depth 1) calls for each row !
These additional SQL calls are quite an overhead !
I know the data well. I know that my Sales records have only 3 different Sale Quantities (SALE_QTY) and 4 different Sale Prices (SALE_PRICE). Therefore, the probability of the same SALE_QTY and SALE_PRICE being repeated in the next row fetched is quite high. If I had very many different Quantities and/or Prices, the probability of repetition would be very low.
With the high probability of repetition, I know that I can instruct Oracle to assume that the computed Sales Tax would be the same for the next row from the SALES table if the SALE_QTY and SALE_PRICE were the same ! I can use a DETERMINISTIC function.
I define my Sales Tax computation function as a DETERMINISTIC function thus :
I then compute Year 2010 Sales Tax using this function :
This time, the total computation took only 1.21seconds ! A vast improvement ! (Had there been 3.6million rows instead of 36,400 only, the difference in time would be very very noticeable -- provided that the pattern of SALE_QTY and SALE_PRICE held even for the larger volume).
(WHY did I lock the SALES_TAX_RATES table ? I wanted to ensure that no values were changed while my computation was running. If the rates in this table were changed, the computed Sales Tax amounts wouldn't be accurate with a DETERMINISTIC definition for the function !)
The tkprof output shows :
The two SQLs in the fuction were executed only 12 times. That means that the function was executed only 12 times. At every row, Oracle evaluated the SALE_QTY and SALE_PRICE versus the values from the previous row. It would re-execute the function only if either of these values differed. If the values are the same, it avoids the overhead of the Function call itself as I have explicitly (with my DETERMINISTIC definition) assured Oracle that the computed value of the Function wouldn't change if the input values were the same !
This is how (if I know the data -- the pattern of SALE_QTY and SALE_PRICE values !) I could use a DETERMINISTIC definition.
(btw : There's another way to speed up the execution as well, still using a Function but rewriting it again. ... That is actually a very simple exercise).
.
.
.
Update : See the UPDATE and comments at the end of this post.
Suppose that I have a (partitioned) SALES table with data like this :
SQL> desc sales;
Name Null? Type
----------------------------------------- -------- ----------------------------
SALE_DATE DATE
SALE_ID NUMBER(8)
SALESMAN_ID NUMBER(5)
SALE_QTY NUMBER
SALE_PRICE NUMBER
SQL> select count(*) from sales partition (sales_p_2010);
COUNT(*)
----------
36399
SQL> select min(sale_date), max(sale_date) from sales partition (sales_p_2010);
MIN(SALE_ MAX(SALE_
--------- ---------
01-JAN-10 30-DEC-10
SQL> select sale_qty, count(*) from sales partition (sales_p_2010) group by sale_qty order by 1;
SALE_QTY COUNT(*)
---------- ----------
1000 18199
2000 7280
3000 10920
SQL> select sale_price, count(*) from sales partition (sales_p_2010) group by sale_price order by 1;
SALE_PRICE COUNT(*)
---------- ----------
1 9114
2 9003
3 9143
4 9139
And a SALES_TAX_RATES tables such as :
SQL> desc sales_tax_rates;
Name Null? Type
----------------------------------------- -------- ----------------------------
DATE_FROM DATE
DATE_TO DATE
QUANTITY NUMBER
TAX_RATE NUMBER
SQL> select * from sales_tax_rates order by date_from, quantity;
DATE_FROM DATE_TO QUANTITY TAX_RATE
--------- --------- ---------- ----------
01-JAN-10 31-DEC-10 1000 .05
01-JAN-10 31-DEC-10 2000 .06
01-JAN-10 31-DEC-10 3000 .07
01-JAN-10 31-DEC-10 5000 .1
01-JAN-11 31-DEC-11 1000 .07
01-JAN-11 31-DEC-11 2000 .08
01-JAN-11 31-DEC-11 3000 .09
01-JAN-11 31-DEC-11 5000 .15
8 rows selected.
SQL>
Since the Sales Tax Rate varies by Quantity, I need to factor the quantity when computing sales tax.
I have a function for the Year 2010 Sales Tax calculations as :
SQL> create or replace function sales_tax_nd_2010
2 (sale_qty_in number, sale_price_in number)
3 return number
4 as
5 f_sales_tax number;
6 f_tax_rate number;
7 begin
8 select tax_rate into f_tax_rate from sales_tax_rates
9 where
10 date_from = to_date('01-JAN-2010','DD-MON-YYYY')
11 and date_to = to_date('31-DEC-2010','DD-MON-YYYY')
12 and sale_qty_in = quantity;
13 select (sale_qty_in * sale_price_in * f_tax_rate) into f_sales_tax from dual;
14 return f_sales_tax;
15 end;
16 /
Function created.
SQL>
(Notice that I haven't defined it as DETERMINISTIC).
Excuting this function, it takes 190 seconds to compute the total Sales Tax for the Year 2010 :
SQL> exec dbms_session.session_trace_enable(waits=>FALSE,binds=>FALSE);
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.08
SQL> select sum(sales_tax_nd_2010(sale_qty, sale_price)) from sales;
SUM(SALES_TAX_ND_2010(SALE_QTY,SALE_PRICE))
-------------------------------------------
10194440
Elapsed: 00:03:10.21
SQL>
The tkprof output for this run is :
SQL ID: 5qxuj4xvh4ctb
Plan Hash: 3519235612
select sum(sales_tax_nd_2010(sale_qty, sale_price))
from
sales
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.14 0.28 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 103.75 126.48 0 143 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 103.90 126.77 0 143 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 184
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=254963 pr=0 pw=0 time=0 us)
36399 PARTITION RANGE ALL PARTITION: 1 2 (cr=143 pr=0 pw=0 time=5807971 us cost=42 size=218394 card=36399)
36399 TABLE ACCESS FULL SALES PARTITION: 1 2 (cr=143 pr=0 pw=0 time=975849 us cost=42 size=218394 card=36399)
SQL ID: g7bbysbxz5bmg
Plan Hash: 1259010386
SELECT TAX_RATE
FROM
SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND
DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AND :B1 = QUANTITY
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.03 0 0 0 0
Execute 36390 6.05 8.49 0 0 0 0
Fetch 36390 13.71 32.59 0 254730 0 36390
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 72781 19.78 41.12 0 254730 0 36390
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 184 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL SALES_TAX_RATES (cr=7 pr=0 pw=0 time=0 us cost=3 size=22 card=1)
SQL ID: 0vp2tqpgvc379
Plan Hash: 1388734953
SELECT (:B3 * :B2 * :B1 )
FROM
DUAL
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 36391 7.32 9.80 0 0 0 0
Fetch 36391 6.54 12.32 0 0 0 36391
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 72783 13.87 22.13 0 0 0 36391
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 184 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 FAST DUAL (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)
SELECT TAX_RATE FROM SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AN
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 7 0 1
SELECT (:B3 * :B2 *
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
SELECT TAX_RATE FROM SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AN
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 7 0 1
SELECT (:B3 * :B2 *
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
SELECT TAX_RATE FROM SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AN
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 7 0 1
SELECT (:B3 * :B2 *
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
SELECT TAX_RATE FROM SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AN
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 7 0 1
SELECT (:B3 * :B2 *
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
SELECT TAX_RATE FROM SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AN
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 7 0 1
SELECT TAX_RATE FROM SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AN
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 7 0 1
SELECT (:B3 * :B2 *
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
SELECT TAX_RATE FROM SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AN
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 7 0 1
SELECT (:B3 * :B2 *
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
SELECT TAX_RATE FROM SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AN
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 7 0 1
SELECT (:B3 * :B2 *
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
SELECT TAX_RATE FROM SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AN
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 7 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 7 0 1
SELECT (:B3 * :B2 *
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
(Apparently, the presentation of some of the executions is mangled as if these are different SQL statements. This could be a bug but it has no significant impact on my test).
Therefore, with a (default) Non-Deterministic Function, the Function (and the two SQLs therein) was executed once for each row fetched from the SALES table -- so we have two additional SQL (recursive depth 1) calls for each row !
These additional SQL calls are quite an overhead !
I know the data well. I know that my Sales records have only 3 different Sale Quantities (SALE_QTY) and 4 different Sale Prices (SALE_PRICE). Therefore, the probability of the same SALE_QTY and SALE_PRICE being repeated in the next row fetched is quite high. If I had very many different Quantities and/or Prices, the probability of repetition would be very low.
With the high probability of repetition, I know that I can instruct Oracle to assume that the computed Sales Tax would be the same for the next row from the SALES table if the SALE_QTY and SALE_PRICE were the same ! I can use a DETERMINISTIC function.
I define my Sales Tax computation function as a DETERMINISTIC function thus :
SQL> create or replace function sales_tax_DET_2010
2 (sale_qty_in number, sale_price_in number)
3 return number DETERMINISTIC
4 as
5 f_sales_tax number;
6 f_tax_rate number;
7 begin
8 select tax_rate into f_tax_rate from sales_tax_rates
9 where
10 date_from = to_date('01-JAN-2010','DD-MON-YYYY')
11 and date_to = to_date('31-DEC-2010','DD-MON-YYYY')
12 and sale_qty_in = quantity;
13 select (sale_qty_in * sale_price_in * f_tax_rate) into f_sales_tax from dual;
14 return f_sales_tax;
15 end;
16 /
Function created.
SQL>
I then compute Year 2010 Sales Tax using this function :
SQL> exec dbms_session.session_trace_enable(waits=>FALSE,binds=>FALSE);
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.17
SQL> lock table sales_tax_rates in exclusive mode;
Table(s) Locked.
Elapsed: 00:00:00.18
SQL> select sum(sales_tax_det_2010(sale_qty, sale_price)) from sales;
SUM(SALES_TAX_DET_2010(SALE_QTY,SALE_PRICE))
--------------------------------------------
10194440
Elapsed: 00:00:01.21
SQL>
This time, the total computation took only 1.21seconds ! A vast improvement ! (Had there been 3.6million rows instead of 36,400 only, the difference in time would be very very noticeable -- provided that the pattern of SALE_QTY and SALE_PRICE held even for the larger volume).
(WHY did I lock the SALES_TAX_RATES table ? I wanted to ensure that no values were changed while my computation was running. If the rates in this table were changed, the computed Sales Tax amounts wouldn't be accurate with a DETERMINISTIC definition for the function !)
The tkprof output shows :
SQL ID: 3s4xbaczvghpb
Plan Hash: 3519235612
select sum(sales_tax_det_2010(sale_qty, sale_price))
from
sales
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.10 0.15 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.20 0.25 0 143 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.31 0.41 0 143 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 184
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=273 pr=0 pw=0 time=0 us)
36399 PARTITION RANGE ALL PARTITION: 1 2 (cr=143 pr=0 pw=0 time=10254530 us cost=42 size=218394 card=36399)
36399 TABLE ACCESS FULL SALES PARTITION: 1 2 (cr=143 pr=0 pw=0 time=6083319 us cost=42 size=218394 card=36399)
SQL ID: g7bbysbxz5bmg
Plan Hash: 1259010386
SELECT TAX_RATE
FROM
SALES_TAX_RATES WHERE DATE_FROM = TO_DATE('01-JAN-2010','DD-MON-YYYY') AND
DATE_TO = TO_DATE('31-DEC-2010','DD-MON-YYYY') AND :B1 = QUANTITY
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 12 0.02 0.03 0 0 0 0
Fetch 12 0.00 0.00 0 84 0 12
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 25 0.04 0.04 0 84 0 12
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 184 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL SALES_TAX_RATES (cr=7 pr=0 pw=0 time=0 us cost=3 size=22 card=1)
SQL ID: 0vp2tqpgvc379
Plan Hash: 1388734953
SELECT (:B3 * :B2 * :B1 )
FROM
DUAL
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 12 0.00 0.00 0 0 0 0
Fetch 12 0.00 0.00 0 0 0 12
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 25 0.00 0.01 0 0 0 12
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 184 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 FAST DUAL (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)
The two SQLs in the fuction were executed only 12 times. That means that the function was executed only 12 times. At every row, Oracle evaluated the SALE_QTY and SALE_PRICE versus the values from the previous row. It would re-execute the function only if either of these values differed. If the values are the same, it avoids the overhead of the Function call itself as I have explicitly (with my DETERMINISTIC definition) assured Oracle that the computed value of the Function wouldn't change if the input values were the same !
This is how (if I know the data -- the pattern of SALE_QTY and SALE_PRICE values !) I could use a DETERMINISTIC definition.
UPDATE : Let me clarify that I would use a DETERMINSTIC function in this manner only if :
a. I knew that the data in the target table (SALES) follows such a pattern that the function predicates will not vary frequently
b. I knew that the reference table (SALES_TAX_RATES) would not be updated frequently. This is an important lookup table where change controls mandate that data is not updated until and approved and only in specific windows. Of course, I add the LOCK TABLE SALES_TAX_RATES as a matter of abundant caution.
(btw : There's another way to speed up the execution as well, still using a Function but rewriting it again. ... That is actually a very simple exercise).
.
.
.
15 April, 2011
Standby Databases (aka "DataGuard") -1
(before I return to my series on Deterministic functions ........... )
UPDATE March 2017: See my new series on SingleInstance DataGuard for RAC, beginning here.
This week I have had two sets of questions about standby databases -- what a coincidence ! The last time I really worked with a Standby was in 8.1.7 -- without the DataGuard "backport" from 9i. (and, before that, in 7.0). All of a sudden, I have had questions about 10g and 11 DG.
Anyways, since I had started "exploring" 11.2 DG (skipping over 9i and 10g) a few days ago, and had setup a DG environment in my VM, here are some entries from the Standby's alert.log :
For the present, I am ignoring the ORA-16086 "errors" -- because I haven't followed the "advice" to create Standby Redo Logs (why make things too complicated, eh ?).
Here's what I have on my Primary :
That looks fine to me. Right ? No Gap.
I am also ignoring these errors on my Standby (heh ! this is a "play and learn" environment !)
What is the point of this blog post ? ......... All in due course.
.
.
.
.
.
.
.
Next, I shutdown my primary :
While the primary shutdown is proceeding, it "flags" these errors :
I then re-start the primary and, in due course, see these messages in the primary alert.log :
I then :
and see :
Soon, I will learn how to perform "maintenance" on the primary with the standby shutdown.
.
.
Returning to this thread ....
I perform recovery on the standby :
and monitor it from the stdby alert.log :
So far so good .....
.
.
.
Updates to this "voyage of discovery" to follow ....
.
.
UPDATE : Adding a Standby Redo Log on the Standby :
following which the messages are :
So, now my Standby Database does have a Standby Redo Log.
Note : I was able to work without a Standby Redo Log but I had almost no transactions generating Redo.
.
.
.
UPDATE March 2017: See my new series on SingleInstance DataGuard for RAC, beginning here.
This week I have had two sets of questions about standby databases -- what a coincidence ! The last time I really worked with a Standby was in 8.1.7 -- without the DataGuard "backport" from 9i. (and, before that, in 7.0). All of a sudden, I have had questions about 10g and 11 DG.
Anyways, since I had started "exploring" 11.2 DG (skipping over 9i and 10g) a few days ago, and had setup a DG environment in my VM, here are some entries from the Standby's alert.log :
Fri Apr 15 22:32:52 2011 RFS[12]: Assigned to RFS process 3778 RFS[12]: Identified database type as 'physical standby': Client is LGWR SYNC pid 2576 Primary database is in MAXIMUM AVAILABILITY mode Standby controlfile consistent with primary Standby controlfile consistent with primary RFS[12]: No standby redo logfiles selected (reason:7) Errors in file /home/oracle/app/oracle/diag/rdbms/stdby/stdby/trace/stdby_rfs_3778.trc: ORA-16086: Redo data cannot be written to the standby redo log Fri Apr 15 22:33:14 2011 RFS[13]: Assigned to RFS process 3790 RFS[13]: Identified database type as 'physical standby': Client is ARCH pid 2658 Fri Apr 15 22:33:34 2011 RFS[14]: Assigned to RFS process 3792 RFS[14]: Identified database type as 'physical standby': Client is ARCH pid 2645 RFS[14]: Opened log for thread 1 sequence 30 dbid 159971472 branch 748133139 Archived Log entry 24 added for thread 1 sequence 30 rlc 748133139 ID 0x988c490 dest 2: Fri Apr 15 22:33:54 2011 RFS[15]: Assigned to RFS process 3794 RFS[15]: Identified database type as 'physical standby': Client is ARCH pid 2658 Fri Apr 15 22:34:20 2011 RFS[16]: Assigned to RFS process 3806 RFS[16]: Identified database type as 'physical standby': Client is LGWR SYNC pid 2576 Primary database is in MAXIMUM AVAILABILITY mode Standby controlfile consistent with primary Standby controlfile consistent with primary RFS[16]: No standby redo logfiles selected (reason:7) Errors in file /home/oracle/app/oracle/diag/rdbms/stdby/stdby/trace/stdby_rfs_3806.trc: ORA-16086: Redo data cannot be written to the standby redo log Fri Apr 15 22:34:41 2011 RFS[17]: Assigned to RFS process 3810 RFS[17]: Identified database type as 'physical standby': Client is ARCH pid 2658
For the present, I am ignoring the ORA-16086 "errors" -- because I haven't followed the "advice" to create Standby Redo Logs (why make things too complicated, eh ?).
Here's what I have on my Primary :
SQL> select dest_id, max(sequence#) from v$archived_log group by dest_id;
DEST_ID MAX(SEQUENCE#)
---------- --------------
1 32
2 32
SQL>
SQL> select * from v$archive_gap;
no rows selected
SQL>
That looks fine to me. Right ? No Gap.
I am also ignoring these errors on my Standby (heh ! this is a "play and learn" environment !)
Fatal NI connect error 12537, connecting to:
(LOCAL=NO)
VERSION INFORMATION:
TNS for Linux: Version 11.2.0.1.0 - Production
Oracle Bequeath NT Protocol Adapter for Linux: Version 11.2.0.1.0 - Production
TCP/IP NT Protocol Adapter for Linux: Version 11.2.0.1.0 - Production
Time: 15-APR-2011 22:39:14
Tracing not turned on.
Tns error struct:
ns main err code: 12537
TNS-12537: TNS:connection closed
ns secondary err code: 12560
nt main err code: 0
nt secondary err code: 0
nt OS err code: 0
opiodr aborting process unknown ospid (3905) as a result of ORA-609
What is the point of this blog post ? ......... All in due course.
.
.
.
.
.
.
.
Next, I shutdown my primary :
SQL> shutdown immediate Database closed. Database dismounted. ORACLE instance shut down. SQL>
While the primary shutdown is proceeding, it "flags" these errors :
Fri Apr 15 22:39:35 2011 ARC3: Archival disabled due to shutdown: 1014 Shutting down archive processes Archiving is disabled Archive process shutdown avoided: 0 active Errors in file /home/oracle/app/oracle/diag/rdbms/prod/prod/trace/prod_arc3_2660.trc: ORA-01014: ORACLE shutdown in progress Errors in file /home/oracle/app/oracle/diag/rdbms/prod/prod/trace/prod_arc3_2660.trc: ORA-01014: ORACLE shutdown in progress Errors in file /home/oracle/app/oracle/diag/rdbms/prod/prod/trace/prod_arc3_2660.trc: ORA-01014: ORACLE shutdown in progress Errors in file /home/oracle/app/oracle/diag/rdbms/prod/prod/trace/prod_arc3_2660.trc: ORA-01014: ORACLE shutdown in progress Errors in file /home/oracle/app/oracle/diag/rdbms/prod/prod/trace/prod_arc3_2660.trc: ORA-01014: ORACLE shutdown in progress Errors in file /home/oracle/app/oracle/diag/rdbms/prod/prod/trace/prod_arc3_2660.trc: ORA-01014: ORACLE shutdown in progress Master background archival failure: 1014 ARCH shutting down ARC3: Archival stopped
I then re-start the primary and, in due course, see these messages in the primary alert.log :
Fri Apr 15 22:44:05 2011 ARC0 started with pid=21, OS id=4137 ARC0: Archival started LGWR: STARTING ARCH PROCESSES COMPLETE ARC0: STARTING ARCH PROCESSES LGWR: Primary database is in MAXIMUM AVAILABILITY mode LGWR: Destination LOG_ARCHIVE_DEST_1 is not serviced by LGWR Fri Apr 15 22:44:06 2011 ARC2 started with pid=20, OS id=4150 Fri Apr 15 22:44:06 2011 ARC3 started with pid=23, OS id=4152 Fri Apr 15 22:44:06 2011 ARC1 started with pid=22, OS id=4148 Fri Apr 15 22:44:07 2011 NSS2 started with pid=24, OS id=4156 ARC1: Archival started ARC2: Archival started ARC3: Archival started ARC0: STARTING ARCH PROCESSES COMPLETE ARC0: Becoming the 'no FAL' ARCH ARC0: Becoming the 'no SRL' ARCH ARC1: Becoming the heartbeat ARCH Fri Apr 15 22:44:36 2011 ORA-16198: LGWR received timedout error from KSR Errors in file /home/oracle/app/oracle/diag/rdbms/prod/prod/trace/prod_lgwr_4066.trc: ORA-16198: Timeout incurred on internal channel during remote archival LGWR: Error 16198 verifying archivelog destination LOG_ARCHIVE_DEST_2 Destination LOG_ARCHIVE_DEST_2 is UNSYNCHRONIZED LGWR: Continuing... Thread 1 advanced to log sequence 36 (thread open) Thread 1 opened at log sequence 36 Current log# 3 seq# 36 mem# 0: /addtl/oracle/oradata/PROD/onlinelog/o1_mf_3_6t3jnv7s_.log Current log# 3 seq# 36 mem# 1: /addtl/oracle/flash_recovery_area/PROD/onlinelog/o1_mf_3_6t3jnxcg_.log Successful open of redo thread 1
I then :
SQL> alter system switch logfile; System altered. SQL>
and see :
Fri Apr 15 22:45:38 2011 NSS2 started with pid=29, OS id=4225 Fri Apr 15 22:46:07 2011 ORA-16198: LGWR received timedout error from KSR Errors in file /home/oracle/app/oracle/diag/rdbms/prod/prod/trace/prod_lgwr_4066.trc: ORA-16198: Timeout incurred on internal channel during remote archival Error 16198 for archive log file 1 to 'stdby' LGWR: Failed to archive log 1 thread 1 sequence 37 (16198) Thread 1 advanced to log sequence 37 (LGWR switch) Current log# 1 seq# 37 mem# 0: /addtl/oracle/oradata/PROD/onlinelog/o1_mf_1_6t3jnm57_.log Current log# 1 seq# 37 mem# 1: /addtl/oracle/flash_recovery_area/PROD/onlinelog/o1_mf_1_6t3jnn4d_.log Fri Apr 15 22:46:13 2011 Archived Log entry 56 added for thread 1 sequence 36 ID 0x988c490 dest 1:
Soon, I will learn how to perform "maintenance" on the primary with the standby shutdown.
.
.
Returning to this thread ....
I perform recovery on the standby :
SQL> shutdown
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup mount
ORACLE instance started.
Total System Global Area 836976640 bytes
Fixed Size 1339740 bytes
Variable Size 494931620 bytes
Database Buffers 335544320 bytes
Redo Buffers 5160960 bytes
Database mounted.
SQL> !pwd
/home/oracle/app/oracle/diag/rdbms/stdby/stdby/trace
SQL> recover automatic standby database;
ORA-00279: change 857509 generated at 04/15/2011 22:47:47 needed for thread 1
ORA-00289: suggestion :
/addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_38_%u_.arc
ORA-00280: change 857509 for thread 1 is in sequence #38
ORA-00278: log file
'/addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_38_%u_.ar
c' no longer needed for this recovery
ORA-00308: cannot open archived log
'/addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_38_%u_.ar
c'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Specify log: {=suggested | filename | AUTO | CANCEL}
and monitor it from the stdby alert.log :
Fri Apr 15 22:52:11 2011 ALTER DATABASE RECOVER automatic standby database Media Recovery Start Serial Media Recovery started Managed Standby Recovery not using Real Time Apply Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_10_6t66l9o7_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_11_6t66kp40_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_12_6t66nrbs_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_13_6t66htwv_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_14_6t66pmn5_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_15_6t66odb9_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_16_6t66tj5m_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_17_6t66svwc_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_18_6t678fyd_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_19_6t67cbgg_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_20_6t67bq2d_.arc Fri Apr 15 22:52:21 2011 Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_21_6t67ftgj_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_22_6t687w1g_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_23_6t687w19_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_24_6t688qdf_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_11/o1_mf_1_25_6t689byn_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_26_6tjol0jr_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_27_6tjokddr_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_28_6tjonl8w_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_29_6tjoq9v5_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_30_6tjosydp_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_31_6tjowowv_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_32_6tjoyvg2_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_33_6tjp21o3_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_34_6tjpppjj_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_35_6tjpopc6_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_36_6tjpqch2_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_37_6tjprmmt_.arc Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_38_%u_.arc Errors with log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_15/o1_mf_1_38_%u_.arc ORA-279 signalled during: ALTER DATABASE RECOVER automatic standby database ...
So far so good .....
.
.
.
Updates to this "voyage of discovery" to follow ....
.
.
UPDATE : Adding a Standby Redo Log on the Standby :
SQL> recover managed standby database disconnect from session;
Media recovery complete.
SQL> recover managed standby database cancel;
Media recovery complete.
SQL> select group#, status, bytes/1048576 from v$log;
GROUP# STATUS BYTES/1048576
---------- ---------------- -------------
1 CLEARING_CURRENT 50
3 CLEARING 50
2 CLEARING 50
SQL> select group#, status, bytes/1048576 from v$standby_log;
no rows selected
SQL> alter database add standby logfile size 50M;
Database altered.
SQL> select group#, status, bytes/1048576 from v$standby_log;
GROUP# STATUS BYTES/1048576
---------- ---------- -------------
4 UNASSIGNED 50
SQL> recover managed standby database disconnect from session;
Media recovery complete.
SQL>
following which the messages are :
Sat Apr 16 13:16:16 2011 ALTER DATABASE RECOVER managed standby database disconnect from session Attempt to start background Managed Standby Recovery process (stdby) Sat Apr 16 13:16:16 2011 MRP0 started with pid=27, OS id=4392 MRP0: Background Managed Standby Recovery process started (stdby) Serial Media Recovery started Managed Standby Recovery not using Real Time Apply Waiting for all non-current ORLs to be archived... All non-current ORLs have been archived. Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_16/o1_mf_1_74_6tl9j689_.arc Media Recovery Waiting for thread 1 sequence 75 Completed: ALTER DATABASE RECOVER managed standby database disconnect from session Sat Apr 16 13:16:34 2011 ALTER DATABASE RECOVER managed standby database cancel Sat Apr 16 13:16:35 2011 MRP0: Background Media Recovery cancelled with status 16037 Errors in file /home/oracle/app/oracle/diag/rdbms/stdby/stdby/trace/stdby_mrp0_4392.trc: ORA-16037: user requested cancel of managed recovery operation Recovery interrupted! Errors in file /home/oracle/app/oracle/diag/rdbms/stdby/stdby/trace/stdby_mrp0_4392.trc: ORA-16037: user requested cancel of managed recovery operation MRP0: Background Media Recovery process shutdown (stdby) Waiting for MRP0 pid 4392 to terminate Managed Standby Recovery Canceled (stdby) Completed: ALTER DATABASE RECOVER managed standby database cancel Sat Apr 16 13:16:40 2011 RFS[94]: Assigned to RFS process 4394 RFS[94]: Identified database type as 'physical standby': Client is LGWR SYNC pid 3274 Primary database is in MAXIMUM AVAILABILITY mode Standby controlfile consistent with primary Standby controlfile consistent with primary RFS[94]: No standby redo logfiles selected (reason:7) Errors in file /home/oracle/app/oracle/diag/rdbms/stdby/stdby/trace/stdby_rfs_4394.trc: ORA-16086: Redo data cannot be written to the standby redo log Sat Apr 16 13:17:02 2011 RFS[95]: Assigned to RFS process 4415 RFS[95]: Identified database type as 'physical standby': Client is ARCH pid 3349 Sat Apr 16 13:17:22 2011 RFS[96]: Assigned to RFS process 4417 RFS[96]: Identified database type as 'physical standby': Client is ARCH pid 3363 RFS[96]: Opened log for thread 1 sequence 75 dbid 159971472 branch 748133139 Archived Log entry 69 added for thread 1 sequence 75 rlc 748133139 ID 0x988c490 dest 2: Sat Apr 16 13:17:39 2011 alter database add standby logfile size 50M Completed: alter database add standby logfile size 50M Sat Apr 16 13:17:42 2011 RFS[97]: Assigned to RFS process 4421 RFS[97]: Identified database type as 'physical standby': Client is ARCH pid 3349 Sat Apr 16 13:18:03 2011 ALTER DATABASE RECOVER managed standby database disconnect from session Attempt to start background Managed Standby Recovery process (stdby) Sat Apr 16 13:18:03 2011 MRP0 started with pid=28, OS id=4433 MRP0: Background Managed Standby Recovery process started (stdby) Sat Apr 16 13:18:08 2011 RFS[98]: Assigned to RFS process 4431 RFS[98]: Identified database type as 'physical standby': Client is LGWR SYNC pid 3274 Primary database is in MAXIMUM AVAILABILITY mode Standby controlfile consistent with primary Standby controlfile consistent with primary RFS[98]: Selected log 4 for thread 1 sequence 77 dbid 159971472 branch 748133139 Serial Media Recovery started Managed Standby Recovery not using Real Time Apply Waiting for all non-current ORLs to be archived... All non-current ORLs have been archived. Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_16/o1_mf_1_75_6tl9m2fl_.arc Media Recovery Waiting for thread 1 sequence 76 Completed: ALTER DATABASE RECOVER managed standby database disconnect from session Sat Apr 16 13:18:29 2011 RFS[99]: Assigned to RFS process 4435 RFS[99]: Identified database type as 'physical standby': Client is ARCH pid 3363 RFS[99]: No standby redo logfiles of size 81 blocks available RFS[99]: Opened log for thread 1 sequence 76 dbid 159971472 branch 748133139 Archived Log entry 70 added for thread 1 sequence 76 rlc 748133139 ID 0x988c490 dest 2: Sat Apr 16 13:18:34 2011 Media Recovery Log /addtl/oracle/flash_recovery_area/STDBY/archivelog/2011_04_16/o1_mf_1_76_6tl9o5bb_.arc Media Recovery Waiting for thread 1 sequence 77 (in transit)
So, now my Standby Database does have a Standby Redo Log.
Note : I was able to work without a Standby Redo Log but I had almost no transactions generating Redo.
.
.
.
10 April, 2011
DETERMINISTIC Functions -- 2
Following up on my previous post, I now take up a Deterministic Function defined on a date column.
Let's see what the tkprof show :
There are 19 rows with 5 distinct dates but the function was executed 12 times ! Isn't there a mismatch ? Should the function have been executed 19 times or 5 times ?
First, I setup the test data :
SQL> create or replace function ten_days_ago_date(date_in date) return date DETERMINISTICI now have 19 rows and will be applying a DETERMINISTIC function to the date column "created" when I query the table.
2 as
3 deducted_date date;
4 begin
5 select date_in - 10 into deducted_date from dual;
6 return deducted_date;
7 end;
8 /
Function created.
SQL>
SQL>
SQL> drop table my_objects purge;
Table dropped.
SQL>
SQL> create table my_objects (obj_id number , obj_name varchar2(30), created date);
Table created.
SQL>
SQL> insert into my_objects
2 select object_id, object_name,created
3 from dba_objects
4 where owner in ('HEMANT','SCOTT')
5 /
19 rows created.
SQL>
SQL> exec dbms_session.session_trace_enable;
PL/SQL procedure successfully completed.
SQL> select obj_id, created, ten_days_ago_date(created)
2 from my_objects
3 order by created
4 /
OBJ_ID CREATED TEN_DAYS_
---------- --------- ---------
73180 13-AUG-09 03-AUG-09
73179 13-AUG-09 03-AUG-09
73181 13-AUG-09 03-AUG-09
73182 13-AUG-09 03-AUG-09
73183 13-AUG-09 03-AUG-09
73184 13-AUG-09 03-AUG-09
82749 06-JUL-10 26-JUN-10
82748 06-JUL-10 26-JUN-10
82751 06-JUL-10 26-JUN-10
85339 14-OCT-10 04-OCT-10
85340 14-OCT-10 04-OCT-10
85341 14-OCT-10 04-OCT-10
85344 05-FEB-11 26-JAN-11
85346 05-FEB-11 26-JAN-11
85429 05-APR-11 26-MAR-11
85434 09-APR-11 30-MAR-11
85439 09-APR-11 30-MAR-11
85444 09-APR-11 30-MAR-11
85451 09-APR-11 30-MAR-11
19 rows selected.
SQL> exec dbms_session.session_trace_disable;
PL/SQL procedure successfully completed.
SQL>
I have 6 rows with the date '13-AUG-09', 3 of '06-JUL-10', 3 of '14-OCT-10', 3 of '05-FEB-11' and 4 of '09-APR-11'.
select obj_id, created, ten_days_ago_date(created)
from my_objects
order by created
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.02 0.23 0 1 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 3 0.01 0.02 0 7 0 19
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 5 0.04 0.25 0 8 0 19
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 184
Rows Row Source Operation
------- ---------------------------------------------------
19 SORT ORDER BY (cr=7 pr=0 pw=0 time=0 us cost=4 size=418 card=19)
19 TABLE ACCESS FULL MY_OBJECTS (cr=7 pr=0 pw=0 time=576 us cost=3 size=418 card=19)
SQL ID: 7dq8qm13md0cf
Plan Hash: 1388734953
SELECT :B1 - 10
FROM
DUAL
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 12 0.00 0.00 0 0 0 0
Fetch 12 0.00 0.00 0 0 0 12
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 25 0.00 0.00 0 0 0 12
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 184 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 FAST DUAL (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)
There are 19 rows with 5 distinct dates but the function was executed 12 times ! Isn't there a mismatch ? Should the function have been executed 19 times or 5 times ?
.
.
.
But wait ..... a DATE datatype in Oracle captures Hours:Minutes:Seconds besides Day:Month:Year. Therefore, two rows with the "Date" '09-APR-11' may not necessarily have really the same Date Value stored in the database !
I rerun the query but also print the Hours:Minutes:Seconds and capture the Binds in the trace file.
Here's the tkprof output :
If I look at the raw trace file, however, I can find the points of execution :
SQL> exec dbms_session.session_trace_enable(waits=>TRUE, binds=>TRUE);
PL/SQL procedure successfully completed.
SQL> select obj_id, created, ten_days_ago_date(created), to_char(created,'DD-MON-RR HH24:MI:SS')
2 from my_objects
3 order by created
4 /
OBJ_ID CREATED TEN_DAYS_ TO_CHAR(CREATED,'DD-MON-RRH
---------- --------- --------- ---------------------------
73180 13-AUG-09 03-AUG-09 13-AUG-09 23:35:45
73179 13-AUG-09 03-AUG-09 13-AUG-09 23:35:45
73181 13-AUG-09 03-AUG-09 13-AUG-09 23:35:45
73182 13-AUG-09 03-AUG-09 13-AUG-09 23:35:45
73183 13-AUG-09 03-AUG-09 13-AUG-09 23:35:45
73184 13-AUG-09 03-AUG-09 13-AUG-09 23:35:45
82749 06-JUL-10 26-JUN-10 06-JUL-10 14:28:11
82748 06-JUL-10 26-JUN-10 06-JUL-10 14:28:11
82751 06-JUL-10 26-JUN-10 06-JUL-10 14:28:11
85339 14-OCT-10 04-OCT-10 14-OCT-10 01:27:25
85340 14-OCT-10 04-OCT-10 14-OCT-10 01:40:57
85341 14-OCT-10 04-OCT-10 14-OCT-10 02:18:35
85344 05-FEB-11 26-JAN-11 05-FEB-11 08:04:52
85346 05-FEB-11 26-JAN-11 05-FEB-11 08:18:05
85429 05-APR-11 26-MAR-11 05-APR-11 07:43:23
85434 09-APR-11 30-MAR-11 09-APR-11 08:12:42
85439 09-APR-11 30-MAR-11 09-APR-11 08:39:13
85444 09-APR-11 30-MAR-11 09-APR-11 21:28:01
85451 09-APR-11 30-MAR-11 09-APR-11 21:58:17
19 rows selected.
SQL> exec dbms_session.session_trace_disable;
PL/SQL procedure successfully completed.
SQL>
Here's the tkprof output :
SQL ID: 7dq8qm13md0cf
Plan Hash: 1388734953
SELECT :B1 - 10
FROM
DUAL
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 12 0.00 0.00 0 0 0 0
Fetch 12 0.00 0.00 0 0 0 12
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 25 0.00 0.00 0 0 0 12
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 184 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 FAST DUAL (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)
If I look at the raw trace file, however, I can find the points of execution :
=====================That adds up to 12 executions. One execution afresh each time the retrieved value changes. Note : The sequence of values that appear in the trace file isn't exactly the same as that in the SQL output. The trace file shows how the function is applied to each row fetched *before* the rows are sorted. The function is applied before the ORDER BY is applied.
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557311398 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
PARSE #2:c=0,e=309,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557311362
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="8/13/2009 23:35:45"
EXEC #2:c=0,e=554,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557312312
FETCH #2:c=1000,e=369,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557312847
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='FAST DUAL (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)'
CLOSE #2:c=0,e=32,dep=1,type=3,tim=1302411557313358
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557314018 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="7/6/2010 14:28:11"
EXEC #2:c=0,e=467,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557314344
FETCH #2:c=0,e=223,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557314745
CLOSE #2:c=0,e=9,dep=1,type=3,tim=1302411557314880
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557315047 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="10/14/2010 1:27:25"
EXEC #2:c=0,e=349,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557315361
FETCH #2:c=0,e=35,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557315478
CLOSE #2:c=0,e=13,dep=1,type=3,tim=1302411557315639
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557315868 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="10/14/2010 1:40:57"
EXEC #2:c=0,e=331,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557316162
FETCH #2:c=0,e=132,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557316371
CLOSE #2:c=0,e=8,dep=1,type=3,tim=1302411557316486
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557316780 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="10/14/2010 2:18:35"
EXEC #2:c=0,e=360,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557317077
FETCH #2:c=0,e=37,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557317208
CLOSE #2:c=0,e=7,dep=1,type=3,tim=1302411557317284
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557317405 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="2/5/2011 8:4:52"
EXEC #2:c=1999,e=1239,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557318621
FETCH #2:c=0,e=229,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557318947
CLOSE #2:c=0,e=8,dep=1,type=3,tim=1302411557319086
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557319365 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="2/5/2011 8:18:5"
EXEC #2:c=1000,e=323,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557319637
FETCH #2:c=0,e=216,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557320053
CLOSE #2:c=0,e=31,dep=1,type=3,tim=1302411557320250
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557321372 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="4/5/2011 7:43:23"
EXEC #2:c=1000,e=479,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557321641
FETCH #2:c=0,e=233,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557322107
CLOSE #2:c=0,e=32,dep=1,type=3,tim=1302411557322321
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557323024 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="4/9/2011 21:28:1"
EXEC #2:c=0,e=264,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557323236
FETCH #2:c=0,e=145,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557323463
CLOSE #2:c=0,e=79,dep=1,type=3,tim=1302411557323718
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557323946 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="4/9/2011 8:39:13"
EXEC #2:c=0,e=209,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557324117
FETCH #2:c=0,e=35,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557324221
CLOSE #2:c=0,e=38,dep=1,type=3,tim=1302411557324259
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557324448 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="4/9/2011 8:12:42"
EXEC #2:c=1000,e=305,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557324717
FETCH #2:c=0,e=45,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557325018
CLOSE #2:c=0,e=8,dep=1,type=3,tim=1302411557325106
=====================
PARSING IN CURSOR #2 len=25 dep=1 uid=184 oct=3 lid=184 tim=1302411557325243 hv=1194754446 ad='2d7c4228' sqlid='7dq8qm13md0cf'
SELECT :B1 - 10 FROM DUAL
END OF STMT
BINDS #2:
Bind#0
oacdty=12 mxl=07(07) mxlc=00 mal=00 scl=00 pre=00
oacflg=13 fl2=206001 frm=00 csi=00 siz=8 off=0
kxsbbbfp=006a49a8 bln=07 avl=07 flg=09
value="4/9/2011 21:58:17"
EXEC #2:c=0,e=201,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=1388734953,tim=1302411557325415
FETCH #2:c=0,e=28,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,plh=1388734953,tim=1302411557325493
CLOSE #2:c=0,e=149,dep=1,type=3,tim=1302411557334524
.
.
.
05 April, 2011
DETERMINISTIC Functions
In my opinion, DETERMINISTIC functions are not very well explained. Some DBAs and Developers know that a Function must be DETERMINISTIC if it is to be used to create a Function Based Index. Also, common understanding is that a Function can be DETERMINISTIC if it is guaranteed to return always return the same output value if the input value supplied is not changed.
Some explanation is in the documentation on the CREATE FUNCTION command.
Yet, how does Oracle optimise the execution of a DETERMINISTIC function ? The documentation says "When the database encounters a deterministic function in one of these contexts, it attempts to use previously calculated results when possible rather than reexecuting the function."
Jonathan Lewis has also explored DETERMINSTIC functions here.
I decided to run my own tests here. I created a DETERMINISTIC function and had it executed once for each row in a 16-row result set :
The trace file shows that the function is actually executed 16 times.
We know that every time we pass the same value to "trunc(:b1/100)", the result will always be the same. This function had to be executed 16 times because each value passed to the function was different -- each time a new OBJ_ID was being passed.
Some explanation is in the documentation on the CREATE FUNCTION command.
"Indicates that the function returns the same result value whenever it is called with the same values for its parameters."
Yet, how does Oracle optimise the execution of a DETERMINISTIC function ? The documentation says "When the database encounters a deterministic function in one of these contexts, it attempts to use previously calculated results when possible rather than reexecuting the function."
Jonathan Lewis has also explored DETERMINSTIC functions here.
I decided to run my own tests here. I created a DETERMINISTIC function and had it executed once for each row in a 16-row result set :
SQL> create or replace function div_by_hundred (value_in number) return number DETERMINISTIC
2 as
3 divided_by_hundred number;
4 begin
5 select trunc(value_in/100) into divided_by_hundred from dual;
6 return divided_by_hundred;
7 end;
8 /
Function created.
SQL>
SQL>
SQL> drop table my_objects purge;
Table dropped.
SQL>
SQL> create table my_objects (obj_id number , obj_name varchar2(30), created date);
Table created.
SQL>
SQL> insert into my_objects
2 select object_id, object_name,created
3 from dba_objects
4 where owner in ('HEMANT','SCOTT')
5 /
16 rows created.
SQL>
SQL> exec dbms_session.session_trace_enable;
PL/SQL procedure successfully completed.
SQL> select obj_id, div_by_hundred(obj_id)
2 from my_objects
3 order by obj_id
4 /
OBJ_ID DIV_BY_HUNDRED(OBJ_ID)
---------- ----------------------
73179 731
73180 731
73181 731
73182 731
73183 731
73184 731
82748 827
82749 827
82751 827
85339 853
85340 853
OBJ_ID DIV_BY_HUNDRED(OBJ_ID)
---------- ----------------------
85341 853
85344 853
85346 853
85429 854
85433 854
16 rows selected.
SQL> exec dbms_session.session_trace_disable;
PL/SQL procedure successfully completed.
SQL>
The trace file shows that the function is actually executed 16 times.
select obj_id, div_by_hundred(obj_id)
from my_objects
order by obj_id
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.02 0.04 0 1 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 3 0.01 0.01 0 7 0 16
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 5 0.03 0.06 0 8 0 16
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 184
Rows Row Source Operation
------- ---------------------------------------------------
16 SORT ORDER BY (cr=7 pr=0 pw=0 time=0 us cost=4 size=208 card=16)
16 TABLE ACCESS FULL MY_OBJECTS (cr=7 pr=0 pw=0 time=120 us cost=3 size=208 card=16)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 0.08 0.10
********************************************************************************
SQL ID: dd7zz37sxfcsc
Plan Hash: 1388734953
SELECT TRUNC(:B1 /100)
FROM
DUAL
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 16 0.00 0.00 0 0 0 0
Fetch 16 0.00 0.00 0 0 0 16
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 33 0.00 0.00 0 0 0 16
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 184 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 FAST DUAL (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)
********************************************************************************
We know that every time we pass the same value to "trunc(:b1/100)", the result will always be the same. This function had to be executed 16 times because each value passed to the function was different -- each time a new OBJ_ID was being passed.
So, what happens if the same OBJ_ID is passed to the function each time ?
This appears in the trace file :
Now, the function is executed only once ! Apparently, Oracle actually "peeks" (for want of a better word) at the value passed to the function. If it is the same as the last value (or one of the last four values ?-- see Jonathan Lewis's last paragraph in his note), it decides to not re-execute the function. That also means, that it holds the return value from the previous execution and re-uses that value -- to be returned again for the next row.
SQL> UPDATE my_objects set obj_id = 1000000;
16 rows updated.
SQL> commit;
Commit complete.
SQL>
SQL> pause Press ENTER to proceed with new session
Press ENTER to proceed with new session
SQL> connect hemant/hemant
Connected.
SQL>
SQL> exec dbms_session.session_trace_enable;
PL/SQL procedure successfully completed.
SQL> select obj_id, div_by_hundred(obj_id)
2 from my_objects
3 order by obj_id
4 /
OBJ_ID DIV_BY_HUNDRED(OBJ_ID)
---------- ----------------------
1000000 10000
1000000 10000
1000000 10000
1000000 10000
1000000 10000
1000000 10000
1000000 10000
1000000 10000
1000000 10000
1000000 10000
1000000 10000
OBJ_ID DIV_BY_HUNDRED(OBJ_ID)
---------- ----------------------
1000000 10000
1000000 10000
1000000 10000
1000000 10000
1000000 10000
16 rows selected.
SQL> exec dbms_session.session_trace_disable;
PL/SQL procedure successfully completed.
SQL>
This appears in the trace file :
select obj_id, div_by_hundred(obj_id)
from my_objects
order by obj_id
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 3 0.00 0.04 0 7 0 16
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 5 0.01 0.05 0 7 0 16
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 184
Rows Row Source Operation
------- ---------------------------------------------------
16 SORT ORDER BY (cr=7 pr=0 pw=0 time=0 us cost=4 size=208 card=16)
16 TABLE ACCESS FULL MY_OBJECTS (cr=7 pr=0 pw=0 time=360 us cost=3 size=208 card=16)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
Disk file operations I/O 1 0.00 0.00
SQL*Net message from client 3 0.05 0.08
********************************************************************************
SQL ID: dd7zz37sxfcsc
Plan Hash: 1388734953
SELECT TRUNC(:B1 /100)
FROM
DUAL
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 1 0.00 0.00 0 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 0 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 184 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 FAST DUAL (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)
********************************************************************************
Now, the function is executed only once ! Apparently, Oracle actually "peeks" (for want of a better word) at the value passed to the function. If it is the same as the last value (or one of the last four values ?-- see Jonathan Lewis's last paragraph in his note), it decides to not re-execute the function. That also means, that it holds the return value from the previous execution and re-uses that value -- to be returned again for the next row.
Will this behaviour hold true with DATEs ?
Stay tuned. .......
.
.
.
Subscribe to:
Posts (Atom)