Re: Java Stored Proc Slow....

From: Thomas Kyte <tkyte_at_us.oracle.com>
Date: 3 Jan 2002 16:30:38 -0800
Message-ID: <a12t3e028vo@drn.newsguy.com>

In article <a0c6518a.0201031230.654fb055_at_posting.google.com>, pchristopher_at_munis.com says...
>
>My situation is pretty straightforward. I need a stored procedure to
>call a UNIX command (actually, an Infomix program, but that's besides
>the point).
>
>What I am doing is using Java Stored Procedures to call a small piece
>of Java that I loaded into an Oracle 8i database. The java simply
>invokes the Java Runtime.exec() to shell the command out the the OS. I
>chose this because the DBMS_Pipes is not practical to deploy to our
>customer base.
>
>The JSP method seems very straightforward, but it is running VERY
>slow. Here are some example times:
>
>ODBC --> JSP --> JAVA (just return back, no runtime call) = .67 secs
>ODBC --> JSP --> JAVA --> UNIX (no code executed, just return back) =
>1.15 secs
>(NOTE: calling the JSP from SQL*Plus is insignificantly faster, so
>ODBC is not my issue!)
>
>Seems way to long considering the Java is just passing along a system
>call and the Unix command run was an empty shell script. In fact, the
>UNIX program that I intend to run does a whole lot of work, SQL
>inserts/updates/deletes and that whole process only takes 0.8 secs. So
>the JSP call more than doubles the execution time. That is
>unacceptable to me.
>
>Any suggestions on where the bottleneck may be??

Sigh, not a version in sight!

Ok, here is test running on a smallish, overloaded sparc box. I used 817, I get very different results, about 0.11, 0.07 and 0.07 seconds for three calls in a row in a fresh session.

SQL*Plus: Release 8.1.7.0.0 - Production on Thu Jan 3 19:23:23 2002 (c) Copyright 2000 Oracle Corporation. All rights reserved. Connected to:
Oracle8i Enterprise Edition Release 8.1.7.2.0 - Production With the Partitioning option
JServer Release 8.1.7.2.0 - Production

ops$tkyte_at_ORA817DEV.US.ORACLE.COM> set echo on
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> @test
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> begin
  2      dbms_java.grant_permission
  3      (user,
  4       'java.io.FilePermission',
  5       '/usr/bin/echo',
  6       'execute');
  7  
  8      dbms_java.grant_permission
  9      (user,
 10       'java.lang.RuntimePermission',
 11       '*',
 12       'writeFileDescriptor' );

 13 end;
 14 /

PL/SQL procedure successfully completed.

ops$tkyte_at_ORA817DEV.US.ORACLE.COM>
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> create or replace and compile   2 java source named "Util"
  3 as
  4 import java.io.*;
  5 import java.lang.*;
  6
  7 public class Util extends Object
  8 {
  9
 10 public static int RunThis(String[] args)  11 {
 12 Runtime rt = Runtime.getRuntime();  13 int rc = -1;
 14
 15 try
 16 {
 17 Process p = rt.exec(args[0]);
 18

 19       int bufSize = 4096;
 20       BufferedInputStream bis =
 21        new BufferedInputStream(p.getInputStream(), bufSize);
 22       int len;
 23       byte buffer[] = new byte[bufSize];
 24  
 25       // Echo back what the program spit out
 26       while ((len = bis.read(buffer, 0, bufSize)) != -1)
 27          System.out.write(buffer, 0, len);
 28  
 29       rc = p.waitFor();

 30 }
 31 catch (Exception e)
 32 {

 33       e.printStackTrace();
 34       rc = -1;

 35 }
 36 finally
 37 {
 38 return rc;
 39 }
 40 }
 41 }
 42 /

Java created.

ops$tkyte_at_ORA817DEV.US.ORACLE.COM>
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> create or replace   2 function RUN_CMD( p_cmd in varchar2) return number   3 as
  4 language java
  5 name 'Util.RunThis(java.lang.String[]) return integer';   6 /

Function created.

ops$tkyte_at_ORA817DEV.US.ORACLE.COM>
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> create or replace procedure RC(p_cmd in varchar2)
  2 as
  3 x number;
  4 begin
  5 x := run_cmd(p_cmd);
  6 end;
  7 /

Procedure created.

ops$tkyte_at_ORA817DEV.US.ORACLE.COM> 
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> set serveroutput on size 1000000
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> exec dbms_java.set_output(1000000)

PL/SQL procedure successfully completed.

ops$tkyte_at_ORA817DEV.US.ORACLE.COM> set timing on ops$tkyte_at_ORA817DEV.US.ORACLE.COM> exec rc('/usr/bin/echo hello world'); hello world

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.11
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> exec rc('/usr/bin/echo hello world'); hello world

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.07
ops$tkyte_at_ORA817DEV.US.ORACLE.COM> exec rc('/usr/bin/echo hello world'); hello world

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.07

Now, in the very first release of 8i, 815, I get timings of:

PL/SQL procedure successfully completed. Elapsed: 00:00:01.03
hello world

PL/SQL procedure successfully completed. Elapsed: 00:00:00.07
hello world

PL/SQL procedure successfully completed. Elapsed: 00:00:00.07

--
Thomas Kyte (tkyte@us.oracle.com)             http://asktom.oracle.com/ 
Expert one on one Oracle, programming techniques and solutions for Oracle.
http://www.amazon.com/exec/obidos/ASIN/1861004826/  
Opinions are mine and do not necessarily reflect those of Oracle Corp 

Received on Thu Jan 03 2002 - 18:30:38 CST