Gather Stats Concurrently

Finally ! Oracle has introduced a "CONCURRENT" preference in DBMS_STATS routines to allow a gather stats on multiple objects concurrently.
Thus a GATHER_SCHEMA_STATS call can be made to have Table Statistics gathered on multiple tables concurrently.
In earlier versions, the DEGREE (of parallelism) would only apply to large tables. Thus, in a schema of some thousands of tables, the GATHER_SCHEMA_STATS call would run through all the tables serially. Only at some large tables would it use Parallelism.

The introduction of the CONCURRENT preference allows the use of Parallel operators to work on multiple tables concurrently.

The Optimizer team has released a short write-up on this.

.

.

.

Synchronising Recovery of two databases

A recent forums question was about backup and recovery to be synchronised for two databases.

To reply, I used my knowledge from the "Distributed Databases" documentation in V7 and how we used to implement Advanced Replication.

When Oracle initiates a Distributed Transaction, it synchronises the SCNs for the databases that are part of the transaction. Essentially, a "Global SCN", which is the highest SCN amongst all those databases participating in the transaction, is selected and this is set in all the databases. Each database may subsequently follow it's own frequency of updating the SCN (i.e. based on the rate of transactions) until the next Distributed Transaction occurs, when the SCNs are again reset to the highest in the group.

Note : SCN synchronization occurs when
a. A connection occurs using a DBLink
b. A distributed SQL statement occurs (yes, even a SELECT !)
c. A distributed transaction commits

Even the V7 Administrator's Guide covered how important it was for Co-ordinated Recovery of Distributed Databases --- using SCNs.


Here's a short, simple demonstration of the synchronisation.
Lines in Italics are on database 'ORCL'.
Lines in BOLD are on database 'DUPDB'.

Initially, the SCN in 'DUPDB' was 6395626, far below the 6501471 in 'ORCL'.
However, as soon as I began distributed transactions, the SCNs were synchronized -- 'DUPDB' caught up with 'ORCL'.

Later when 'DUPDB's SCN had gone to a much higher 6501805 (because there were other "local" transactions in this database) and ran a distributed transaction to bring the SCN to 6502089, it was 'ORCL's turn to catch-up on the SCN


SQL> create database link DUPDB connect to hemant identified by dupdb using 'dupdb';

Database link created.

SQL>
SQL> create database link ORCL connect to hemant identified by orcl using 'ORCL';

Database link created.

SQL>
SQL> create table IN_ORCL (col_1 number, col_2 timestamp, col_3 varchar(30));

Table created.

SQL> select current_scn from v$database;

CURRENT_SCN
-----------
6501471

SQL>
SQL> create table IN_DUPDB (col_1 number, col_2 timestamp, col_3 varchar(30));

Table created.

SQL> select current_scn from v$database;

CURRENT_SCN
-----------
6395626

SQL>
SQL> insert into in_dupdb@dupdb values (1,systimestamp,'FROM ORCL');

1 row created.

SQL> select current_scn from v$database;

CURRENT_SCN
-----------
6501531

SQL>
SQL> select current_scn from v$database;

CURRENT_SCN
-----------
6501537

SQL>
SQL> select systimestamp, current_scn, name from v$database;

SYSTIMESTAMP
---------------------------------------------------------------------------
CURRENT_SCN NAME
----------- ---------
28-JAN-11 11.59.05.566584 PM +08:00
6501585 ORCL


SQL>
SQL> l
1* select systimestamp, current_scn, name from v$database
SQL> /

SYSTIMESTAMP
---------------------------------------------------------------------------
CURRENT_SCN NAME
----------- ---------
28-JAN-11 11.59.59.867294 PM +08:00
6501805 DUPDB


SQL> insert into in_orcl@orcl values (1,systimestamp,'FROM DUPDB');

1 row created.

SQL> select systimestamp, current_scn, name from v$database;

SYSTIMESTAMP
---------------------------------------------------------------------------
CURRENT_SCN NAME
----------- ---------
29-JAN-11 12.00.46.522963 AM +08:00
6502089 DUPDB


SQL>
SQL> select systimestamp, current_scn, name from v$database;

SYSTIMESTAMP
---------------------------------------------------------------------------
CURRENT_SCN NAME
----------- ---------
29-JAN-11 12.00.49.642064 AM +08:00
6502089 ORCL





Note : It does not matter if the database "initiating" a distributed transaction has a lower or a higher SCN than the other database. Oracle just selects the highest SCN (higher of the two in a 2-database transaction, higher of the 'n' in an n-database transaction) and applies it to all the databases.

.
.
.

Transaction Failure --- when is the error returned ?

There was a question in the orafaq forums
"What happens when UNDO space is full? Transaction takes more time to ERROR?"
where my response was to the effect that the user sees the error message only after the rollback is completed.
Thus,
a) if a transaction began at 1pm
b) but, at 3pm, found that it had run out of space in the Undo tablespace (e.g. the datafile is fully occupied and does not have autoextend enable) and other undo extents / segments cannot be expired and reused
c) the user/client does not see the ORA-30036 error at 3pm but only after the (automatic) rollback of the transaction is completed -- which could be at 3:45pm.

Therefore, the time you see the error is not really the exact time when the error occurred. You are presented the error message only after the rollback is completed and the database is returned to a consistent state.

Here's a simple demonstration. I run two "large" transactions (and have a relatively very small Undo tablespace) and check the timestamps of the transactions and messages :

00:17:43 SQL>
00:17:43 SQL> select count(*) from sales_lines;

COUNT(*)
----------
100000

00:17:43 SQL>
00:17:43 SQL> drop table sales_lines_multi purge;

Table dropped.

00:17:44 SQL> create table sales_lines_multi as select * from sales_lines where 1=2;

Table created.

00:17:44 SQL>
00:17:44 SQL> select systimestamp from dual;

SYSTIMESTAMP
---------------------------------------------------------------------------
28-JAN-11 12.17.44.385819 AM +08:00

00:17:44 SQL> insert into sales_lines_multi
00:17:44   2  select * from sales_lines
00:17:44   3  union all
00:17:44   4  select * from sales_lines
00:17:44   5  union all
00:17:44   6  select * from sales_lines
00:17:44   7  union all
00:17:44   8  select * from sales_lines
00:17:44   9  /

400000 rows created.

00:17:47 SQL> select systimestamp from dual;

SYSTIMESTAMP
---------------------------------------------------------------------------
28-JAN-11 12.17.47.414854 AM +08:00

00:17:47 SQL>
00:17:47 SQL> commit;

Commit complete.

00:17:47 SQL> exec dbms_lock.sleep(10);

PL/SQL procedure successfully completed.

00:17:57 SQL>
00:17:57 SQL> select systimestamp from dual;

SYSTIMESTAMP
---------------------------------------------------------------------------
28-JAN-11 12.17.57.500389 AM +08:00

00:17:57 SQL> delete sales_lines_multi;
delete sales_lines_multi
 *
ERROR at line 1:
ORA-30036: unable to extend segment by 8 in undo tablespace 'UNDO'


00:18:04 SQL> select systimestamp from dual;

SYSTIMESTAMP
---------------------------------------------------------------------------
28-JAN-11 12.18.04.386362 AM +08:00

00:18:04 SQL>
00:18:04 SQL> exec dbms_lock.sleep(10);

PL/SQL procedure successfully completed.

00:18:14 SQL>
00:18:14 SQL> select systimestamp from dual;

SYSTIMESTAMP
---------------------------------------------------------------------------
28-JAN-11 12.18.14.412227 AM +08:00

00:18:14 SQL> rollback;

Rollback complete.

00:18:14 SQL> select systimestamp from dual;

SYSTIMESTAMP
---------------------------------------------------------------------------
28-JAN-11 12.18.14.437548 AM +08:00

00:18:14 SQL>
00:18:14 SQL> select count(*) from sales_lines_multi;

COUNT(*)
----------
400000

00:18:14 SQL>  

Thus, I had an INSERT transaction that ran from 12.17.44.385819 to 12.17.47.414854 -- for approximately 3seconds. This transaction completed successfully.

Next, I had a DELETE transaction that ran from 12.17.57.500389 and reported an ORA-30036 slightly before 12.18.04.386362. Therefore, it seems to have run for about 7seconds before it failed. However, did the session actually fail on undo space at 12.18.04 ?

To monitor this, I wrote and ran a procedure :

create or replace procedure log_transaction_proc
as
runcnt number;
cursor c1 is select rownum from dual where rownum < addr="s.taddr" username =" 'HEMANT';"

This procedure wrote the the "log_transaction" table approximately every 5centi-seconds if it found an active transaction by the user 'HEMANT'.

UPDATE : I notice that there's a bug in the procedure which causes it to run in an infinite loop. However, that doesn't invalidate the findings that this blog post identifies (the procedure does write to the log_transaction table !).

These were some of the rows in the log_transaction table :

T_STAMP                                                                      USED_UREC  USED_UBLK
--------------------------------------------------------------------------- ---------- ----------
28-JAN-11 12.17.43.900921 AM                                                        41          3
28-JAN-11 12.17.44.365687 AM                                                        48          1
28-JAN-11 12.17.44.477116 AM                                                        66          2
28-JAN-11 12.17.44.532674 AM                                                       175          4
28-JAN-11 12.17.44.586143 AM                                                       344          8
................
28-JAN-11 12.17.47.280307 AM                                                      8102        164
28-JAN-11 12.17.47.335687 AM                                                      8156        165
28-JAN-11 12.17.47.388669 AM                                                      8390        169
28-JAN-11 12.17.57.593152 AM                                                      2133         52
28-JAN-11 12.17.57.647491 AM                                                      3915         94 

Note how it found NO transaction between 12.17.47.388669 and 12.17.57.593152. Essentially, the first transaction ended some time after 12.17.47.388669 but within 5centiseconds after that !
This first transaction was the INSERT of 400,000 rows that actually required only slightly over 8,390 undo records and 169 undo blocks. (The Undo for an INSERT is actually very small).

Next, I saw these entries for the DELETE :

T_STAMP                                                                      USED_UREC  USED_UBLK
--------------------------------------------------------------------------- ---------- ----------
28-JAN-11 12.17.57.593152 AM                                                      2133         52
28-JAN-11 12.17.57.647491 AM                                                      3915         94
28-JAN-11 12.17.57.702068 AM                                                      5897        142
28-JAN-11 12.17.57.756098 AM                                                      8273        198
28-JAN-11 12.17.57.810300 AM                                                     10216        245
................
28-JAN-11 12.18.01.841294 AM                                                    119177       2839
28-JAN-11 12.18.01.894567 AM                                                    121401       2892
28-JAN-11 12.18.01.947189 AM                                                    121523       2895
28-JAN-11 12.18.02.000468 AM                                                    118341       2819
28-JAN-11 12.18.02.053156 AM                                                    115310       2747
................
28-JAN-11 12.18.04.086817 AM                                                     14787        353
28-JAN-11 12.18.04.143813 AM                                                     11674        279
28-JAN-11 12.18.04.200892 AM                                                      8378        201
28-JAN-11 12.18.04.259882 AM                                                      5457        131
28-JAN-11 12.18.04.319280 AM                                                      2189         53 

The transaction kept growing only upto sometime within 5centiseconds after 12.18.01.947189 when it was 121,523 undo rows. (We cannot know how many table rows did get deleted at this point). However, the transaction started shrinking by 12.18.02.000468. Why did it start shrinking ? Because it had failed ! (here we discover later that the failure was ORA-30036). The transaction kept shrinking --- i.e. it kept undergoing the "automatic" rollback until sometime after 12.18.04.319280. We know from the SQL execution log that the ORA-30036 error was returned to the client just before 12.18.04.386362.

Therefore, the transaction actually went out of Undo space between 12.18.01.947189 and 12.18.02.000468. The user/client/application saw the error message only slightly before 12.18.04.386362 --- i.e. more than 2 seconds later. This difference was the time it took Oracle to actually rollback the failed transaction.

I have seen cases where the time difference between when a transaction actually ran out of undo space and when the error was reported to the user was 30minutes in some cases and more than an hour in more extreme cases.

Note : The ORA-30036 error does not get reported in the alert.log file.

.
.
.