27 April, 2010

Oracle Database History

As "Noons" (Nuno Souto) had to correct me in my last post, I searched for and found the Oracle Magazine article on 30 years of Oracle History.
UPDATE : That Magazine URL no longer exists.  The article is now here.

.
.
.

25 April, 2010

AutoTune Undo

Rollback segments (aka "Undo segments") were introduced in -- V4 (corrected, as pointed out by Noons). They provide two key implementations :
a. The ability to rollback a transaction -- whether intentionally or to handle transaction / session / process / instance / server failure
b. Multi Version Read Consistency

In 9i, Oracle introduced Automatic Undo Management whereby the database instance itself adds and drops undo segments and retains undo information for a duration ("UNDO_RETENTION") specified by the DBA.

In 10g (or was it 10gR2), Oracle [quietly] added _undo_autotune. This allows the database instance to extend and override (ignore) "UNDO_RETENTION". This particularly kicks in when the datafiles for the Undo Tablespace are set to AUTOEXTEND ON.

There is very good reason for allowing the Undo Retention duration to by "dynamic". Queries that are long running while DML is concurrently being executed against the same tables can continue to expect to be able to read a consistent image -- even if they exceed the expected Undo Retention duration. Oracle, on determining that queries are running longer, also retains Undo information longer ! Smart, isn't it ?

But there's a serious limitation to this approach when you think about it. Say you have a database with 5000 tables, 100 concurrent queries and 80 concurrent transactions at any time. How will Oracle track queries against transactions that modify data being used by the queries ? Ideally it would have to track each query's start time and the list of all the tables being referenced in the query and then maintain a list of transactions against those tables and modify undo retention for those transactions only. In fact, ideally it should modify undo retention only if those transactions update the same rows that the queries are or will be accessing ! This becomes a very tall order.

So, it's "automatic"s engine takes a short cut. It tracks query durations and periodically updates itself with information about the longest running query -- irrespective of which tables the query accesses.
For all Oracle knows, the longest running query may be against a table [or set of tables] that have not been updated in the past 6 minutes or 6 hours or 6 days or 6 months and will not be updated in the next 6 ..... Therefore, truth be told, this query does NOT need undo retention -- and does not need undo retention to be extended at all. Yet, the database engine will extend undo retention for all transactions against all the other tables in the same database instance, for the duration of that query.

With some more thought, you can then see the implications of this -- undo retention grows, undo space usage increases rapidly ! Completely unnecessarily.

AutoTuned undo does make sense where queries and transactions hit the same tables (yes, I am repeating this assertion). It does not help and actually causes more adverse issues where there is no commonality between long running queries and transactions.


In this small test, I ran a long running query


select col_1, slow_access from long_running_query_table;


concurrently with these transactions (from another session) :


insert into dummy_txn_table values (i);
update dummy_txn_table set col_1 = i+1;
commit;


even with a sleep of 15seconds between each transaction.

I then monitored Undo space usage with this query :


select to_char(begin_time, 'DD-MON HH24:MI') Begin_Time, to_char(end_time, 'DD-MON HH24:MI') End_Time,
undoblks, txncount, maxconcurrency, activeblks, expiredblks, tuned_undoretention, maxquerylen
from v$undostat order by begin_time


The query ran from 00:20 to 02:47 (at which point it was "killed").
The transactions ran upto 05:53.

The v$undostat figures were :

BEGIN_TIME END_TIME UNDOBLKS TXNCOUNT MAXCONCURRENCY ACTIVEBLKS EXPIREDBLKS TUNED_UNDORETENTION MAXQUERYLEN
------------ ------------ ---------- ---------- -------------- ---------- ----------- ------------------- -----------
23-APR 00:11 23-APR 00:21 179 118 1 160 6496 900 0
23-APR 00:21 23-APR 00:31 247 228 1 160 5216 1617 777
23-APR 00:31 23-APR 00:41 263 92 1 160 3408 2219 1377
23-APR 00:41 23-APR 00:51 283 108 1 160 3384 2821 1981
23-APR 00:51 23-APR 01:01 329 149 3 160 2720 3421 2581
23-APR 01:01 23-APR 01:11 322 272 1 160 2336 4021 3181
23-APR 01:11 23-APR 01:21 315 102 1 160 2208 4622 3781
23-APR 01:21 23-APR 01:31 355 116 1 160 2072 5225 4382
23-APR 01:31 23-APR 01:41 349 94 2 160 1648 5825 4985
23-APR 01:41 23-APR 01:51 342 104 1 160 624 6425 5585
23-APR 01:51 23-APR 02:01 430 248 3 160 368 7026 6186
23-APR 02:01 23-APR 02:11 400 97 1 160 240 7626 6786
23-APR 02:11 23-APR 02:21 465 116 1 160 240 8229 7389
23-APR 02:21 23-APR 02:31 429 94 1 160 240 8830 7990
23-APR 02:31 23-APR 02:41 486 105 1 160 240 9431 8590
23-APR 02:41 23-APR 02:51 421 94 1 160 240 10031 9191
23-APR 02:51 23-APR 03:01 446 274 3 160 5248 900 0
23-APR 03:01 23-APR 03:11 469 106 2 160 2824 900 0
23-APR 03:11 23-APR 03:21 407 168 1 160 3088 900 0
23-APR 03:21 23-APR 03:31 454 97 3 160 3472 900 0
23-APR 03:31 23-APR 03:41 452 111 1 160 3088 900 0
23-APR 03:41 23-APR 03:51 485 92 1 160 3344 900 0
23-APR 03:51 23-APR 04:01 512 175 3 160 3472 900 0
23-APR 04:01 23-APR 04:11 484 99 2 160 2576 900 0
23-APR 04:11 23-APR 04:21 544 171 2 160 3328 900 0
23-APR 04:21 23-APR 04:31 579 110 2 160 2312 900 0
23-APR 04:31 23-APR 04:41 626 97 3 160 1928 900 0
23-APR 04:41 23-APR 04:51 522 104 1 160 1928 900 0
23-APR 04:51 23-APR 05:01 613 151 3 160 1920 900 0
23-APR 05:01 23-APR 05:11 565 176 1 160 2304 900 0
23-APR 05:11 23-APR 05:21 609 95 1 160 2312 900 0
23-APR 05:21 23-APR 05:31 664 134 3 160 2056 900 0
23-APR 05:31 23-APR 05:41 572 92 1 160 2824 900 0
23-APR 05:41 23-APR 05:50 536 91 1 160 2824 900 0



You can see how TUNED_UNDORETENTION kept increasing upto 02:51. After the query was killed, a large number of Undo blocks were suddenly "Expired" and TUNED_UNDORETENTION dropped back to 900 (the "default" value set at the instance level).

The query and the transactions were against completely unrelated tables. Yet, the presence of the query caused all undo for all transactions to be retained in the undo segments much longer, requiring more undo blocks !

.
.
.

14 April, 2010

SQLs in PLSQL -- 2

Building on the demo PLSQL procedure in my previous SQLs in PLSQL post, I show how Oracle converts 3 "similar" statements to the "same" statement !

If I create 3 "similar" INSERT statements in my procedure and execute it as :

SQL> create or replace procedure PLSQL_SQL_bind_2
2 as
3 l_entry_id number;
4 l_entry_text varchar2(500);
5
6 cursor c1 is
7 select object_id, owner||object_name from dba_objects where object_type = 'VIEW' order by object_id;
8
9 begin
10 open c1;
11 loop
12 fetch c1 into l_entry_id,l_entry_text;
13 exit when c1%NOTFOUND;
14 insert into log_table values (l_entry_id, l_entry_text);
15 l_entry_id := l_entry_id+100000;
16 insert into LOG_TABLE VALUES
17 (l_entry_id, l_entry_text);
18 l_entry_id := l_entry_id + 200000;
19 insert into
20 Log_Table
21 Values
22 (L_Entry_ID,
23 L_Entry_TEXT);
24 end loop;
25 commit;
26 end;
27 /

Procedure created.

SQL>
SQL> select count(*) from dba_objects where object_type = 'VIEW';

COUNT(*)
----------
3697

SQL> alter session set sql_trace=TRUE;

Session altered.

SQL> execute PLSQL_sql_bind_2;

PL/SQL procedure successfully completed.

SQL>


I find that tkprof of the Trace shows :

SELECT OBJECT_ID, OWNER||OBJECT_NAME
FROM
DBA_OBJECTS WHERE OBJECT_TYPE = 'VIEW' ORDER BY OBJECT_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 3698 0.25 0.24 0 5407 0 3697
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3700 0.26 0.25 0 5407 0 3697

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS

INSERT INTO LOG_TABLE
VALUES
(:B2 , :B1 )


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 11091 0.43 0.40 0 208 12239 11091
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 11094 0.43 0.40 0 208 12239 11091

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS


Exactly the same "INSERT" statement executed 11,091 (i.e. 3697*3) times !
But why are there 3 different PARSEs ?

This is what the raw Trace file shows :

PARSING IN CURSOR #12 len=99 dep=1 uid=64 oct=3 lid=64 tim=1241463209324952 hv=608974888 ad='8f7363d0'
SELECT OBJECT_ID, OWNER||OBJECT_NAME FROM DBA_OBJECTS WHERE OBJECT_TYPE = 'VIEW' ORDER BY OBJECT_ID
END OF STMT
PARSE #12:c=12998,e=12188,p=0,cr=2,cu=0,mis=1,r=0,dep=1,og=1,tim=1241463209324936
EXEC #12:c=0,e=131,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1241463209325440
FETCH #12:c=219967,e=215466,p=0,cr=5407,cu=0,mis=0,r=1,dep=1,og=1,tim=1241463209541097

PARSING IN CURSOR #10 len=41 dep=1 uid=64 oct=2 lid=64 tim=1241463209542024 hv=4147238877 ad='942837f8'
INSERT INTO LOG_TABLE VALUES (:B2 , :B1 )
END OF STMT
PARSE #10:c=0,e=441,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,tim=1241463209542012

PARSING IN CURSOR #13 len=227 dep=2 uid=0 oct=3 lid=0 tim=1241463209543228 hv=2190775527 ad='8f5fb7c8'
select u.name,o.name, t.update$, t.insert$, t.delete$, t.enabled from obj$ o,user$ u,trigger$ t where t.baseobject=:1 and t.obj#=o.obj# and o.owner#=u.user# and bitand(property,16)=0 and bitand(property,8)=0 order by o.obj#
END OF STMT
PARSE #13:c=0,e=416,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=4,tim=1241463209543221
EXEC #13:c=3999,e=4077,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=4,tim=1241463209547660
FETCH #13:c=0,e=105,p=0,cr=1,cu=0,mis=0,r=0,dep=2,og=4,tim=1241463209547905

EXEC #10:c=7998,e=7968,p=0,cr=2,cu=22,mis=1,r=1,dep=1,og=1,tim=1241463209550338

PARSING IN CURSOR #2 len=41 dep=1 uid=64 oct=2 lid=64 tim=1241463209550701 hv=4147238877 ad='942837f8'
INSERT INTO LOG_TABLE VALUES (:B2 , :B1 )
END OF STMT
PARSE #2:c=0,e=115,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1241463209550695
EXEC #2:c=1000,e=153,p=0,cr=1,cu=3,mis=0,r=1,dep=1,og=1,tim=1241463209551180

PARSING IN CURSOR #3 len=41 dep=1 uid=64 oct=2 lid=64 tim=1241463209551343 hv=4147238877 ad='942837f8'
INSERT INTO LOG_TABLE VALUES (:B2 , :B1 )
END OF STMT
PARSE #3:c=0,e=29,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1241463209551338
EXEC #3:c=0,e=113,p=0,cr=1,cu=3,mis=0,r=1,dep=1,og=1,tim=1241463209551868

FETCH #12:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=1241463209552009
EXEC #10:c=0,e=39,p=0,cr=0,cu=1,mis=0,r=1,dep=1,og=1,tim=1241463209552170
EXEC #2:c=0,e=28,p=0,cr=0,cu=1,mis=0,r=1,dep=1,og=1,tim=1241463209552298
EXEC #3:c=0,e=25,p=0,cr=0,cu=1,mis=0,r=1,dep=1,og=1,tim=1241463209552414
FETCH #12:c=0,e=7,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=1241463209552517
EXEC #10:c=0,e=31,p=0,cr=0,cu=1,mis=0,r=1,dep=1,og=1,tim=1241463209552631
EXEC #2:c=0,e=38,p=0,cr=0,cu=1,mis=0,r=1,dep=1,og=1,tim=1241463209552760
EXEC #3:c=0,e=24,p=0,cr=0,cu=1,mis=0,r=1,dep=1,og=1,tim=1241463209552873


with the Cursors repeatedly being executed as :

FETCH #12
EXEC #10
EXEC #2
EXEC #3



Cursor 12 is the SQL for the PLSQL Cursor c1 in my procedure.
Cursors 10, 2 and 3 are the three INSERT statements.
Note that all three have the same HashValue (hv=4147238877) !

Oracle's PLSQL engine converted the 3 INSERT statements (which are literally dissimilar) into the exactly same SQL statement which needed a Hard Parse only once and Soft Parse twice thereafter. Then, for each of the 11,091 Executions, no further parse was needed.

Go back and look at the 3 different INSERT statements in the procedure and note the single INSERT statement (hv=4147238877) !

Thus, Oracle is smart enough to convert SQL statements in a PLSQL procedure (or block) into *reusable* SQLs which do not need to be parsed 11thousand times.

.
.
.

13 April, 2010

SQLs in PLSQL

A short demonstration of how SQLs embedded in PLSQL are handled.

I define a stored procedure that
a. Opens a Cursor and fetches from it
b. Runs an INSERT, using PLSQL variables for each row from the cursor
c. Runs three other INSERTs using literals

Note how the Parsing and Execution is handled for a. and b. versus c.
Also note how the SQL is converted to Upper Case.

First the test case :

SQL> REM Demonstrate that SQLs in PLSQL becomes Binds
SQL>
SQL> connect / as sysdba
Connected.
SQL> grant select on dba_objects to hemant;

Grant succeeded.

SQL> alter system flush shared_pool;

System altered.

SQL> alter system flush shared_pool;

System altered.

SQL>
SQL> connect hemant/hemant
Connected.
SQL>
SQL> drop table log_table purge;

Table dropped.

SQL> create table log_table (entry_id number, entry_text varchar2(500));

Table created.

SQL>
SQL> create or replace procedure PLSQL_SQL_bind
2 as
3 l_entry_id number;
4 l_entry_text varchar2(500);
5
6 cursor c1 is
7 select object_id, owner||object_name from dba_objects where object_type = 'VIEW' order by object_id;
8
9 begin
10 open c1;
11 loop
12 fetch c1 into l_entry_id,l_entry_text;
13 exit when c1%NOTFOUND;
14 insert into log_table values (l_entry_id, l_entry_text);
15 end loop;
16 insert into LOG_TABLE values (0,'A Dummy');
17 insert into LOG_TABLE values (1,'Another');
18 insert into LOG_TABLE values (2,'A Third');
19 commit;
20 end;
21 /

Procedure created.

SQL>
SQL> show errors;
No errors.
SQL>
SQL> select count(*) from dba_objects where object_type = 'VIEW';

COUNT(*)
----------
3697

SQL> alter session set sql_trace=TRUE;

Session altered.

SQL> execute PLSQL_sql_bind;

PL/SQL procedure successfully completed.

SQL> select 'x' from dual;

'
-
x

SQL> exit


So, the cursor fetches 3,697 rows, causing the first INSERT to be executed 3,697 times.

This is what tkprof shows :

For the Cursor c1 :

SELECT OBJECT_ID, OWNER||OBJECT_NAME
FROM
DBA_OBJECTS WHERE OBJECT_TYPE = 'VIEW' ORDER BY OBJECT_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 3698 0.23 0.22 0 5407 0 3697
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3700 0.24 0.23 0 5407 0 3697

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS


For the INSERTs of the rows from the Cursor :

INSERT INTO LOG_TABLE
VALUES
(:B2 , :B1 )


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 3697 0.14 0.14 0 36 4009 3697
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3698 0.14 0.14 0 36 4009 3697

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS


For the 3 additional INSERTs with Literals :

INSERT INTO LOG_TABLE
VALUES
(0,'A Dummy')


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 1 3 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 1 3 1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS

INSERT INTO LOG_TABLE
VALUES
(1,'Another')


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 1 3 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 1 3 1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS

INSERT INTO LOG_TABLE
VALUES
(2,'A Third')


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 1 3 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 1 3 1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS


Thus, we can see that when using PLSQL variables, Oracle replaces them with it's own generated Bind Variables (:B1 and :B2). Also note that there is a single Parse call for the first INSERT executed 3,697 times while the INSERTs with literals are parsed separately for each execution -- no bind variable substitution has occurred.

.
.
.

03 April, 2010

11gR2 Recursive SubQuery Factoring

Anton Scheffer has published an interesting application for 11gR2's Recursive SubQuery Factoring : Solving a Sudoku.

.
.
(Here's a simple explanation of SubQuery Factoring, introduced in 9i, by Adrian Billington.)

.
.
.