Oracle … as usual

Oracle by Laurent Leturgez

Insert data in Oracle with Java … Batched mode.

Problem / Context

Today, I worked on a performance issue at my customer. The context is a Java app which did a processing and at the end of this processing, the application inserts tons of data on an Oracle database.

The customers was complaining about slow performance on the insertion phase and asked me to have a look on it.

Database was IO Bound, and many sessions were doing some one-row inserts on various tables (INSERT INTO … VALUES (:1, :2, …) ). These one-row insert were off course processed many times, and oracle session’s stats was reporting a high number of executions.

On the Java side

As an Oracle DBA or Developer, we all know that, with PLSQL, it’s easy to write a FORALL loop that will bulk insert the data, and then reduce execution time. To do that, you need to have a cursor which is read in bulkl (BULK COLLECT) and each part is then inserted in the database. This reduces the number of operations, loops etc.


DECLARE
CURSOR s_cur IS
SELECT *
FROM servers;

TYPE fetch_array IS TABLE OF s_cur%ROWTYPE;
s_array fetch_array;
BEGIN
OPEN s_cur;
LOOP
FETCH s_cur BULK COLLECT INTO s_array LIMIT 1000;

FORALL i IN 1..s_array.COUNT
INSERT INTO servers2 VALUES s_array(i);

EXIT WHEN s_cur%NOTFOUND;
END LOOP;
CLOSE s_cur;
COMMIT;
END;
/

Source: http://psoug.org/snippet/FORALL-Insert_499.htm

In Java, the problem can be different because the data processed by your app are not necesseraly coming from a database.

Usually, statements are prepared, variables are attached and the statement is executed. When it’s done in a loop, it looks something like that:


try{
         DriverManager.registerDriver (new oracle.jdbc.driver.OracleDriver());
         Connection c = DriverManager.getConnection ("jdbc:oracle:thin:@192.168.99.8:1521:orcl","laurent","laurent");
         PreparedStatement stmt = c.prepareStatement("insert into emp(employee_id,first_name,last_name,salary) values (?,?,?,?)");
         start=System.currentTimeMillis();

         for (int i=0 ; i < 50000 ; i++) {
                  stmt.setInt(1,i);
                  stmt.setString(2,generateRandomChars("01234567890ABCDEF",16));
                  stmt.setString(3,generateRandomChars("01234567890ABCDEF",16));
                  stmt.setInt(4,r.nextInt(10000+1)+5000);
                  stmt.executeUpdate();
         }
         stop=System.currentTimeMillis();
         System.out.println("time = "+(stop-start));
         stmt.close();
         c.close();
   }
   catch(Exception e){
      System.err.println(e);
      e.printStackTrace();
   }

The problem is the statement is sent to the database 50000 times, and then increase number of operation between the database and the application. As a result, execution time is high (this demo has been executed on a VM on my laptop):

[oracle@oel6 JAVA]$ time java -cp $CLASSPATH:ojdbc7.jar:. TestNoBatchedInsert
time = 75430

real    1m16.514s
user    0m5.279s
sys     0m1.080s

As for PLSQL, there is a technique to write a beautiful and powerful java code that will process inserts by batchs, and then reduce the number of loops, calls between database and application etc.

To do that, instead of using executeStatement method X times, we can use the addBatch method that will create a “batch” which will be executed on the database when PreparedStatement’s method “executeBatch” will be called.

If you’re familiar with FORALL in PLSQL, you probably know that, the more the batchsize is big, the more memory you will use. In Java, it will be the same and the result will be a bigger heap size, that’s why it’s recommended to define a batch size and each time your batch will reach a max size, the batch will be executed. This can be done like this:

try{
        DriverManager.registerDriver (new oracle.jdbc.driver.OracleDriver());
        Connection c = DriverManager.getConnection ("jdbc:oracle:thin:@192.168.99.8:1521:orcl","laurent","laurent");
        PreparedStatement stmt = c.prepareStatement("insert into emp(employee_id,first_name,last_name,salary) values (?,?,?,?)");
        start=System.currentTimeMillis();

        int batchSize=5000;
        int count=0;
        for (int i=0 ; i < 50000 ; i++) {
                stmt.setInt(1,i);
                stmt.setString(2,generateRandomChars("01234567890ABCDEF",16));
                stmt.setString(3,generateRandomChars("01234567890ABCDEF",16));
                stmt.setInt(4,r.nextInt(10000+1)+5000);
                stmt.addBatch();

                if (++count % batchSize == 0) {
                        stmt.executeBatch();
                }
        }

        stop=System.currentTimeMillis();
        System.out.println("time = "+(stop-start));
        stmt.close();
        c.close();
}
catch(Exception e){
  System.err.println(e);
  e.printStackTrace();
}

Now, if I run this program, wall time is not really the same scale:

[oracle@oel6 JAVA]$ time java -cp $CLASSPATH:ojdbc7.jar:. TestBatchedInsert
time = 598

real    0m1.964s
user    0m3.393s
sys     0m0.269s

On the database side

AWR Reports show many things:

  • First,  if we run the java sample codes as they are described, the no batch mode will commit the database after each execute update. As a result, log file switch event will increase:

Non batched inserts:

Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                                           Total Wait       Wait   % DB Wait
Event                                Waits Time (sec)    Avg(ms)   time Class
------------------------------ ----------- ---------- ---------- ------ --------
log file sync                       49,999         64       1.28   86.8 Commit
DB CPU                                            9.3              12.6
db file sequential read                 47          0       0.97     .1 User I/O
SQL*Net message to client           50,012          0       0.00     .1 Network
log file switch completion               1          0      27.60     .0 Configur
undo segment extension                   2          0       5.16     .0 Configur
direct path write                        3          0       1.08     .0 User I/O
direct path sync                         1          0       3.15     .0 User I/O
Disk file operations I/O                19          0       0.04     .0 User I/O
control file sequential read           194          0       0.00     .0 System I

Batched inserts:

Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                                           Total Wait       Wait   % DB Wait
Event                                Waits Time (sec)    Avg(ms)   time Class
------------------------------ ----------- ---------- ---------- ------ --------
DB CPU                                             .3              72.9
SQL*Net more data from client          268          0       0.17   10.1 Network
log file sync                           13          0       3.29    9.5 Commit
db file sequential read                 49          0       0.37    4.0 User I/O
Disk file operations I/O                17          0       0.03     .1 User I/O
control file sequential read           134          0       0.00     .1 System I
SQL*Net more data to client             10          0       0.02     .1 Network
SQL*Net message to client               22          0       0.00     .0 Network
log file single write                    0          0                .0 System I
asynch descriptor resize                 0          0                .0 Other
  • Then, due to batched process, number of buffer gets is reduced when batched inserts are used

Non batched inserts:

Segments by Logical Reads                   DB/Inst: ORCL/orcl  Snaps: 200-201
-> Total Logical Reads:         212,288
-> Captured Segments account for   28.4% of Total
-> When ** MISSING ** occurs, some of the object attributes may not be available

                     Tablespace
Owner                   Name
-------------------- ----------
                     Subobject  Obj.                             Logical
Object Name            Name     Type        Obj#   Dataobj#        Reads  %Total
-------------------- ---------- ----- ---------- ---------- ------------ -------
LAURENT              USERS
EMP                             TABLE      93857      93860       52,576   24.77

Batched inserts:
Segments by Logical Reads                   DB/Inst: ORCL/orcl  Snaps: 201-202
-> Total Logical Reads:          11,792
-> Captured Segments account for   83.0% of Total
-> When ** MISSING ** occurs, some of the object attributes may not be available

                     Tablespace
Owner                   Name
-------------------- ----------
                     Subobject  Obj.                             Logical
Object Name            Name     Type        Obj#   Dataobj#        Reads  %Total
-------------------- ---------- ----- ---------- ---------- ------------ -------
LAURENT              USERS
EMP                             TABLE      93857      93860        3,504   29.72
  • Same for buffer gets. Execution number is less for batched inserts (number of execution depends on your batch size)

Non batched inserts:

     Buffer                 Gets              Elapsed
      Gets   Executions   per Exec   %Total   Time (s)  %CPU   %IO    SQL Id
----------- ----------- ------------ ------ ---------- ----- ----- -------------
    152,587      50,000          3.1   71.9        2.1  11.3     0 7c9ws5uvx9nyc
Module: JDBC Thin Client
insert into emp(employee_id,first_name,last_name,salary) values (:1 ,:2 ,:3 ,:4
)

Batched inserts:

     Buffer                 Gets              Elapsed
      Gets   Executions   per Exec   %Total   Time (s)  %CPU   %IO    SQL Id
----------- ----------- ------------ ------ ---------- ----- ----- -------------
      3,669          10        366.9   31.1        0.1    57     0 7c9ws5uvx9nyc
Module: JDBC Thin Client
insert into emp(employee_id,first_name,last_name,salary) values (:1 ,:2 ,:3 ,:4)

 

When developer have to insert tons on data from a java app, it’s better when they used the best way to do it …. batched inserts have to be used in that case, it will help the database to be more powerful.

That’s it for today 😉

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google+ photo

You are commenting using your Google+ account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

w

Connecting to %s

%d bloggers like this: