Re: Java Stored Proc Slow....

From: Peter <pchristopher_at_munis.com>
Date: 4 Jan 2002 07:58:21 -0800
Message-ID: <a0c6518a.0201040758.24b2e8ce_at_posting.google.com>


Tom,

[Quoted] Sorry about the versions....forgive me, I'm new at Oracle, but should still know better...

In any case, I tried exactly what you said (acutally cut and paste the whole code session). It was almost exactly what my code was anyways. I still get 0.4+ seconds(which is signigicantly slower than .07 secs!!) times and higher, even after ignoring the first call for that session

Any tuning hints that I may be missing?

Below is the session where I tested your suggestion, including version numbers:

SQL*Plus: Release 8.1.7.0.0 - Production on Fri Jan 4 10:14:36 2002

(c) Copyright 2000 Oracle Corporation. All rights reserved.

Connected to:
Oracle8i Enterprise Edition Release 8.1.7.0.0 - Production With the Partitioning option
JServer Release 8.1.7.0.0 - Production

SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

SQL> set timing on;
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.90
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.90
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.91
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.40
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.50
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.40
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.40
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.50
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.51
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.60
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.50
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.50
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.50
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.50
SQL> exec rc('/usr/bin/echo hello world');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.50
SQL> Thomas Kyte <tkyte_at_us.oracle.com> wrote in message news:<a12t3e028vo_at_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
Received on Fri Jan 04 2002 - 16:58:21 CET

Original text of this message