Welcome to Experts Exchange

Add your voice to the tech community where 5M+ people, just like you, are talking about what matters.

  • Help others & share knowledge
  • Earn cash & points
  • Learn & ask questions
Solved

Performance issue when calling Oracle functions

Posted on 2008-06-19
14
433 Views
Last Modified: 2010-04-21
My Java code calls a plsql function continuosly for roughly around 100 to 150 times with various parameters.

I gather information in a hashtable and call this plsql function in a loop and the output of each call would be one of the inputs for the next call.

As the program progresses the time it takes to complete each iteration is increasing exponentially...
0
Comment
Question by:ThummalaRaghuveer
  • 9
  • 4
14 Comments
 
LVL 92

Expert Comment

by:objects
ID: 21827694
can u post your loop code

0
 
LVL 2

Author Comment

by:ThummalaRaghuveer
ID: 21827696
Here is the part of the code that does it

 public void getRefLines(OAPageContext pageContext, OAWebBean webBean,int oldQuoteHeaderId,int copyQuoteHeaderId,int quoteHeaderId,int quoteLineId,int qotLineNumber,CallableStatement cstmtLine) throws SQLException
    {
      long strtTime;
      long endTime;
      TestAMImpl quoteMergeAM = (TestAMImpl)pageContext.getApplicationModule(webBean);
      Connection conn = quoteMergeAM.getOADBTransaction().getJdbcConnection();
      String sqlString = "SELECT     quote_line_id, ref_line_id "+
              " FROM (SELECT quote_line_id, ref_line_id "+
              "  FROM aso_quote_line_details "+
              "  WHERE quote_line_id IN ( "+
                     " SELECT quote_line_id "+
                       " FROM aso_quote_lines_all "+
                      " WHERE quote_header_id = "+copyQuoteHeaderId+
                        " AND line_number = (SELECT line_number "+
                         "                     FROM aso_quote_lines_all "+
                         "                    WHERE quote_line_id = "+quoteLineId+") "+
                         "AND service_item_flag = \'N\') )"+
              "CONNECT BY PRIOR quote_line_id = ref_line_id "+
              "START WITH ref_line_id IS NULL "+
              "ORDER BY LEVEL";
              System.out.println(sqlString);
        Hashtable lines = new Hashtable();
        Hashtable refLineMapping = new Hashtable();
        Hashtable lineMapping = new Hashtable();
        Statement stmt = conn.createStatement();
        ResultSet rs = stmt.executeQuery(sqlString);
        System.out.println("level 1.1");
        int newConfigHeaderId = 0;
        int newBaseLineId = 0;
       
        while (rs.next())
        {
          System.out.println("Creating Line Id :"+rs.getString(1));
          //lines.put(rs.getString(1),rs.getString(2));
          if (rs.getRow() ==1)
          {
            System.out.println("Creating config :"+rs.getString(1));
            System.out.println("getting config header:"+rs.getString(1));
            String sqlConfigString = "SELECT config_header_id,config_revision_num "+
                                "FROM aso_quote_line_details aqld "+
                                "WHERE aqld.quote_line_id = "+rs.getString(1)+" AND config_header_id IS NOT NULL";
            Statement cfgStmt = conn.createStatement();
            ResultSet rsCfg = cfgStmt.executeQuery(sqlConfigString);    
            int configHeaderId = 0;
            int configRevisionNum = 0;
            while(rsCfg.next())
            {
              configHeaderId = rsCfg.getInt(1);
              configRevisionNum = rsCfg.getInt(2);
              System.out.println("got config :"+configHeaderId);
            }
            rsCfg.close();
            if (configHeaderId != 0)
            {
             
              System.out.println("Prepared statement config:"+"{?=call xxr_create_CONFIG("+configHeaderId+","+configRevisionNum+")}");
              strtTime = System.currentTimeMillis();
              CallableStatement cstmt = conn.prepareCall("{?=call xxr_create_CONFIG("+configHeaderId+","+configRevisionNum+")}");
             
              //cstmt.registerOutParameter(1,srcQuoteHeaderId);
              cstmt.registerOutParameter(1,OracleTypes.NUMBER);
              cstmt.execute();
              newConfigHeaderId = cstmt.getInt(1);
              endTime = System.currentTimeMillis();
              System.out.println("Took "+(endTime - strtTime)+" milliseconds for creating config header");

              cstmt.close();
              System.out.println("New Config Headerid is :"+newConfigHeaderId);
              quoteMergeAM.getDBTransaction().commit();            
            }
            System.out.println("Prepared call 1 : "+"{?=call xxr_merge_quote_lines("+quoteLineId+","+quoteHeaderId+","+"null,"+newConfigHeaderId+","+qotLineNumber+")}");
            //CallableStatement cstmt = conn.prepareCall("{?=call xxr_merge_quote_lines("+quoteLineId+","+quoteHeaderId+","+"null,"+newConfigHeaderId+","+qotLineNumber+")}");
              strtTime = System.currentTimeMillis();
              cstmtLine.setInt(2,quoteLineId);              
              cstmtLine.setInt(3,quoteHeaderId);
              cstmtLine.setNull(4,OracleTypes.NUMBER);
              cstmtLine.setInt(5,newConfigHeaderId);
              cstmtLine.setInt(6,qotLineNumber);
             
              //cstmt.registerOutParameter(1,srcQuoteHeaderId);
              cstmtLine.registerOutParameter(1,OracleTypes.NUMBER);
              cstmtLine.execute();
              endTime = System.currentTimeMillis();
              System.out.println("Took "+(endTime - strtTime)+" milliseconds for creating Base Line");
              quoteMergeAM.getDBTransaction().commit();
              newBaseLineId = cstmtLine.getInt(1);
             
              //cstmt.close();
              refLineMapping.put(new Integer(quoteLineId),new Integer(newBaseLineId));
          }
          else
          {
            System.out.println("{?=call xxr_merge_quote_lines("+rs.getInt(1)+","+quoteHeaderId+","+refLineMapping.get(new Integer(rs.getInt(2))).toString()+","+newConfigHeaderId+","+qotLineNumber+")}");
            //CallableStatement cstmt = conn.prepareCall("{?=call xxr_merge_quote_lines("+rs.getInt(1)+","+quoteHeaderId+","+refLineMapping.get(new Integer(rs.getInt(2))).toString()+","+newConfigHeaderId+","+qotLineNumber+")}");
              strtTime = System.currentTimeMillis();
              cstmtLine.setInt(2,rs.getInt(1));              
              cstmtLine.setInt(3,quoteHeaderId);
              cstmtLine.setInt(4,Integer.parseInt(refLineMapping.get(new Integer(rs.getInt(2))).toString()));
              cstmtLine.setInt(5,newConfigHeaderId);
              cstmtLine.setInt(6,qotLineNumber);
              //cstmt.registerOutParameter(1,srcQuoteHeaderId);
              cstmtLine.registerOutParameter(1,OracleTypes.NUMBER);
             
              cstmtLine.execute();
              endTime = System.currentTimeMillis();
              System.out.println("Took "+(endTime - strtTime)+" milliseconds for creating Line");
              int newLineId = cstmtLine.getInt(1);
              //cstmt.close();
              refLineMapping.put(new Integer(rs.getInt(1)),new Integer(newLineId));
          }
             
         
           
        }
        cstmtLine.close();
        rs.close();
        quoteMergeAM.getDBTransaction().commit();
         
       
     
     
    }
0
 
LVL 2

Author Comment

by:ThummalaRaghuveer
ID: 21827702
I would really appreciate any kind of discussion on this
0
Free Tool: Subnet Calculator

The subnet calculator helps you design networks by taking an IP address and network mask and returning information such as network, broadcast address, and host range.

One of a set of tools we're offering as a way of saying thank you for being a part of the community.

 
LVL 92

Accepted Solution

by:
objects earned 500 total points
ID: 21827728
whats the logging showing?

have you checked if the time is being spent in the java app, or whether it is a db issue?

0
 
LVL 2

Author Comment

by:ThummalaRaghuveer
ID: 21827794
I am logging the times on the database as well as java side...

DB is taking less than a second to complete its operation....

but java app is taking longer....

Initially its happening fast but as time goes by the timing on the java side increasing exponentially...

towards the end its taking more than 23 seconds for each call
0
 
LVL 2

Author Comment

by:ThummalaRaghuveer
ID: 21827822
Here is the content from the logs on java app side

Creating Line Id :2336
Creating config :2336
getting config header:2336
got config :482520
Prepared statement config:{?=call xxr_create_CONFIG(482520,1)}
Took 110 milliseconds for creating config header
New Config Headerid is :1752700
Prepared call 1 : {?=call xxr_merge_quote_lines(2336,2518,null,1752700,1)}
Took 360 milliseconds for creating Base Line
Creating Line Id :2338
{?=call xxr_merge_quote_lines(2338,2518,56667,1752700,1)}
Took 313 milliseconds for creating Line
Creating Line Id :2342
{?=call xxr_merge_quote_lines(2342,2518,56667,1752700,1)}
Took 359 milliseconds for creating Line
Creating Line Id :2339
{?=call xxr_merge_quote_lines(2339,2518,56667,1752700,1)}
Took 438 milliseconds for creating Line
Creating Line Id :2340
{?=call xxr_merge_quote_lines(2340,2518,56667,1752700,1)}
Took 515 milliseconds for creating Line
Creating Line Id :2345
{?=call xxr_merge_quote_lines(2345,2518,56667,1752700,1)}
Took 594 milliseconds for creating Line
Creating Line Id :2344
{?=call xxr_merge_quote_lines(2344,2518,56667,1752700,1)}
Took 656 milliseconds for creating Line
Creating Line Id :2343
{?=call xxr_merge_quote_lines(2343,2518,56667,1752700,1)}
Took 735 milliseconds for creating Line
Creating Line Id :2341
{?=call xxr_merge_quote_lines(2341,2518,56667,1752700,1)}
Took 844 milliseconds for creating Line
Creating Line Id :2354
{?=call xxr_merge_quote_lines(2354,2518,56672,1752700,1)}
Took 921 milliseconds for creating Line
Creating Line Id :2355
{?=call xxr_merge_quote_lines(2355,2518,56672,1752700,1)}
Took 1016 milliseconds for creating Line
Creating Line Id :2356
{?=call xxr_merge_quote_lines(2356,2518,56672,1752700,1)}
Took 1109 milliseconds for creating Line
Creating Line Id :2353
{?=call xxr_merge_quote_lines(2353,2518,56672,1752700,1)}
Took 1235 milliseconds for creating Line
Creating Line Id :2352
{?=call xxr_merge_quote_lines(2352,2518,56672,1752700,1)}
Took 1344 milliseconds for creating Line
Creating Line Id :2346
{?=call xxr_merge_quote_lines(2346,2518,56673,1752700,1)}
Took 1437 milliseconds for creating Line
Creating Line Id :2347
{?=call xxr_merge_quote_lines(2347,2518,56674,1752700,1)}
Took 1578 milliseconds for creating Line
Creating Line Id :2357
{?=call xxr_merge_quote_lines(2357,2518,56672,1752700,1)}
Took 1719 milliseconds for creating Line
Creating Line Id :2349
{?=call xxr_merge_quote_lines(2349,2518,56675,1752700,1)}
Took 1875 milliseconds for creating Line
Creating Line Id :2350
{?=call xxr_merge_quote_lines(2350,2518,56671,1752700,1)}
Took 2062 milliseconds for creating Line
Creating Line Id :2351
{?=call xxr_merge_quote_lines(2351,2518,56670,1752700,1)}
Took 2235 milliseconds for creating Line
Creating Line Id :2358
{?=call xxr_merge_quote_lines(2358,2518,56668,1752700,1)}
Took 2390 milliseconds for creating Line
Creating Line Id :2348
{?=call xxr_merge_quote_lines(2348,2518,56669,1752700,1)}
Took 2532 milliseconds for creating Line
Quote line id for line 1 is 2359
SELECT     quote_line_id, ref_line_id  FROM (SELECT quote_line_id, ref_line_id   FROM aso_quote_line_details   WHERE quote_line_id IN (  SELECT quote_line_id  FROM aso_quote_lines_all  WHERE quote_header_id = 396 AND line_number = (SELECT line_number                      FROM aso_quote_lines_all                     WHERE quote_line_id = 2359) AND service_item_flag = 'N') )CONNECT BY PRIOR quote_line_id = ref_line_id START WITH ref_line_id IS NULL ORDER BY LEVEL
level 1.1
Creating Line Id :2359
Creating config :2359
getting config header:2359
got config :482521
Prepared statement config:{?=call xxr_create_CONFIG(482521,13)}
Took 79 milliseconds for creating config header
New Config Headerid is :1752701
Prepared call 1 : {?=call xxr_merge_quote_lines(2359,2518,null,1752701,2)}
Took 1688 milliseconds for creating Base Line
Creating Line Id :2361
{?=call xxr_merge_quote_lines(2361,2518,56689,1752701,2)}
Took 1766 milliseconds for creating Line
Creating Line Id :2364
{?=call xxr_merge_quote_lines(2364,2518,56689,1752701,2)}
Took 1969 milliseconds for creating Line
Creating Line Id :2363
{?=call xxr_merge_quote_lines(2363,2518,56689,1752701,2)}
Took 2140 milliseconds for creating Line
Creating Line Id :2362
{?=call xxr_merge_quote_lines(2362,2518,56689,1752701,2)}
Took 2328 milliseconds for creating Line
Creating Line Id :2366
{?=call xxr_merge_quote_lines(2366,2518,56692,1752701,2)}
Took 2547 milliseconds for creating Line
Creating Line Id :2371
{?=call xxr_merge_quote_lines(2371,2518,56692,1752701,2)}
Took 3438 milliseconds for creating Line
Creating Line Id :2365
{?=call xxr_merge_quote_lines(2365,2518,56692,1752701,2)}
Took 4015 milliseconds for creating Line
Creating Line Id :2367
{?=call xxr_merge_quote_lines(2367,2518,56692,1752701,2)}
Took 4016 milliseconds for creating Line
Creating Line Id :2385
{?=call xxr_merge_quote_lines(2385,2518,56690,1752701,2)}
Took 3766 milliseconds for creating Line
Creating Line Id :2401
{?=call xxr_merge_quote_lines(2401,2518,56691,1752701,2)}
Took 3969 milliseconds for creating Line
Creating Line Id :2370
{?=call xxr_merge_quote_lines(2370,2518,56692,1752701,2)}
Took 4250 milliseconds for creating Line
Creating Line Id :2393
{?=call xxr_merge_quote_lines(2393,2518,56693,1752701,2)}
Took 5313 milliseconds for creating Line
Creating Line Id :2369
{?=call xxr_merge_quote_lines(2369,2518,56692,1752701,2)}
Took 5109 milliseconds for creating Line
Creating Line Id :2368
{?=call xxr_merge_quote_lines(2368,2518,56692,1752701,2)}
Took 6234 milliseconds for creating Line
Creating Line Id :2383
{?=call xxr_merge_quote_lines(2383,2518,56696,1752701,2)}
Took 6203 milliseconds for creating Line
Creating Line Id :2397
{?=call xxr_merge_quote_lines(2397,2518,56701,1752701,2)}
Took 6704 milliseconds for creating Line
Creating Line Id :2396
{?=call xxr_merge_quote_lines(2396,2518,56701,1752701,2)}
Took 6875 milliseconds for creating Line
Creating Line Id :2395
{?=call xxr_merge_quote_lines(2395,2518,56701,1752701,2)}
Took 7468 milliseconds for creating Line
Creating Line Id :2394
{?=call xxr_merge_quote_lines(2394,2518,56701,1752701,2)}
Took 8094 milliseconds for creating Line
Creating Line Id :2519
{?=call xxr_merge_quote_lines(2519,2518,56695,1752701,2)}
Took 8609 milliseconds for creating Line
Creating Line Id :2388
{?=call xxr_merge_quote_lines(2388,2518,56698,1752701,2)}
Took 9454 milliseconds for creating Line
Creating Line Id :2375
{?=call xxr_merge_quote_lines(2375,2518,56700,1752701,2)}
Took 9921 milliseconds for creating Line
Creating Line Id :2373
{?=call xxr_merge_quote_lines(2373,2518,56702,1752701,2)}
Process exited.
0
 
LVL 2

Author Comment

by:ThummalaRaghuveer
ID: 21827830
Initially it took less than a second then its taking around 9 seconds.... for each call
0
 
LVL 92

Expert Comment

by:objects
ID: 21827839
do u have auto commit enabled?

0
 
LVL 2

Author Comment

by:ThummalaRaghuveer
ID: 21827852
no I am commiting manually using quoteMergeAM.getDBTransaction().commit();
0
 
LVL 2

Author Comment

by:ThummalaRaghuveer
ID: 21827929
Is it that if I use CallableStatement, everytime I use it I get a lower performance than the previous call....

Does it happen normally or is it just happening here
0
 
LVL 92

Expert Comment

by:objects
ID: 21827968
I can't see from what you have posted why that would be happening sorry.

0
 
LVL 7

Expert Comment

by:humanonomics
ID: 21830285
Don't know what I am suggesting will make a significant difference, but why do you have quoteMergeAM.getDBTransaction().commit() at the end of all db transactions in couple of if conditions and then again at end outside of while loop, just have it once, outside the while loop.

2nd I don't see anywhere the command for releasing the connection. I presume that quoteMergeAM handles a connection pool, I feel there has to be an API that will release the connection back to the pool.
0
 
LVL 2

Author Comment

by:ThummalaRaghuveer
ID: 21834506
humanonomics, you are right, I was just testing it out and was just seeing if it makes a difference....

Also I get the connection from a pool so it is responsible for handling it...
0
 
LVL 2

Author Closing Comment

by:ThummalaRaghuveer
ID: 31469023
Got the solution finally....

All the calls that I am making insert rows into the DB.

Some post processing happens on each batch during every insert.

So as the number of rows inserted by the program increase time taken for this post processing is also increasing. Hence is the issue.

Fixed this by adding a logic to plsql function to do the post processing only at the end.

Thanks Objects for the discussion. It really helped me in confirming that there is everything is right from java app side.

I should have identified this while logging, but I was using an autonomous transaction for logging and somehow the time stamps are all same.....
0

Featured Post

Free Tool: Subnet Calculator

The subnet calculator helps you design networks by taking an IP address and network mask and returning information such as network, broadcast address, and host range.

One of a set of tools we're offering as a way of saying thank you for being a part of the community.

Question has a verified solution.

If you are experiencing a similar issue, please ask a related question

Suggested Solutions

Title # Comments Views Activity
map related example 6 55
servlet filter example 37 71
How  Can  I  resolve   this  Error "java.sql.SQLException: Invalid column index" 4 49
tomcat startup error 5 102
By the end of 1980s, object oriented programming using languages like C++, Simula69 and ObjectPascal gained momentum. It looked like programmers finally found the perfect language. C++ successfully combined the object oriented principles of Simula w…
Introduction Java can be integrated with native programs using an interface called JNI(Java Native Interface). Native programs are programs which can directly run on the processor. JNI is simply a naming and calling convention so that the JVM (Java…
Video by: Michael
Viewers learn about how to reduce the potential repetitiveness of coding in main by developing methods to perform specific tasks for their program. Additionally, objects are introduced for the purpose of learning how to call methods in Java. Define …
Viewers will learn about the regular for loop in Java and how to use it. Definition: Break the for loop down into 3 parts: Syntax when using for loops: Example using a for loop:

809 members asked questions and received personalized solutions in the past 7 days.

Join the community of 500,000 technology professionals and ask your questions.

Join & Ask a Question