Monthly Archives: December 2014

RAC One Node 12c-revisited on ODA 12.1.2.1.0 featuring database on ACFS

Thanks to Andy Colvin (@acolvin) and the Enkitec lab I have been able to get my hands on an ODA X4-2. And since that’s a lot quieter than turning on my own lab server, and also a lot faster I used the environment to test RAC One Node in 12.1.0.2.1. I recently had a question from a customer about the usefulness of the solution and what it brings to the HA table. Well here you go.

There is just a slight caveat: to make use of the high availability features in RAC One Node you need to have an application that has been written to take advantage of them. Using Fast Connection Failover or Application Continuity is the way to go. Although I have written sample code to exploit the functionality of FCF/FAN and Application Continuity it has recently come to my attention that the very popular swingbench benchmark can do the same. I saw the connection pool tab in my demos but it didn’t “click”. Now I would like to show you what happens with your application during common scenarios in RAC One Node.

Scenario 1: Database relocation

For this blog post I’d like to try a database live migration from the first to the second host in the cluster. The database has been created using oakcli, primarily because I wanted to get more familiar with it. This is ODA release 12.1.2.1.0, the latest and greatest at the time of writing. I also love the fact that the ODA comes with quite a few of these: Intel(R) Xeon(R) CPU E5-2697 v2 @ 2.70GHz. To be precise, each node has 2s24c48t of Ivy Bridge Xeons. Nice.

[oracle@server1 ~]$ /opt/oracle/oak/bin/oakcli show version
Version
-------
12.1.2.1.0

As root (indeed!) I invoked oakcli, the primary ODA command line tool. The first time around I was bitten by not having read the documentation: if you specify the -version flag oakcli will create a new RDBMS home in both cluster nodes. That was _not_ what I had in mind. On the other hand I am now familiar with checking the environment (various permutations of oakcli show…) and deleting an Oracle home. This command created the datbase in the end:

[root@server1 ~]# oakcli create database -db RON -oh OraDb12102_home1

The command will prompt you for the datbase type (single instance, RAC One, clustered) – good stuff, simple to use, and more importantly: it worked first time.

Databases in ACFS

Now remember that from ODA release 12.1.2 onwards 11.2.0.4 and 12.1.x databases will be created on ACFS. In my case that looks slightly odd, I guess I have to get used to it first:

SQL> select name from v$datafile;

NAME
---------------------------------------------------------------------------------------------
/u02/app/oracle/oradata/datastore/.ACFS/snaps/RON/RON/datafile/o1_mf_system_b93xdj44_.dbf
/u02/app/oracle/oradata/datastore/.ACFS/snaps/RON/RON/datafile/o1_mf_sysaux_b93xdmhk_.dbf
/u02/app/oracle/oradata/datastore/.ACFS/snaps/RON/RON/datafile/o1_mf_undotbs1_b93xdosz_.dbf
/u02/app/oracle/oradata/datastore/.ACFS/snaps/RON/RON/datafile/o1_mf_undotbs2_b93xdypp_.dbf
/u02/app/oracle/oradata/datastore/.ACFS/snaps/RON/RON/datafile/o1_mf_users_b93xdzjj_.dbf
/u02/app/oracle/oradata/datastore/.ACFS/snaps/RON/RON/datafile/o1_mf_soe_tbs_b93yl62m_.dbf

6 rows selected.

SQL> select name from v$tempfile;

NAME 
----------------------------------------------------------------------------------------
/u02/app/oracle/oradata/datastore/.ACFS/snaps/RON/RON/datafile/o1_mf_temp_b93xdpl2_.tmp

SQL> select member from v$logfile

MEMBER
-----------------------------------------------------------------------------
/u01/app/oracle/oradata/datastore/RON/RON/onlinelog/o1_mf_1_b93xd3tb_.log
/u01/app/oracle/oradata/datastore/RON/RON/onlinelog/o1_mf_2_b93xd9m5_.log
/u01/app/oracle/oradata/datastore/RON/RON/onlinelog/o1_mf_3_b93y0hrq_.log
/u01/app/oracle/oradata/datastore/RON/RON/onlinelog/o1_mf_4_b93y0pf9_.log

SQL> show parameter control_files

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
control_files                        string      /u01/app/oracle/oradata/datast
                                                 ore/RON/RON/controlfile/o1_mf_
                                                 b93xd3ll_.ctl
SQL> show parameter db_recovery_file_dest

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_recovery_file_dest                string      /u01/app/oracle/fast_recovery_
                                                 area/datastore/RON
db_recovery_file_dest_size           big integer 465G

The funny bit is that /u02/app/oracle/oradata/datastore contains snapshots… This is visible in the data file location where you find an .ACFS/snaps component. I believe the naming convention is to use .ACFS (invisible) followed by the snapshot name. You can view the snapshot detail using acfsutil:

[grid@server1 ~]$ acfsutil snap info RON /u02/app/oracle/oradata/datastore/
snapshot name:               RON
snapshot location:           /u02/app/oracle/oradata/datastore/.ACFS/snaps/RON
RO snapshot or RW snapshot:  RW
parent name:                 /u02/app/oracle/oradata/datastore/
snapshot creation time:      Wed Dec 17 15:26:24 2014

Interestingly the /u01 data store does not have a snapshot:

[grid@server1 ~]$ acfsutil snap info /u01/app/oracle/oradata/datastore
    number of snapshots:  0
    snapshot space usage: 0  ( 0.00 )

But I digress…

Database setup and configuration

After the database has been created, it is defined in Clusterware as follows:

[oracle@server1 ~]$ srvctl config database -d ron
Database unique name: RON
Database name: RON
Oracle home: /u01/app/oracle/product/12.1.0.2/dbhome_1
Oracle user: oracle
Spfile: /u02/app/oracle/oradata/datastore/.ACFS/snaps/RON/RON/spfileRON.ora
Password file: /u02/app/oracle/oradata/datastore/.ACFS/snaps/RON/RON/orapwRON
Domain: 
Start options: open
Stop options: immediate
Database role: PRIMARY
Management policy: AUTOMATIC
Server pools: 
Disk Groups: 
Mount point paths: /u01/app/oracle/fast_recovery_area/datastore,/u01/app/oracle/oradata/datastore,/u02/app/oracle/oradata/datastore
Services: RON_racone
Type: RACOneNode
Online relocation timeout: 30
Instance name prefix: RON
Candidate servers: server1,server2
OSDBA group: dba
OSOPER group: racoper
Database instances: 
Database is administrator managed
[oracle@server1 ~]$ 

The mandatory service is defined like this:

[oracle@server1 ~]$ srvctl config service -d ron
Service name: RON_racone
Server pool: 
Cardinality: 1
Disconnect: false
Service role: PRIMARY
Management policy: AUTOMATIC
DTP transaction: false
AQ HA notifications: false
Global: false
Commit Outcome: false
Failover type: 
Failover method: 
TAF failover retries: 
TAF failover delay: 
Connection Load Balancing Goal: LONG
Runtime Load Balancing Goal: NONE
TAF policy specification: NONE
Edition: 
Pluggable database name: 
Maximum lag time: ANY
SQL Translation Profile: 
Retention: 86400 seconds
Replay Initiation Time: 300 seconds
Session State Consistency: 
GSM Flags: 0
Service is enabled
Preferred instances: RON_2
Available instances: 
[oracle@server1 ~]$ 

With RAC One Node it is even more important to connect to the service, and not to the instance.

Getting ready for the testing

The situation before the test is shown here:

[oracle@server1 ~]$ srvctl status database -d ron
Instance RON_2 is running on node server2
Online relocation: INACTIVE
[oracle@server1 ~]$ srvctl status service -d ron
Service RON_racone is running on instance(s) RON_2

For swingbench to benefit from FCF it needs to be configured so that it uses a connection pool. I have used the swingbench FAQ (http://www.dominicgiles.com/swingbenchfaq.html) to do so. My connection is defined as follows:

   <Connection>
      <UserName>soe</UserName>
      <Password>soe</Password>
      <ConnectString>//cluster-scan/RON_racone</ConnectString>
      <DriverType>Oracle jdbc Driver</DriverType>
        <ConnectionPooling>
            <PooledInitialLimit>50</PooledInitialLimit>
            <PooledMinLimit>25</PooledMinLimit>
            <PooledMaxLimit>100</PooledMaxLimit>
            <PooledInactivityTimeOut>50</PooledInactivityTimeOut>
            <PooledConnectionWaitTimeout>45</PooledConnectionWaitTimeout>
            <PooledPropertyCheckInterval>10</PooledPropertyCheckInterval>
            <PooledAbandonedConnectionTimeout>120</PooledAbandonedConnectionTimeout>
        </ConnectionPooling>
      <Properties> 
         <Property Key="StatementCaching">50</Property>
         <Property Key="FastFailover">true</Property>
         <Property Key="OnsConfiguration">nodes=server1:6200,server2:6200</Property>
         <Property Key="AppContinuityDriver">true</Property>
         <Property Key="FetchSize">20</Property>
      </Properties>
   </Connection>   

This part and the rest of the configuration is based largely on this post: Application Continuity in Oracle Database 12c (12.1.0.2).

Now – finally – for the test!

Starting charbench will trigger the creation of 100 sessions on the currently active instance (I set NumberOfUsers to 100) and they will be chugging along nicely. Here is the output after a couple of minutes:

[oracle@server1 bin]$ ./charbench -c oda_soe.xml 
Author  :        Dominic Giles
Version :        2.5.0.952

Results will be written to results.xml.
Hit Return to Terminate Run...

Time            Users   TPM     TPS

7:24:28 AM      100     17242   291                                            

I saw about 290 TPS for a total of around 18,000 TPM over some time. Let’s start the live migration. But first, I’d like to use the glass bowl to see what might happen (new in 12.1.0.2):

[oracle@server1 ~]$ srvctl predict database -db RON -verbose
Database ron will be started on node server1
Database ron will be stopped on node server2
Service ron_racone will be started on node server1

Well I guess that might be correct, but let’s try:

[oracle@server1 ~]$ srvctl relocate database -d ron -verbose -node server1
Configuration updated to two instances
Instance RON_1 started
Services relocated
Waiting for up to 30 minutes for instance RON_2 to stop ...
Instance RON_2 stopped
Configuration updated to one instance
[oracle@server1 ~]$ 

While this command executed I didn’t lose a single connection – 100 SOE connections were always established. It also takes a few second for the cache to warm up, during which the transaction rate dips a little bit:

[oracle@server1 bin]$ ./charbench -c oda_soe.xml
Author  :        Dominic Giles
Version :        2.5.0.952

Results will be written to results.xml.
Hit Return to Terminate Run...

Time            Users   TPM     TPS

7:29:11 AM      100     13135   191                                            

One minute after this the throughput is back to normal.

[oracle@server1 bin]$ ./charbench -c oda_soe.xml
Author  :        Dominic Giles
Version :        2.5.0.952

Results will be written to results.xml.
Hit Return to Terminate Run...

Time            Users   TPM     TPS

7:30:50 AM      100     16800   295          

Online relocation with RAC One node is certainly a possibility and works nicely if your application is ready for connection pools and the new way of connecting to the database.

Preview of the next article in the series

In the next article I’d like to add a couple of things I haven’t had time to test yet: 12.1.0.x extends the concept of the database resident connection pool to Java applications (and other middle tier) which would allow me to scale even further. I’d also like to show you what happens if the current RAC One Node instance fails. Stay tuned!

Advertisements

Adventures in RAC: gc buffer busy acquire and release

It seems that I’m getting more and more drawn into the world of performance analysis, and since I sometimes tend to forget things I need to write them down. I almost enjoy the “getting there” more than ultimately solving the problem. You pick up quite a few things on the way.

This environment is Exadata 12.1.1.1.1/Oracle 12.1.0.2 but as with so many things the fact that the database is on Exadata shouldn’t matter.

So here is one of these posts, this time I’m writing up what I saw related to GC Buffer Busy Acquire.

gc buffer busy acquire?

Whenever I see a wait event I haven’t dealt with extensively in the past I try to provoke behaviour to study it more closely. But first you need to know the event’s meaning. One option is to check v$event_name:

SQL> select name, parameter1, parameter2, parameter3, wait_class
  2  from v$event_name where name = 'gc buffer busy acquire';

NAME                           PARAMETER1 PARAMETER2 PARAMETER3 WAIT_CLASS
------------------------------ ---------- ---------- ---------- -------------------
gc buffer busy acquire         file#      block#     class#     Cluster

So when you see this event in ASH/traces/v$session etc you know it’s a cluster wait and potentially limiting your processing throughput. It also tells you the file#, block# and class# of the buffer which you can link to v$bh. This view allows you to find the data object ID given these input parameters.

Using https://orainternals.wordpress.com/2012/04/19/gc-buffer-busy-acquire-vs-release/ as a source I worked out that the event has to do with acquiring a buffer (=block) in RAC (gc = global cache) on the local instance. If the block you need is on the remote instance you wait for it to be released, and the wait event is gc buffer busy release.

Since Oracle will clone blocks in buffer caches for consistent reads and use a shared lock on these for reading I thought that waiting can only happen if someone requested a block in XCUR (exclusive current) mode. So with that working hypothesis I went to work.

How to test

I started off writing a small java class that creates a connection pool against my RAC database. I initially used the default service name in the connect descriptor but had to find out that dbms_monitor.SERV_MOD_ACT_TRACE_ENABLE did not trace my sessions. In the end I created a true RAC service with CLB and RLB goals against both instances and I ended up with traces in the diagnostic_dest.

After setting up the UCP connection pool the code will create a number of threads that each will pull a connection from the pool, do some work (*) and hand it back to the pool as good citizens should do.

(*) The do some work bit is this::

...
                        try {

                                PreparedStatement pstmt = conn.prepareStatement(
                                  "select /* bufferbusy001 */ id, to_char(sysdate,'hh24:mi:ss') d " +
                                  "from t1 where id = ? for update");

                                int randomID = new Random().nextInt((1450770 - 1450765) + 1) + 1450765;
                                System.out.println("thread " + mThreadID + " now querying for ID " + randomID);
                                pstmt.setInt(1, randomID);

                                ResultSet rs = pstmt.executeQuery();

                                while (rs.next()) {
                                        System.out.println("Thread " + mThreadID + " reporting an id of "
                                        + rs.getInt("id") + ". Now it is " + rs.getString("d"));
                                }

                                rs.close();
                                pstmt.close();
                                conn.rollback();
                                conn.close();
                                conn = null;

                                Thread.sleep(2000);
                        } catch (Exception e) {
                                e.printStackTrace();
                        }
...

I think that’s how a Java developer would do it (with more error handling of course) but then I’m not a Java developer. It did work though! What I considered most important was to generate contention on a single block. Using dbms_rowid I could find out which IDs belong to (a random) block:

SQL> select * from (
  2    select id,DBMS_ROWID.ROWID_BLOCK_NUMBER (rowid, 'BIGFILE') as block
  3      from t1
  4 ) where block = 11981654;

        ID      BLOCK
---------- ----------
   1450765   11981654
   1450766   11981654
   1450767   11981654
   1450768   11981654
   1450769   11981654
   1450770   11981654

6 rows selected.

So if I manage to randomly select from the table where ID in the range …765 to …770 then I should be ok and just hit that particular block.

It turned out that the SQL statement completed so quickly I had to considerably ramp up the number of sessions in the pool to see anything. I went up from 10 to 500 before I could notice a change. Most of the statements are too quick to even be caught in ASH-Tanel’s ashtop script showed pretty much nothing except ON-CPU occasionally as well as the odd log file sync event. Snapper also reported sessions in idle state.

SQL> r
  1  select count(*), inst_id, status, sql_id, event, state
  2  from gv$session where module = 'BufferBusy'
  3* group by inst_id, status, sql_id, event, state

  COUNT(*)    INST_ID STATUS   SQL_ID        EVENT                          STATE
---------- ---------- -------- ------------- ------------------------------ -------------------
       251          1 INACTIVE               SQL*Net message from client    WAITING
       248          2 INACTIVE               SQL*Net message from client    WAITING

2 rows selected.

That’s what you see for most of the time.

Let me trace this for you

So in order to get any meaningful idea about the occurrence (or absence) of the gc buffer busy acquire event I added a MODULE to my sessions so I can later on run trcsess to combine traces. Here is the resulting raw trace, or rather an excerpt from it:

=====================
PARSING IN CURSOR #140650659166120 len=96 dep=0 uid=65 oct=3 lid=65 tim=4170152514049 hv=1500360262 ad='5b58a4a10' sqlid='6a5jfvpcqvbk6'
select /* bufferbusy001 */ id, to_char(sysdate,'hh24:mi:ss') d from t1 where id = :1  for update
END OF STMT
PARSE #140650659166120:c=0,e=5598,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2291732815,tim=4170152514046
WAIT #140650659166120: nam='gc buffer busy acquire' ela= 12250 file#=6 block#=11981654 class#=1 obj#=20520 tim=4170152526533
WAIT #140650659166120: nam='buffer busy waits' ela= 1890 file#=6 block#=11981654 class#=1 obj#=20520 tim=4170152528475
WAIT #140650659166120: nam='enq: TX - row lock contention' ela= 188606 name|mode=1415053318 usn<<16 | slot=1179674 sequence=1485 obj#=20520 tim=4170152717199
WAIT #140650659166120: nam='gc buffer busy acquire' ela= 1590 file#=6 block#=11981654 class#=1 obj#=20520 tim=4170152718839
WAIT #140650659166120: nam='enq: TX - row lock contention' ela= 36313 name|mode=1415053318 usn<<16 | slot=1245199 sequence=1894 obj#=20520 tim=4170152755340
WAIT #140650659166120: nam='gc buffer busy acquire' ela= 1268 file#=6 block#=11981654 class#=1 obj#=20520 tim=4170152756655
WAIT #140650659166120: nam='buffer busy waits' ela= 668 file#=6 block#=11981654 class#=1 obj#=20520 tim=4170152757363
WAIT #140650659166120: nam='KJC: Wait for msg sends to complete' ela= 11 msg=26941469232 dest|rcvr=65539 mtype=8 obj#=20520 tim=4170152757492
EXEC #140650659166120:c=1999,e=243530,p=0,cr=9,cu=4,mis=0,r=0,dep=0,og=1,plh=2291732815,tim=4170152757651
WAIT #140650659166120: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3=0 obj#=20520 tim=4170152757709
FETCH #140650659166120:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=2291732815,tim=4170152757749
STAT #140650659166120 id=1 cnt=1 pid=0 pos=1 obj=0 op='FOR UPDATE  (cr=9 pr=0 pw=0 time=243443 us)'
STAT #140650659166120 id=2 cnt=2 pid=1 pos=1 obj=0 op='BUFFER SORT (cr=3 pr=0 pw=0 time=60 us)'
STAT #140650659166120 id=3 cnt=1 pid=2 pos=1 obj=48863 op='INDEX RANGE SCAN I_T1$SEC1 (cr=3 pr=0 pw=0 time=37 us cost=3 size=6 card=1)'
WAIT #140650659166120: nam='SQL*Net message from client' ela= 260 driver id=1413697536 #bytes=1 p3=0 obj#=20520 tim=4170152758109
CLOSE #140650659166120:c=0,e=5,dep=0,type=1,tim=4170152758141
XCTEND rlbk=1, rd_only=0, tim=4170152758170
WAIT #0: nam='gc buffer busy acquire' ela= 3764 file#=6 block#=11981654 class#=1 obj#=20520 tim=4170152761976
WAIT #0: nam='buffer busy waits' ela= 1084 file#=6 block#=11981654 class#=1 obj#=20520 tim=4170152763104
WAIT #0: nam='log file sync' ela= 246 buffer#=119491 sync scn=19690898 p3=0 obj#=20520 tim=4170152763502
WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=20520 tim=4170152763536

Result! There are gc buffer busy acquire events recorded. I can’t rule out TX-row lock contention since with all those threads and only 6 IDs to choose from there was going to be some locking on the same ID caused by the “for update” clause.

Now I am reasonably confident that I worked out at least one scenario causing a gc buffer busy acquire. You might also find the location of the blocks in the buffer cache interesting:

SYS:dbm011> select count(*), inst_id, block#, status
  2  from gv$bh where block# = 11981654
  3  group by inst_id, block#, status order by inst_id, status;

   COUNT(*)     INST_ID      BLOCK# STATUS
----------- ----------- ----------- ----------
          9           1    11981654 cr
          1           1    11981654 xcur
          9           2    11981654 cr

There is the one block in XCUR mode and 9 in CR mode in the buffer cache for that block.

Making it worse

Now I didn’t want to stop there, I was interested in what would happen under CPU load. During my career I noticed cluster waits appear primarily when you are CPU-bound (all other things being equal). This could be the infamous middle-tier-connection-pool-mismanagement or an execution plan going wrong with hundreds of users performing nested loop joins when they should hash-join large data sets… This is usually the point where OEM users ask the DBAs to do something against that “sea of grey” in the performance pages.

As with every cluster technology an overloaded CPU does not help. Well-I guess that’s true for all computing. To increase the CPU load I created 10 dd sessions to read from /dev/zero and write to /dev/null. Sounds silly but one of these hogs 1 CPU core 100%. With 10 out of 12 cores 100% occupied that way on node 1 I relaunched my test. The hypothesis that CPU overload has an effect was proven right by suddenly finding ASH samples of my session.

SQL> @ash/ashtop sql_id,session_state,event "sql_id='6a5jfvpcqvbk6'" sysdate-5/1440 sysdate

    Total
  Seconds     AAS %This   SQL_ID        SESSION EVENT
--------- ------- ------- ------------- ------- ----------------------------------------
      373     1.2   79% | 6a5jfvpcqvbk6 WAITING enq: TX - row lock contention
       54      .2   11% | 6a5jfvpcqvbk6 WAITING gc buffer busy release
       20      .1    4% | 6a5jfvpcqvbk6 ON CPU
       11      .0    2% | 6a5jfvpcqvbk6 WAITING gc buffer busy acquire
       11      .0    2% | 6a5jfvpcqvbk6 WAITING gc current block busy
        1      .0    0% | 6a5jfvpcqvbk6 WAITING gc current block 2-way

6 rows selected.

Using ASQLMON I can even see where time is spent:

SQL> @scripts/ash/asqlmon 6a5jfvpcqvbk6 % sysdate-1 sysdate

    SECONDS Activity Visual       Line ID Parent ASQLMON_OPERATION                   SESSION EVENT                                         AVG_P3 OBJ_ALIAS_ ASQLMON_PR
----------- -------- ------------ ------- ------ ----------------------------------- ------- ---------------------------------------- ----------- ---------- ----------
         38    2.4 % |          |       0        SELECT STATEMENT                    ON CPU                                                883065
          1     .1 % |          |       1      0  FOR UPDATE                         WAITING gc current block 2-way                      33554433  [SEL$1]
         25    1.6 % |          |       1      0                                     ON CPU                                            5369727.36  [SEL$1]
         17    1.1 % |          |       1      0                                     WAITING buffer busy waits                                  1  [SEL$1]
        109    6.8 % |#         |       1      0                                     WAITING gc buffer busy release                             1  [SEL$1]
         31    1.9 % |          |       1      0                                     WAITING gc buffer busy acquire                             1  [SEL$1]
         27    1.7 % |          |       1      0                                     WAITING gc current block busy                       33554433  [SEL$1]
        768   48.0 % |#####     |       1      0                                     WAITING enq: TX - row lock contention            6685.143229  [SEL$1]
          3     .2 % |          |       2      1   BUFFER SORT                       ON CPU                                                     0
          2     .1 % |          |       3      2    INDEX RANGE SCAN [I_T1$SEC1]     ON CPU                                                     0 T1@SEL$1 [ [A:]
                                                                                                                                                  SEL$1]     "ID"=:1


          2     .1 % |          |       0        SELECT STATEMENT                    ON CPU                                            16777216.5
          2     .1 % |          |       1      0  FOR UPDATE                         WAITING gc current block busy                       33554433  [SEL$1]
         24    1.5 % |          |       1      0                                     WAITING write complete waits                               0  [SEL$1]
          9     .6 % |          |       1      0                                     WAITING gc buffer busy acquire                             1  [SEL$1]
         30    1.9 % |          |       1      0                                     WAITING gc buffer busy release                             1  [SEL$1]
          9     .6 % |          |       1      0                                     WAITING buffer busy waits                                  1  [SEL$1]
          7     .4 % |          |       1      0                                     ON CPU                                           158.8571429  [SEL$1]
        496   31.0 % |###       |       1      0                                     WAITING enq: TX - row lock contention            6396.395161  [SEL$1]
                   % |          |       2      1   BUFFER SORT
                   % |          |       3      2    INDEX RANGE SCAN [I_T1$SEC1]                                                                  T1@SEL$1 [ [A:]
                                                                                                                                                  SEL$1]     "ID"=:1

Further Reading

I’m sure there is a wealth of resources available out there, in my case Riyaj’s blog helped me a lot. He even tagged posts with gc buffer busy: https://orainternals.wordpress.com/tag/gc-buffer-busy

Have a look at the Oaktable World 2014 agenda and watch Tanel Poder’s session attentively. You’d be surprised how many scripts he made publicly available to troubleshoot perform. Like snapper? It’s only the tip of the iceberg. And if you can, you should really attend his advanced troubleshooting seminar.

UKOUG post conference geek update part 1 – ACFS for Oracle databases

One of the many interesting things I heard at the conference this time around was that Oracle’s future direction includes the use of database files on ACFS. When ACFS came out this was strictly ruled out, but has been possible for a little while now, I believe with 12.1.0.1.0. With the Oracle Database Appliance (ODA) using this deployment option and hearing about it at the conference, a little further investigation was in order. During one of the presentation @OracleRACPM Markus Michalewicz had a reference to a script that I didn’t know on his slides. The script is called gDBClone, and I wanted to see how it works. The idea is that the script can be used to create a snap-clone of a database if the source is on ACFS and in archivelog mode.

As it turned out there were a few hurdles along the way and I will point them out so you don’t run into the same issues.

UPDATE: these hurdles might be there since Oracle databases aren’t supported on ACFS in Oracle Restart: https://docs.oracle.com/database/121/OSTMG/asmfilesystem.htm#OSTMG95961 Please consider yourself warned! For the rest of the article let’s pretend that this is a clustered environment. The article is therefore purely educational and no encouragement to do this in real life.

The script and associated white paper assume that you have two systems-production and dev/test/uat. The goal of the clone procedure is to be able to create a copy of your live database on your dev/test/uat cluster. This database can then be used as the source for ACFS snapshots. This can be represented in ASCII art:


+------+   clone   +------------------+
| PROD |   ---->   |      MASTER      |
+------+           |      /     \     |  snap #1
                   |     /       \    |  snap #2
                   | CLONE1    CLONE2 |
                   +------------------+

It is by no means required to follow this approach, and if nothing else then you can use the clone script to run a RMAN duplication in a single command. I once wrote a script to do the same but this was a truly complex thing to do.

For this article I’ll assume that you clone PROD (named ORCL) to MASTER, and snap MASTER to CLONE1.

The setup

Since my “travel-lab” is not a RAC cluster I opted for an installation of 12.1.0.2.1 for Oracle Restart and the database to keep it simple.

ACFS storage will be provided by and ADVM volume from disk group data. In my case this was quite easy to accomplish. Since this was an 12.1 system anyway I created my DATA disk group with ASM, RDBMS and ADVM compatibility for 12.1.0.2.0.

You create the ASM Dynamic Volume Manager (ADVM) volume on top of the ASM disk group, in my case on DATA. This is a simple task and can be performed by a variety of tools, I opted for a call to asmcmd:

ASMCMD> volcreate
usage: volcreate -G <diskgroup> -s <size> [ --column <number> ] [ --width <stripe_width> ]
[--redundancy {high|mirror|unprotected} ] [--primary {hot|cold}] [--secondary {hot|cold}] <volume>
help:  help volcreate
ASMCMD> volcreate -G data -s 10G volume1
ASMCMD> volinfo --all
Diskgroup Name: DATA

         Volume Name: VOLUME1
         Volume Device: /dev/asm/volume1-162
         State: ENABLED
         Size (MB): 10240
         Resize Unit (MB): 64
         Redundancy: UNPROT
         Stripe Columns: 8
         Stripe Width (K): 1024
         Usage:
         Mountpath:

Initially I got a message that ASM could not communicate with the (ASM) Volume driver.

SQL> /* ASMCMD */alter diskgroup data add volume 'volume1' size 10G
ORA-15032: not all alterations performed
ORA-15477: cannot communicate with the volume driver
ERROR: /* ASMCMD */alter diskgroup data add volume 'volume1' size 10G

This was solved by modprobe calls to the oracle kernel modules.

[root@server5 ~]# modprobe  oracleacfs
[root@server5 ~]# modprobe  oracleadvm
[root@server5 ~]# modprobe  oracleoks
[root@server5 ~]# lsmod | grep oracle
oracleadvm            507006  7
oracleacfs           3307457  1
oracleoks             505749  2 oracleadvm,oracleacfs

There is a known issue with the execution of udev rules (/etc/udev/rules.d/55-usm.rules) that might delay the setting of permissions. On my system a udevadm trigger solved it. Still odd (Oracle Linux 6.6/ UEK 3 3.8.13-44.1.1.el6uek.x86_64), especially since a call to acfsdriverstate supported stated it was supported.

Once the volume is created it needs to be formatted using ACFS. This can be done in this way:

[oracle@server5 ~]$  mkfs -t acfs /dev/asm/volume1-162
mkfs.acfs: version                   = 12.1.0.2.0
mkfs.acfs: on-disk version           = 39.0
mkfs.acfs: volume                    = /dev/asm/volume1-162
mkfs.acfs: volume size               = 10737418240  (  10.00 GB )
mkfs.acfs: Format complete.

Trying to register the file system in the ACFS registry pointed me to the first problem with the procedure on Oracle Restart:

[root@server5 ~]# acfsutil registry -a /dev/asm/volume1-162 /u01/oradata
Usage: srvctl <command> <object> [<options>]
    commands: enable|disable|start|stop|status|add|remove|modify|update|getenv|setenv|
       unsetenv|config|upgrade|downgrade
    objects: database|service|asm|diskgroup|listener|home|ons
For detailed help on each command and object and its options use:
  srvctl <command> -help [-compatible] or
  srvctl <command> <object> -help [-compatible]
PRKO-2012 : filesystem object is not supported in Oracle Restart
acfsutil registry: ACFS-03111: unable to add ACFS mount /u01/oradata within Oracle Registry

Interesting-but not a problem in the lab. I usually mount file systems where in my opinion they logically belong to. In this case I mounted the file system to /u01/oradata. Spoiler alert: this is not what you are supposed to do if you want to use the gDBClone script.

To cut a long story short, the mount point was assumed to be in /acfs for a snap’d or cloned database. The script also assumes that your system is a RAC environment, and I found it not to work well in 12.1 at all due to the way it tries to get the database version from the OCR (OLR) profile. First the new ACFS file system is mounted, then made accessible to the oracle user:

[root@server5 ~]# mount -t acfs /dev/asm/volume1-162 /acfs
[root@server5 ~]# chown -R oracle:dba /acfs
[root@server5 ~]# mount | grep acfs
/dev/asm/volume1-162 on /acfs type acfs (rw)

Creating the MASTER database

My source system resides in ASM, and there is no way of creating COW clones in ASM. The MASTER database must be moved to ACFS first as a result, from where you can take storage snapshots.

A quick hack was required since I only had 1 machine, so I created the source database (PROD in the ASCII art example) as “orcl” using the following call to dbca and setting it to archivelog mode:

dbca -silent -createDatabase -templateName General_Purpose.dbc  -gdbname orcl \
> -sid orcl -sysPassword pwd1 -systemPassword pwd2  -emConfiguration none  \
> -storageType ASM  -asmsnmpPassword pwd3 -diskGroupName data -recoveryGroupName reco  \
> -totalMemory 2048

The next step is to create the MASTER database. The gDBClone script checks if a database is on ACFS in function checkIfACFS(). If a database is found to be on ASM (by checking the SPFILE location in the Clusterware profile) it requires it to be CLONED as opposed to SNAPped. Here is the command to clone ORCL to MASTER. You must set your environment to an RDBMS home before executing the script.

# ./gDBClone clone -sdbname orcl -sdbhost server5 -sdbport 1521 -tdbname master -acfs /acfs -debug

It uses a RMAN duplicate under the covers. The arguments are almost self-explanatory. It takes the location of the source database (can be remote) and where you want to store the database. Since I desperately want to store the clone on ACFS I specified it in the command. The -debug flag prints more verbose output, a lot of information is also found in /var/log/gDBName/. Note that the script is to be run as root :(

To get there a few tricks were necessary in Oracle Restart environments, I’ll feed them back to Oracle to see if they can be added to the script. You probably won’t encounter problems when using a clustered 11.2 installation.

At one point the script checks the VERSION flag in the database resource profile (crsctl stat res ora..db -p | grep ‘^VERSION’, and since that field no longer shows up in 12.1 the variable is undefined in perl and the execution fails. The problem with Oracle Restart is related to setting the database type to SINGLE on the local host (srvctl add database … -c SINGLE -x …). Oracle Restart doesn’t understand those switches. Also you can’t set the db_unique_name in 12c to a name of a database already registered in the OCR. Moving the step to register the database further down in the execution helped.

Please don’t get me wrong: the script is very neat in that it allows you to run an RMAN duplicate command over the network, potentially creating the backup on the fly. In 12c RMAN will pull backup pieces if they exist instead of creating a backup on the fly to reduce its impact on the production database. Oh and I forgot-you can even convert it to a clustered database if it is not already.

Creating an ACFS clone database

Next up is the creation of the CLONE database. My first attempts were unsuccessful. The main trick seems to be to keep the ACFS mount underneath the / (root) file system. Mounting it elsewhere caused the script to fail. If you can read perl, check the $acfs variable and checkIfACFS() routine to understand why. Also, the compatibility of your ASM diskgroup containing the volume has to be greater than 11.2.0.3 or you get this error:

[root@server5 ~]# ./gDBClone snap -sdbname master -tdbname clone1
2014-12-12 11:03:53: I Getting host info...
2014-12-12 11:03:53: I Starting.....
2014-12-12 11:03:53: I Validating environment.....

Enter the source MASTER SYSDBA password:
2014-12-12 11:03:56: I Getting OH version...
2014-12-12 11:04:04: I Checking SCAN listener server5.example.com:1521...
2014-12-12 11:04:05: I Checking database CLONE1 existence...
2014-12-12 11:04:05: I Checking registered instance CLONE1 ...
2014-12-12 11:04:10: I Checking if the Source Database MASTER it's on ASM
2014-12-12 11:04:10: I Source Database MASTER it's on ACFS
2014-12-12 11:04:10: I Checking snapshot CLONE1 existence
2014-12-12 11:04:10: I Setting up clone environment....
2014-12-12 11:04:10: I Starting auxiliary listener....
2014-12-12 11:05:10: I Creating ACFS snapshot.....
2014-12-12 11:05:10: I Start/stop MASTER to check consistency.
2014-12-12 11:05:42: I Checking if the source database MASTER is stored on an ACFS snapshot
acfsutil snap create: ACFS-03048: Snapshot operation could not complete.
acfsutil snap create: ACFS-03174: The Oracle ASM Dynamic Volume Manager (Oracle ADVM) compatibility
    attribute for the disk group is less than 11.2.0.3.0.
2014-12-12 11:05:42: E Error getting ACFS snapshot

This can be fixed quite easily provided that you don’t break anything. Remember that compatibility can be raised but never lowered. With everything in place, the clone is quick:

[root@server5 ~]# ./gDBClone snap -sdbname master -tdbname clone1
2014-12-12 11:20:17: I Getting host info...
2014-12-12 11:20:17: I Starting.....
2014-12-12 11:20:17: I Validating environment.....

Enter the source MASTER SYSDBA password:
2014-12-12 11:20:19: I Getting OH version...
2014-12-12 11:20:27: I Checking SCAN listener server5.example.com:1521...
2014-12-12 11:20:27: I Checking database CLONE1 existence...
2014-12-12 11:20:28: I Checking registered instance CLONE1 ...
2014-12-12 11:20:31: I Checking if the Source Database MASTER it's on ASM
2014-12-12 11:20:31: I Source Database MASTER it's on ACFS
2014-12-12 11:20:31: I Checking snapshot CLONE1 existence
2014-12-12 11:20:31: I Setting up clone environment....
2014-12-12 11:20:31: I Starting auxiliary listener....
2014-12-12 11:21:31: I Creating ACFS snapshot.....
2014-12-12 11:21:31: I Start/stop MASTER to check consistency.
2014-12-12 11:21:58: I Checking if the source database MASTER is stored on an ACFS snapshot
2014-12-12 11:21:58: I Setting up snapshot database.....
2014-12-12 11:21:58: I Creating Clone parameter files
2014-12-12 11:22:01: I Activating clone database.....
PRKO-2002 : Invalid command line option: -j
2014-12-12 11:23:04: I Successfully created clone "CLONE1" database

Now what does this database look like? I remember a conversation with Andy Colvin about this since he saw it on our ODA first, but consider this:

[oracle@server5 ~]$ sq

SQL*Plus: Release 12.1.0.2.0 Production on Fri Dec 12 11:51:22 2014

Copyright (c) 1982, 2014, Oracle.  All rights reserved.

Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options

SQL> select name from v$datafile;

NAME
--------------------------------------------------------------------------------
/acfs/.ACFS/snaps/CLONE1/MASTER/MASTER/datafile/o1_mf_system_b8p3pxs7_.dbf
/acfs/.ACFS/snaps/CLONE1/MASTER/MASTER/datafile/o1_mf_sysaux_b8p3pz4f_.dbf
/acfs/.ACFS/snaps/CLONE1/MASTER/MASTER/datafile/o1_mf_undotbs1_b8p3q2q0_.dbf
/acfs/.ACFS/snaps/CLONE1/MASTER/MASTER/datafile/o1_mf_users_b8p3qo2o_.dbf

Now the interesting thing is when you look into that top-level ACFS directory:

SQL> !ls -la /acfs/
total 76
drwxr-xr-x.  5 oracle dba       4096 Dec 12 10:35 .
dr-xr-xr-x. 27 root   root      4096 Dec 12 10:30 ..
drwx------.  2 oracle dba      65536 Dec 12 10:31 lost+found
drwxr-xr-x.  3 oracle oinstall  4096 Dec 12 10:52 MASTER

No .ACFS file! Even more interestingly, you can actually see what’s in the .ACFS directory when referring to it directly

SQL> !ls -l /acfs/.ACFS
total 8
drwxrwx---. 6 root root 4096 Dec 12 10:31 repl
drwxr-xr-x. 3 root root 4096 Dec 12 11:21 snaps

What I want to do next is to run a few performance benchmarks on a database in ACFS to see how it holds up. But that’s for another day…

Little things worth knowing: creating the Swingbench order entry schema “lights out”

This is a little note, primarily to myself I guess, about the creation of the order entry schema (part of Swingbench, written by Dominic Giles) when no VNC sessions are available (although you can almost always use port-forwarding :). Instead, you can create the schema on the command line. I always execute commands on remote systems in screen for increased peace of mind. Should the network drop, the order entry generation will continue as if nothing ever happened.

Like many others I use Swingbench during trainings and presentations to have some activity on a system. Very useful for demonstrating ASH and OEM, and many other things too!

This article references swingbench 2.5, the latest version at the time of writing. It requires a JDK to be present, I simply used the one bundled with Oracle 12.1.0.2.0 which is my target database version. You first start by downloading Swingbench from Dominic’s website and unzip it in a directory from where you want to run it. It is usually a good idea to keep the load generator on a different (set of) machine(s). As long as you can connect to the database you want to use to house the SOE schema you’re fine.

Creating the SOE schema

Before you can run swingbench (or minibench/charbench) you need to create the SOE schema. The oewizard is the tool of choice. If you haven’t done so, add java to your path. Then you can have a look at the available options:

$ JAVA_HOME=/u01/app/oracle/product/12.1.0.2/dbhome_1/jdk
$ export PATH=$PATH:$JAVA_HOME/bin

$ ./oewizard -h
usage: parameters:
 -allindexes             build all indexes for schema
 -bigfile                use big file tablespaces
 -c <filename>           wizard config file
 -cl                     run in character mode
 -compositepart          use a composite paritioning model if it exisits
 -compress               use default compression model if it exists
 -create                 create benchmarks schema
 -cs <connectString>     connectring for database
 -dba <username>         dba username for schema creation
 -dbap <password>        password for schema creation
 -debug                  turn on debugging output
 -debugf                 turn on debugging output to file (debug.log)
 -df <datafile>          datafile name used to create schema in
 -drop                   drop benchmarks schema
 -dt <driverType>        driver type (oci|thin)
 -g                      run in graphical mode (default)
 -generate               generate data for benchmark if available
 -h,--help               print this message
 -hashpart               use hash paritioning model if it exists
 -hcccompress            use HCC compression if it exisits
 -nocompress             don't use any database compression
 -noindexes              don't build any indexes for schema
 -nopart                 don't use any database partitioning
 -normalfile             use normal file tablespaces
 -oltpcompress           use OLTP compression if it exisits
 -p <password>           password for benchmark schema
 -part                   use default paritioning model if it exists
 -pkindexes              only create primary keys for schema
 -rangepart              use a range paritioning model if it exisits
 -s                      run in silent mode
 -scale <scale>          mulitiplier for default config
 -sp <soft partitions>   the number of softparitions used. Defaults to cpu
                         count
 -tc <thread count>      the number of threads(parallelism) used to
                         generate data. Defaults to cpus*2
 -ts <tablespace>        tablespace to create schema in
 -u <username>           username for benchmark schema
 -v                      run in verbose mode when running from command
                         line
 -version <version>      version of the benchmark to run

Note that not all partitioning schemes are valid in this case, and neither are all compression methods. I found the below command to create the schema the way I want it.

./oewizard -allindexes -cl -create -cs //cluster-scan/sbench -dba martin \
> -dbap notTellingYouHere -ts soe_tbs -part -p soe -scale 8 -tc 8 -u soe -v

SwingBench Wizard
Author  :        Dominic Giles
Version :        2.5.0.949

Running in Lights Out Mode using config file : oewizard.xml
Connecting to : jdbc:oracle:thin:@//cluster-scan/sbench
Connected
Starting script ../sql/soedgcreateuser.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 104 millisecond(s)
Starting run
Starting script ../sql/soedgdrop2.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 55 millisecond(s)
Starting script ../sql/soedgcreatetableshash2.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 520 millisecond(s)
Starting script ../sql/soedgviews.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 19 millisecond(s)
Starting script ../sql/soedgsqlset.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 84 millisecond(s)
Inserting data into table ADDRESSES_11499978
Inserting data into table ADDRESSES_3999993

-- more data

Completed processing table LOGON_7943271 in 0:00:25
Connection cache closed
Starting script ../sql/soedganalyzeschema2.sql
Script completed in 0 hour(s) 1 minute(s) 20 second(s) 701 millisecond(s)
Starting script ../sql/soedgconstraints2.sql
Script completed in 0 hour(s) 1 minute(s) 41 second(s) 520 millisecond(s)
Starting script ../sql/soedgindexes2.sql
Script completed in 0 hour(s) 0 minute(s) 44 second(s) 685 millisecond(s)
Starting script ../sql/soedgsequences2.sql
Script completed in 0 hour(s) 0 minute(s) 3 second(s) 53 millisecond(s)
Starting script ../sql/soedgpackage2_header.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 215 millisecond(s)
Starting script ../sql/soedgpackage2_body.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 127 millisecond(s)
Starting script ../sql/soedgsetupmetadata.sql
Script completed in 0 hour(s) 0 minute(s) 0 second(s) 614 millisecond(s)

============================================
|           Datagenerator Run Stats        |
============================================
Connection Time                        0:00:00.005
Data Generation Time                   0:10:38.185
DDL Creation Time                      0:03:51.630
Total Run Time                         0:14:29.823
Rows Inserted per sec                      151,713
Data Generated (MB) per sec                   12.1
Actual Rows Generated                   97,718,288

Connecting to : jdbc:oracle:thin:@//cluster-scan/sbench
Connected

Post Creation Validation Report
===============================
The creation of the schema appears to have been unsuccessful. See the following sections for further details.

Valid Objects
=============
Valid Tables : 'ORDERS','ORDER_ITEMS','CUSTOMERS','WAREHOUSES','ORDERENTRY_METADATA','INVENTORIES',
'PRODUCT_INFORMATION','PRODUCT_DESCRIPTIONS','ADDRESSES','CARD_DETAILS'
Valid Indexes : 'ORD_CUSTOMER_IX','ORD_ORDER_DATE_IX','ORD_WAREHOUSE_IX','ORDER_ITEMS_PK','ITEM_ORDER_IX',
'ITEM_PRODUCT_IX','CUST_EMAIL_IX','CUST_ACCOUNT_MANAGER_IX','CUST_FUNC_LOWER_NAME_IX',
'CARDDETAILS_CUST_IX''PRD_DESC_PK','PROD_NAME_IX','PRODUCT_INFORMATION_PK','PROD_SUPPLIER_IX',
'PROD_CATEGORY_IX','INVENTORY_PK','INV_PRODUCT_IX','INV_WAREHOUSE_IX','ORDER_PK',
'ORD_SALES_REP_IX','WAREHOUSES_PK','WHS_LOCATION_IX','CUSTOMERS_PK','ADDRESS_PK',
'ADDRESS_CUST_IX',
'CARD_DETAILS_PK'
Valid Views : 'PRODUCTS','PRODUCT_PRICES'
Valid Sequences : 'CUSTOMER_SEQ','ORDERS_SEQ','ADDRESS_SEQ','LOGON_SEQ','CARD_DETAILS_SEQ'
Valid Code :

Invalid Objects (1)
================
Invalid Tables :
Invalid Indexes :
Invalid Views :
Invalid Sequences :
Invalid Code : 'ORDERENTRY'

Missing Objects (0)
================
Missing Tables :
Missing Indexes : 
Missing Views :
Missing Sequences :
Missing Code :
Schema Created

To compile the package SYS needs to grant execute on DBMS_LOCK to SOE.

This results in a schema with the following number of rows:

SQL> declare
  2   v_cnt number;
  3  begin
  4   for i in (select table_name from dba_tables where owner='SOE') loop
  5    execute immediate 'select count(*) from soe.' || i.table_name into v_cnt;
  6    dbms_output.put_line(i.table_name || ' - ' || to_char(v_cnt, '999,999,999'));
  7   end loop;
  8  end;
  9  /
ORDER_ITEMS -   34,316,243
ORDERS -   11,438,320
INVENTORIES -      896,853
PRODUCT_INFORMATION -        1,000
LOGON -   19,063,872
PRODUCT_DESCRIPTIONS -        1,000
ORDERENTRY_METADATA -            4
CUSTOMERS -    8,000,000
ADDRESSES -   12,000,000
CARD_DETAILS -   12,000,000
WAREHOUSES -        1,000

PL/SQL procedure successfully completed.

Elapsed: 00:00:02.70

SQL> compute sum of m on report
SQL> break on report

SQL> select sum(bytes)/power(1024,2) m, segment_name, segment_type
  2   from dba_segments where owner = 'SOE'
  3  group by segment_name, segment_type
  4  order by 1;

              M SEGMENT_NAME                   SEGMENT_TYPE
--------------- ------------------------------ ------------------
            .06 WAREHOUSES                     TABLE
            .06 PRODUCT_INFORMATION_PK         INDEX
            .06 ORDERENTRY_METADATA            TABLE
            .13 WHS_LOCATION_IX                INDEX
            .13 PROD_CATEGORY_IX               INDEX
            .13 WAREHOUSES_PK                  INDEX
            .13 PROD_SUPPLIER_IX               INDEX
            .13 PROD_NAME_IX                   INDEX
            .13 PRD_DESC_PK                    INDEX
            .25 PRODUCT_INFORMATION            TABLE
            .31 PRODUCT_DESCRIPTIONS           TABLE
          16.69 INV_WAREHOUSE_IX               INDEX
          16.69 INV_PRODUCT_IX                 INDEX
          18.00 INVENTORY_PK                   INDEX
          88.00 INVENTORIES                    TABLE
         169.00 CUST_ACCOUNT_MANAGER_IX        INDEX
         177.06 CUSTOMERS_PK                   INDEX
         204.06 CUST_DOB_IX                    INDEX
         242.19 ORD_SALES_REP_IX               INDEX
         253.38 ORDER_PK                       INDEX
         254.31 CUST_FUNC_LOWER_NAME_IX        INDEX
         265.06 ORD_CUSTOMER_IX                INDEX
         265.69 ADDRESS_PK                     INDEX
         265.75 CARD_DETAILS_PK                INDEX
         276.88 CARDDETAILS_CUST_IX            INDEX
         278.13 ORD_WAREHOUSE_IX               INDEX
         278.50 ADDRESS_CUST_IX                INDEX
         291.88 ORD_ORDER_DATE_IX              INDEX
         347.81 CUST_EMAIL_IX                  INDEX
         717.88 ITEM_PRODUCT_IX                INDEX
         788.94 ITEM_ORDER_IX                  INDEX
         864.00 LOGON                          TABLE PARTITION
         968.00 CARD_DETAILS                   TABLE PARTITION
       1,352.00 CUSTOMERS                      TABLE PARTITION
       1,408.00 ADDRESSES                      TABLE PARTITION
       1,544.00 ORDERS                         TABLE PARTITION
       2,368.00 ORDER_ITEMS                    TABLE PARTITION
---------------
      13,721.38
37 rows selected.

Happy benchmarking!