Recently we migrated our application to Oracle 10g RAC (3 Instance) and ended up with sequences created as out of order at each Instance.
Here is the snippet of code to demonstrate that.
rajesh@ORA10GR2-01> SELECT INST_ID,
2 INSTANCE_NUMBER,
3 INSTANCE_NAME
4 FROM GV$INSTANCE
5 ORDER BY INST_ID;
INST_ID INSTANCE_NUMBER INSTANCE_NAME
---------- --------------- ----------------
1 1 ORA10GR2-01
2 2 ORA10GR2-02
3 3 ORA10GR2-03
rajesh@ORA10GR2-01> create sequence s CACHE 30;
Sequence created.
Elapsed: 00:00:00.07
rajesh@ORA10GR2-01> select SEQUENCE_NAME,ORDER_FLAG,CACHE_SIZE
2 from user_sequences
3 where sequence_name ='S'
4 /
SEQUENCE_NAME O CACHE_SIZE
------------------------------ - ----------
S N 30
Elapsed: 00:00:00.17
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select s.nextval from dual;
NEXTVAL
----------
1
Elapsed: 00:00:00.14
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select s.nextval from dual;
NEXTVAL
----------
2
Elapsed: 00:00:00.25
rajesh@ORA10GR2-01>
When connecting back to Instance02 I found the sequence values different.
rajesh@ORA10GR2-01> connect rajesh/oracle@ORA10GR2-02
Connected.
rajesh@ORA10GR2-02> select s.nextval from dual;
NEXTVAL
----------
31
Elapsed: 00:00:00.48
rajesh@ORA10GR2-02>
rajesh@ORA10GR2-02> select s.nextval from dual;
NEXTVAL
----------
32
Elapsed: 00:00:00.15
rajesh@ORA10GR2-02>
When connecting back to Instance03 I found the sequence values different again.
rajesh@ORA10GR2-02> connect rajesh/oracle@ORA10GR2-03
Connected.
rajesh@ORA10GR2-03> select s.nextval from dual;
NEXTVAL
----------
61
Elapsed: 00:00:00.21
rajesh@ORA10GR2-03> select s.nextval from dual;
NEXTVAL
----------
62
Elapsed: 00:00:00.14
rajesh@ORA10GR2-03>
The reason for this out of order sequence at each instance is the sequence cache is in the shared pool, therefore sessions on the same node can share the cached entry, but sessions on different nodes cannot.
The solution to solve this sequence running out of order at each instance is to create sequence using ORDER option. which will guarantee the order in which numbers are generated.
rajesh@ORA10GR2-01> create sequence s CACHE 30 ORDER;
Sequence created.
Elapsed: 00:00:00.09
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select SEQUENCE_NAME,ORDER_FLAG,CACHE_SIZE
2 from user_sequences
3 where sequence_name ='S'
4 /
SEQUENCE_NAME O CACHE_SIZE
------------------------------ - ----------
S Y 30
Elapsed: 00:00:00.10
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select s.nextval from dual;
NEXTVAL
----------
1
Elapsed: 00:00:00.17
rajesh@ORA10GR2-01> select s.nextval from dual;
NEXTVAL
----------
2
Elapsed: 00:00:00.34
rajesh@ORA10GR2-01>
Connecting back to Instance02.
rajesh@ORA10GR2-01> connect rajesh/oracle@ORA10GR2-02
Connected.
rajesh@ORA10GR2-02> select s.nextval from dual;
NEXTVAL
----------
3
Elapsed: 00:00:00.17
rajesh@ORA10GR2-02>
rajesh@ORA10GR2-02> select s.nextval from dual;
NEXTVAL
----------
4
Elapsed: 00:00:00.17
rajesh@ORA10GR2-02>
Connecting back to Instance03.
rajesh@ORA10GR2-02> connect rajesh/oracle@ORA10GR2-03
Connected.
rajesh@ORA10GR2-03> select s.nextval from dual;
NEXTVAL
----------
5
Elapsed: 00:00:00.14
rajesh@ORA10GR2-03>
rajesh@ORA10GR2-03> select s.nextval from dual;
NEXTVAL
----------
6
Elapsed: 00:00:00.17
rajesh@ORA10GR2-03>
We changed the sequence to "ordered" Now selecting on either node gets the next number as expected.
However having the sequence with CACHE and ORDER would lead to some performance implications due to cluster synchronization. In Oracle 10g RAC, if you specify the "ordered" clause for a sequence, then a global lock is allocated by the node when you access the sequence. This lock acquisition happens only at the first sequence access for the node, and subsequent uses of the sequence do not wait on this lock.
rajesh@ORA10GR2-01> create sequence s order;
Sequence created.
Elapsed: 00:00:00.01
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select SEQUENCE_NAME,ORDER_FLAG,CACHE_SIZE
2 from user_sequences
3 where sequence_name ='S';
SEQUENCE_NAME O CACHE_SIZE
------------------------------ - ----------
S Y 20
Elapsed: 00:00:00.01
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01>
Connected.
rajesh@ORA10GR2-01>
I was running the below Pl/SQL block evenly across all the RAC Instance.
rajesh@ORA10GR2-01> declare
2 k number;
3 l_start number;
4 l_cpu_time number;
5 begin
6 l_start := dbms_utility.get_time;
7 l_cpu_time := dbms_utility.get_cpu_time;
8 for i in 1..500000
9 loop
10 select s.nextval
11 into k
12 from dual;
13 end loop;
14
15 dbms_output.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
16 dbms_output.put_line (' Total CPU time = '|| (dbms_utility.get_cpu_time - l_cpu_time) );
17 end;
18 /
Total Execution time = 82110
Total CPU time = 7057
PL/SQL procedure successfully completed.
Elapsed: 00:13:40.99
rajesh@ORA10GR2-01>
And the AWR on Instance 1 is.
SQL Id Time (ms)
------------- ----------
9x2hyv1prpts9 802,038
Module: SQL*Plus
OUTPUT
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst011 Snaps: 3518-3519
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 802,038 1 3519 3519
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst011 Snaps: 3518-3519
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 802,038 802,037.9 30.0
CPU Time (ms) 70,597 70,597.3 93.7
Executions 1 N/A N/A
Buffer Gets 149,976 149,976.0 56.6
Disk Reads 3 3.0 7.7
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.0
Rows 1 1.0 N/A
User I/O Wait Time (ms) 45 N/A N/A
Cluster Wait Time (ms) 186,959 N/A N/AApplication Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 13,813 N/A N/AInvalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
And the AWR on Instance 2 is.
And the AWR on Instance 3 is.
Total Execution time = 32396
Total CPU time = 3418
Here is the snippet of code to demonstrate that.
rajesh@ORA10GR2-01> SELECT INST_ID,
2 INSTANCE_NUMBER,
3 INSTANCE_NAME
4 FROM GV$INSTANCE
5 ORDER BY INST_ID;
INST_ID INSTANCE_NUMBER INSTANCE_NAME
---------- --------------- ----------------
1 1 ORA10GR2-01
2 2 ORA10GR2-02
3 3 ORA10GR2-03
rajesh@ORA10GR2-01> create sequence s CACHE 30;
Sequence created.
Elapsed: 00:00:00.07
rajesh@ORA10GR2-01> select SEQUENCE_NAME,ORDER_FLAG,CACHE_SIZE
2 from user_sequences
3 where sequence_name ='S'
4 /
SEQUENCE_NAME O CACHE_SIZE
------------------------------ - ----------
S N 30
Elapsed: 00:00:00.17
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select s.nextval from dual;
NEXTVAL
----------
1
Elapsed: 00:00:00.14
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select s.nextval from dual;
NEXTVAL
----------
2
Elapsed: 00:00:00.25
rajesh@ORA10GR2-01>
When connecting back to Instance02 I found the sequence values different.
rajesh@ORA10GR2-01> connect rajesh/oracle@ORA10GR2-02
Connected.
rajesh@ORA10GR2-02> select s.nextval from dual;
NEXTVAL
----------
31
Elapsed: 00:00:00.48
rajesh@ORA10GR2-02>
rajesh@ORA10GR2-02> select s.nextval from dual;
NEXTVAL
----------
32
Elapsed: 00:00:00.15
rajesh@ORA10GR2-02>
When connecting back to Instance03 I found the sequence values different again.
rajesh@ORA10GR2-02> connect rajesh/oracle@ORA10GR2-03
Connected.
rajesh@ORA10GR2-03> select s.nextval from dual;
NEXTVAL
----------
61
Elapsed: 00:00:00.21
rajesh@ORA10GR2-03> select s.nextval from dual;
NEXTVAL
----------
62
Elapsed: 00:00:00.14
rajesh@ORA10GR2-03>
The reason for this out of order sequence at each instance is the sequence cache is in the shared pool, therefore sessions on the same node can share the cached entry, but sessions on different nodes cannot.
The solution to solve this sequence running out of order at each instance is to create sequence using ORDER option. which will guarantee the order in which numbers are generated.
rajesh@ORA10GR2-01> create sequence s CACHE 30 ORDER;
Sequence created.
Elapsed: 00:00:00.09
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select SEQUENCE_NAME,ORDER_FLAG,CACHE_SIZE
2 from user_sequences
3 where sequence_name ='S'
4 /
SEQUENCE_NAME O CACHE_SIZE
------------------------------ - ----------
S Y 30
Elapsed: 00:00:00.10
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select s.nextval from dual;
NEXTVAL
----------
1
Elapsed: 00:00:00.17
rajesh@ORA10GR2-01> select s.nextval from dual;
NEXTVAL
----------
2
Elapsed: 00:00:00.34
rajesh@ORA10GR2-01>
Connecting back to Instance02.
rajesh@ORA10GR2-01> connect rajesh/oracle@ORA10GR2-02
Connected.
rajesh@ORA10GR2-02> select s.nextval from dual;
NEXTVAL
----------
3
Elapsed: 00:00:00.17
rajesh@ORA10GR2-02>
rajesh@ORA10GR2-02> select s.nextval from dual;
NEXTVAL
----------
4
Elapsed: 00:00:00.17
rajesh@ORA10GR2-02>
Connecting back to Instance03.
rajesh@ORA10GR2-02> connect rajesh/oracle@ORA10GR2-03
Connected.
rajesh@ORA10GR2-03> select s.nextval from dual;
NEXTVAL
----------
5
Elapsed: 00:00:00.14
rajesh@ORA10GR2-03>
rajesh@ORA10GR2-03> select s.nextval from dual;
NEXTVAL
----------
6
Elapsed: 00:00:00.17
rajesh@ORA10GR2-03>
We changed the sequence to "ordered" Now selecting on either node gets the next number as expected.
However having the sequence with CACHE and ORDER would lead to some performance implications due to cluster synchronization. In Oracle 10g RAC, if you specify the "ordered" clause for a sequence, then a global lock is allocated by the node when you access the sequence. This lock acquisition happens only at the first sequence access for the node, and subsequent uses of the sequence do not wait on this lock.
rajesh@ORA10GR2-01> create sequence s order;
Sequence created.
Elapsed: 00:00:00.01
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select SEQUENCE_NAME,ORDER_FLAG,CACHE_SIZE
2 from user_sequences
3 where sequence_name ='S';
SEQUENCE_NAME O CACHE_SIZE
------------------------------ - ----------
S Y 20
Elapsed: 00:00:00.01
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01>
Connected.
rajesh@ORA10GR2-01>
I was running the below Pl/SQL block evenly across all the RAC Instance.
rajesh@ORA10GR2-01> declare
2 k number;
3 l_start number;
4 l_cpu_time number;
5 begin
6 l_start := dbms_utility.get_time;
7 l_cpu_time := dbms_utility.get_cpu_time;
8 for i in 1..500000
9 loop
10 select s.nextval
11 into k
12 from dual;
13 end loop;
14
15 dbms_output.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
16 dbms_output.put_line (' Total CPU time = '|| (dbms_utility.get_cpu_time - l_cpu_time) );
17 end;
18 /
Total Execution time = 82110
Total CPU time = 7057
PL/SQL procedure successfully completed.
Elapsed: 00:13:40.99
rajesh@ORA10GR2-01>
And the AWR on Instance 1 is.
SQL Id Time (ms)
------------- ----------
9x2hyv1prpts9 802,038
Module: SQL*Plus
OUTPUT
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst011 Snaps: 3518-3519
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 802,038 1 3519 3519
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst011 Snaps: 3518-3519
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 802,038 802,037.9 30.0
CPU Time (ms) 70,597 70,597.3 93.7
Executions 1 N/A N/A
Buffer Gets 149,976 149,976.0 56.6
Disk Reads 3 3.0 7.7
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.0
Rows 1 1.0 N/A
User I/O Wait Time (ms) 45 N/A N/A
Cluster Wait Time (ms) 186,959 N/A N/AApplication Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 13,813 N/A N/AInvalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
And the AWR on Instance 2 is.
Elapsed
SQL Id Time (ms)
------------- ----------
9x2hyv1prpts9 818,718
Module: SQL*Plus
OUTPUT
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst012 Snaps: 3518-3519
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 818,718 1 3519 3519
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst012 Snaps: 3518-3519
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 818,718 818,718.5 31.7
CPU Time (ms) 72,017 72,017.1 97.5
Executions 1 N/A N/A
Buffer Gets 149,898 149,898.0 81.6
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.0
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 135,191 N/A N/A
Application Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 14,768 N/A N/A
Invalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
SQL Id Time (ms)
------------- ----------
9x2hyv1prpts9 818,718
Module: SQL*Plus
OUTPUT
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst012 Snaps: 3518-3519
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 818,718 1 3519 3519
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst012 Snaps: 3518-3519
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 818,718 818,718.5 31.7
CPU Time (ms) 72,017 72,017.1 97.5
Executions 1 N/A N/A
Buffer Gets 149,898 149,898.0 81.6
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.0
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 135,191 N/A N/A
Application Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 14,768 N/A N/A
Invalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
Elapsed
SQL Id Time (ms)
------------- ----------
9x2hyv1prpts9 816,826
Module: SQL*Plus
OUTPUT
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst013 Snaps: 3518-3519
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 816,826 1 3519 3519
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst013 Snaps: 3518-3519
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 816,826 816,826.4 97.8
CPU Time (ms) 68,859 68,858.5 90.9
Executions 1 N/A N/A
Buffer Gets 133,660 133,660.0 28.3
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.0
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 25,148 N/A N/A
Application Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 8,942 N/A N/A
Invalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
SQL Id Time (ms)
------------- ----------
9x2hyv1prpts9 816,826
Module: SQL*Plus
OUTPUT
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst013 Snaps: 3518-3519
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 816,826 1 3519 3519
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst013 Snaps: 3518-3519
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 816,826 816,826.4 97.8
CPU Time (ms) 68,859 68,858.5 90.9
Executions 1 N/A N/A
Buffer Gets 133,660 133,660.0 28.3
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.0
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 25,148 N/A N/A
Application Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 8,942 N/A N/A
Invalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
Due to the less CACHE sequence value and ORDER attribute and since the same sequence is shared across all Instance we ended up with Clustered & Concurrency waits.
Now repeting the same test with Increased CACHE size.
rajesh@ORA10GR2-01> create sequence s CACHE 100000 order;
Sequence created.
Elapsed: 00:00:00.03
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select SEQUENCE_NAME,ORDER_FLAG,CACHE_SIZE
2 from user_sequences
3 where sequence_name ='S';
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01> select SEQUENCE_NAME,ORDER_FLAG,CACHE_SIZE
2 from user_sequences
3 where sequence_name ='S';
SEQUENCE_NAME O CACHE_SIZE
------------------------------ - ----------
S Y 100000
------------------------------ - ----------
S Y 100000
Elapsed: 00:00:00.01
rajesh@ORA10GR2-01> declare
2 k number;
3 l_start number;
4 l_cpu_time number;
5 begin
6 l_start := dbms_utility.get_time;
7 l_cpu_time := dbms_utility.get_cpu_time;
8 for i in 1..500000
9 loop
10 select s.nextval
11 into k
12 from dual;
13 end loop;
14
15 dbms_output.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
16 dbms_output.put_line (' Total CPU time = '|| (dbms_utility.get_cpu_time - l_cpu_time) );
17 end;
18 /
2 k number;
3 l_start number;
4 l_cpu_time number;
5 begin
6 l_start := dbms_utility.get_time;
7 l_cpu_time := dbms_utility.get_cpu_time;
8 for i in 1..500000
9 loop
10 select s.nextval
11 into k
12 from dual;
13 end loop;
14
15 dbms_output.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
16 dbms_output.put_line (' Total CPU time = '|| (dbms_utility.get_cpu_time - l_cpu_time) );
17 end;
18 /
Total Execution time = 32396
Total CPU time = 3418
PL/SQL procedure successfully completed.
Elapsed: 00:05:23.96
rajesh@ORA10GR2-01>
rajesh@ORA10GR2-01>
AWR at Instance-01 shows
Elapsed
SQL Id Time (ms)
------------- ----------
9x2hyv1prpts9 316,430
Module: SQL*Plus
OUTPUT
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst011 Snaps: 3520-3521
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 316,430 1 3521 3521
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst011 Snaps: 3520-3521
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 316,430 316,429.6 91.0
CPU Time (ms) 34,199 34,198.8 87.9
Executions 1 N/A N/A
Buffer Gets 118 118.0 0.9
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.1
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 4 N/A N/AApplication Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 8 N/A N/AInvalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
SQL Id Time (ms)
------------- ----------
9x2hyv1prpts9 316,430
Module: SQL*Plus
OUTPUT
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst011 Snaps: 3520-3521
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 316,430 1 3521 3521
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst011 Snaps: 3520-3521
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 316,430 316,429.6 91.0
CPU Time (ms) 34,199 34,198.8 87.9
Executions 1 N/A N/A
Buffer Gets 118 118.0 0.9
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.1
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 4 N/A N/AApplication Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 8 N/A N/AInvalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
AWR at Instance-02 shows
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst012 Snaps: 3520-3521
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 320,198 1 3521 3521
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst012 Snaps: 3520-3521
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 320,198 320,198.1 96.7
CPU Time (ms) 36,561 36,561.4 92.0
Executions 1 N/A N/A
Buffer Gets 59 59.0 0.7
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.1
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 12 N/A N/A
Application Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 9 N/A N/AInvalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst012 Snaps: 3520-3521
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 320,198 1 3521 3521
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst012 Snaps: 3520-3521
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 320,198 320,198.1 96.7
CPU Time (ms) 36,561 36,561.4 92.0
Executions 1 N/A N/A
Buffer Gets 59 59.0 0.7
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.1
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 12 N/A N/A
Application Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 9 N/A N/AInvalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
AWR at Instance-03 shows
--------------------------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst013 Snaps: 3520-3521
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 318,115 1 3521 3521
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst013 Snaps: 3520-3521
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 318,115 318,115.2 92.6
CPU Time (ms) 31,745 31,745.2 83.8
Executions 1 N/A N/A
Buffer Gets 47 47.0 0.0
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.1
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 11 N/A N/A
Application Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 5 N/A N/AInvalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
declare k number; l_start number; l_cpu_time number; begin l_start :=
dbms_utility.get_time; l_cpu_time := dbms_utility.get_cpu_time; for i in 1..5
00000 loop select s.nextval into k from dual; end loop; dbms_outpu
t.put_line (' Total Execution time = '|| (dbms_utility.get_time - l_start) );
-------------------------------------------------------------
SQL ID: 9x2hyv1prpts9 DB/Inst: IRDST01/irdst013 Snaps: 3520-3521
-> 1st Capture and Last Capture Snap IDs
refer to Snapshot IDs witin the snapshot range
-> declare k number; l_start number; l_cpu_time number; begin l...
OUTPUT
--------------------------------------------------------------------------------
Plan Hash Total Elapsed 1st Capture Last Capture
# Value Time(ms) Executions Snap ID Snap ID
--- ---------------- ---------------- ------------- ------------- --------------
1 0 318,115 1 3521 3521
-------------------------------------------------------------
Plan 1(PHV: 0)
--------------
OUTPUT
--------------------------------------------------------------------------------
Plan Statistics DB/Inst: IRDST01/irdst013 Snaps: 3520-3521
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100
Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 318,115 318,115.2 92.6
CPU Time (ms) 31,745 31,745.2 83.8
Executions 1 N/A N/A
Buffer Gets 47 47.0 0.0
Disk Reads 0 0.0 0.0
OUTPUT
--------------------------------------------------------------------------------
Parse Calls 1 1.0 0.1
Rows 1 1.0 N/A
User I/O Wait Time (ms) 0 N/A N/A
Cluster Wait Time (ms) 11 N/A N/A
Application Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 5 N/A N/AInvalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 20 N/A N/A
-------------------------------------------------------------
Now the Cluster Wait Time & Concurrency Wait Time got reduced due to Increased CACHE size. which leads to less synchronization across RAC Instances.
No comments:
Post a Comment