Note: Tested in Oracle 19.24 with single user session.
1. Test Run
We run 5 different Scenarios (see Blog appended Test Code), each for 100 seconds.
set serveroutput on size 50000
-- Enable java println output on Sqlplus Window
exec dbms_java.set_output(50000);
exec TestOraJvmRun2_call(plsqlSleepSeconds=> 100);
exec TestOraJvmRun2_call(plsqlRunSeconds=> 100);
exec TestOraJvmRun2_call(javaPlsqlMixRunSeconds=> 100);
exec TestOraJvmRun2_call(javaSleepSeconds=> 100);
exec TestOraJvmRun2_call(javaRunSeconds=> 100);
2. Test Output
2.1 plsqlSleepSeconds
SQL > exec TestOraJvmRun2_call(plsqlSleepSeconds=> 100);
***** TestOraJvmRun2: plsqlSleepSeconds = 100, plsqlRunSeconds = 0, javaPlsqlMixRunSeconds = 0, javaSleepSeconds = 0, javaRunSeconds = 0
====== 1 Start plsqlSleepSeconds ========= at 16:09:06.699
====== 1 End plsqlSleepSeconds ========= at 16:10:47.252
====== 2 Start plsqlRunSeconds ========= at 16:10:47.252
====== 2 End plsqlRunSeconds ========= at 16:10:47.253
====== 3 Start javaPlsqlMixRunSeconds ========= at 16:10:47.253
====== 3 End javaPlsqlMixRunSeconds ========= at 16:10:47.253
====== 4 Start javaSleepSeconds ========= at 16:10:47.255
====== 4 End javaSleepSeconds ========= at 16:10:47.255
====== 5 Start javaRunSeconds ========= at 16:10:47.255
====== 5 End javaRunSeconds ========= at 16:10:47.255
============================================================
SESS_TIME_MODEL-stat_name (Sid=374, Run=1) val
------------------------------------------------------------
DB time 1.04
sql execute elapsed time 1.03
============================================================
SYS_TIME_MODEL-stat_name val
------------------------------------------------------------
background elapsed time 3.00
background cpu time 2.12
DB time 1.04
sql execute elapsed time 1.04
Elapsed: 00:01:41.23
2.2 plsqlRunSeconds
SQl > exec TestOraJvmRun2_call(plsqlRunSeconds=> 100);
***** TestOraJvmRun2: plsqlSleepSeconds = 0, plsqlRunSeconds = 100, javaPlsqlMixRunSeconds = 0, javaSleepSeconds = 0, javaRunSeconds = 0
====== 1 Start plsqlSleepSeconds ========= at 16:10:47.457
====== 1 End plsqlSleepSeconds ========= at 16:10:47.458
====== 2 Start plsqlRunSeconds ========= at 16:10:47.458
====== 2 End plsqlRunSeconds ========= at 16:12:27.515
====== 3 Start javaPlsqlMixRunSeconds ========= at 16:12:27.516
====== 3 End javaPlsqlMixRunSeconds ========= at 16:12:27.516
====== 4 Start javaSleepSeconds ========= at 16:12:27.516
====== 4 End javaSleepSeconds ========= at 16:12:27.516
====== 5 Start javaRunSeconds ========= at 16:12:27.516
====== 5 End javaRunSeconds ========= at 16:12:27.516
============================================================
SESS_TIME_MODEL-stat_name (Sid=374, Run=2) val
------------------------------------------------------------
DB time 99.81
sql execute elapsed time 99.81
DB CPU 99.38
PL/SQL execution elapsed time 54.10
============================================================
SYS_TIME_MODEL-stat_name val
------------------------------------------------------------
DB time 99.81
sql execute elapsed time 99.81
DB CPU 99.38
PL/SQL execution elapsed time 54.10
background elapsed time 50.32
background cpu time 18.25
Elapsed: 00:01:40.11
2.3 javaPlsqlMixRunSecond
SQL > exec TestOraJvmRun2_call(javaPlsqlMixRunSeconds=> 100);
***** TestOraJvmRun2: plsqlSleepSeconds = 0, plsqlRunSeconds = 0, javaPlsqlMixRunSeconds = 100, javaSleepSeconds = 0, javaRunSeconds = 0
====== 1 Start plsqlSleepSeconds ========= at 16:12:27.578
====== 1 End plsqlSleepSeconds ========= at 16:12:27.579
====== 2 Start plsqlRunSeconds ========= at 16:12:27.579
====== 2 End plsqlRunSeconds ========= at 16:12:27.579
====== 3 Start javaPlsqlMixRunSeconds ========= at 16:12:27.579
====== 3 End javaPlsqlMixRunSeconds ========= at 16:14:07.698
====== 4 Start javaSleepSeconds ========= at 16:14:07.698
====== 4 End javaSleepSeconds ========= at 16:14:07.698
====== 5 Start javaRunSeconds ========= at 16:14:07.698
====== 5 End javaRunSeconds ========= at 16:14:07.698
============================================================
SESS_TIME_MODEL-stat_name (Sid=374, Run=3) val
------------------------------------------------------------
DB time 99.75
sql execute elapsed time 99.75
Java execution elapsed time 52.99
DB CPU 51.92
PL/SQL execution elapsed time 19.07
============================================================
SYS_TIME_MODEL-stat_name val
------------------------------------------------------------
DB time 99.74
sql execute elapsed time 99.74
background elapsed time 68.16
Java execution elapsed time 52.99
DB CPU 51.91
PL/SQL execution elapsed time 19.07
background cpu time 16.64
Elapsed: 00:01:40.17
2.4 javaSleepSeconds
SQL > exec TestOraJvmRun2_call(javaSleepSeconds=> 100);
***** TestOraJvmRun2: plsqlSleepSeconds = 0, plsqlRunSeconds = 0, javaPlsqlMixRunSeconds = 0, javaSleepSeconds = 100, javaRunSeconds = 0
====== 1 Start plsqlSleepSeconds ========= at 16:14:07.757
====== 1 End plsqlSleepSeconds ========= at 16:14:07.758
====== 2 Start plsqlRunSeconds ========= at 16:14:07.758
====== 2 End plsqlRunSeconds ========= at 16:14:07.758
====== 3 Start javaPlsqlMixRunSeconds ========= at 16:14:07.758
====== 3 End javaPlsqlMixRunSeconds ========= at 16:14:07.758
====== 4 Start javaSleepSeconds ========= at 16:14:07.758
====== 4 End javaSleepSeconds ========= at 16:15:47.759
====== 5 Start javaRunSeconds ========= at 16:15:47.759
====== 5 End javaRunSeconds ========= at 16:15:47.759
============================================================
SESS_TIME_MODEL-stat_name (Sid=374, Run=4) val
------------------------------------------------------------
sql execute elapsed time 100.01
DB time 100.00
Java execution elapsed time 100.00
============================================================
SYS_TIME_MODEL-stat_name val
------------------------------------------------------------
DB time 100.01
sql execute elapsed time 100.01
Java execution elapsed time 100.00
background elapsed time 1.80
background cpu time 1.71
Elapsed: 00:01:40.05
2.5 javaRunSeconds
SQL > exec TestOraJvmRun2_call(javaRunSeconds=> 100);
***** TestOraJvmRun2: plsqlSleepSeconds = 0, plsqlRunSeconds = 0, javaPlsqlMixRunSeconds = 0, javaSleepSeconds = 0, javaRunSeconds = 100
====== 1 Start plsqlSleepSeconds ========= at 16:15:47.819
====== 1 End plsqlSleepSeconds ========= at 16:15:47.820
====== 2 Start plsqlRunSeconds ========= at 16:15:47.820
====== 2 End plsqlRunSeconds ========= at 16:15:47.820
====== 3 Start javaPlsqlMixRunSeconds ========= at 16:15:47.820
====== 3 End javaPlsqlMixRunSeconds ========= at 16:15:47.820
====== 4 Start javaSleepSeconds ========= at 16:15:47.820
====== 4 End javaSleepSeconds ========= at 16:15:47.820
====== 5 Start javaRunSeconds ========= at 16:15:47.820
====== 5 End javaRunSeconds ========= at 16:17:27.820
============================================================
SESS_TIME_MODEL-stat_name (Sid=374, Run=5) val
------------------------------------------------------------
DB time 100.01
Java execution elapsed time 100.01
sql execute elapsed time 100.01
DB CPU 99.56
============================================================
SYS_TIME_MODEL-stat_name val
------------------------------------------------------------
sql execute elapsed time 100.01
DB time 100.00
Java execution elapsed time 100.00
DB CPU 99.56
background elapsed time 3.74
background cpu time 2.17
Elapsed: 00:01:40.05
3. Test Code
3.1 Plsql Code
create table test_tab_1 as select 1 k, 1234 val from dual;
create or replace procedure plsql_run(p_run number := 1e3) as
l_x number;
begin
for f in 1..p_run loop
update test_tab_1 set val = mod (l_x, p_run/10);
commit;
end loop;
for f in 1..p_run*100 loop
l_x := mod (l_x, p_run) + sqrt (f);
end loop;
end;
/
-- exec plsql_run(1e3);
create or replace procedure plsql_run_seconds(p_run_sec number := 30) as
l_x number;
l_start_time number := dbms_utility.get_time;
begin
--dbms_session.sleep(p_sleep_sec);
while ((dbms_utility.get_time - l_start_time)/100 < p_run_sec) loop
plsql_run(1e3);
end loop;
end;
/
-- exec plsql_run_seconds(3);
3.2 Java Stored Procedure
create or replace and compile java source named "TestOraJvmRun2" as
import java.io.*;
import java.sql.*;
import java.text.SimpleDateFormat;
import oracle.jdbc.OracleDriver;
public class TestOraJvmRun2
{
public static String proc(String testName, int plsqlSleepSeconds, int plsqlRunSeconds, int javaPlsqlMixRunSeconds, int javaSleepSeconds, int javaRunSeconds) throws SQLException
{
String exceptMessage = "No Exception";
String test_title = ("\n***** "+ testName +
": plsqlSleepSeconds = " + plsqlSleepSeconds +
", plsqlRunSeconds = " + plsqlRunSeconds +
", javaPlsqlMixRunSeconds = " + javaPlsqlMixRunSeconds +
", javaSleepSeconds = " + javaSleepSeconds +
", javaRunSeconds = " + javaRunSeconds);
System.out.println(test_title);
try {
Connection connection = new OracleDriver().defaultConnection();
CallableStatement cstmt;
System.out.println("\n====== 1 Start plsqlSleepSeconds ========= at " + java.time.LocalDateTime.now());
cstmt = connection.prepareCall("begin dbms_session.sleep(?); end;");
cstmt.setInt(1, plsqlSleepSeconds);
cstmt.execute();
cstmt.close();
System.out.println("====== 1 End plsqlSleepSeconds ========= at " + java.time.LocalDateTime.now());
System.out.println("\n====== 2 Start plsqlRunSeconds ========= at " + java.time.LocalDateTime.now());
cstmt = connection.prepareCall("begin plsql_run_seconds(?); end;");
cstmt.setInt(1, plsqlRunSeconds);
cstmt.execute();
cstmt.close();
System.out.println("====== 2 End plsqlRunSeconds ========= at " + java.time.LocalDateTime.now());
System.out.println("\n====== 3 Start javaPlsqlMixRunSeconds ========= at " + java.time.LocalDateTime.now());
long sleepOneSecond = 1000*1000000L; // convert 1 second to nanoseconds
long startTime;
for (int i = 0; i < javaPlsqlMixRunSeconds; i++) { // java loop calling plsql
startTime = System.nanoTime();
while ((System.nanoTime() - startTime) < sleepOneSecond)
{try {
cstmt = connection.prepareCall("begin plsql_run(1e1); end;");
Thread.sleep(1);
cstmt.execute();
cstmt.close();
} catch (Exception e) {
exceptMessage = e.toString();
//System.out.println(e);
}
}
}
System.out.println("====== 3 End javaPlsqlMixRunSeconds ========= at " + java.time.LocalDateTime.now());
System.out.println("\n====== 4 Start javaSleepSeconds ========= at " + java.time.LocalDateTime.now());
{try {
Thread.sleep(javaSleepSeconds*1000);
} catch (Exception e) {
exceptMessage = e.toString();
//System.out.println(e);
}
}
System.out.println("====== 4 End javaSleepSeconds ========= at " + java.time.LocalDateTime.now());
System.out.println("\n====== 5 Start javaRunSeconds ========= at " + java.time.LocalDateTime.now());
for (int i = 0; i < javaRunSeconds; i++) {
startTime = System.nanoTime();
while ((System.nanoTime() - startTime) < sleepOneSecond)
{}
}
System.out.println("====== 5 End javaRunSeconds ========= at " + java.time.LocalDateTime.now());
} catch (Exception e) {
e.printStackTrace();
}
return test_title;
}
}
/
create or replace function TestOraJvmRun2_proc(testName varchar2, plsqlSleepSeconds number, plsqlRunSeconds number,
javaPlsqlMixRunSeconds number, javaSleepSeconds number, javaRunSeconds number)
return varchar2 as language java
name 'TestOraJvmRun2.proc(java.lang.String, int, int, int, int, int) return String';
/
3.3 Plsql Test Call
drop table test_run_tm_stat;
create table test_run_tm_stat as select 0 run, 0 seq, sysdate datetime, sid, stat_name, round(value/1e6, 2) val from V$SESS_TIME_MODEL where 1=2;
select * from test_run_tm_stat;
drop sequence TestOraJvmRun_seq;
create sequence TestOraJvmRun_seq;
create or replace procedure TestOraJvmRun2_call (testName VARCHAR2 :='TestOraJvmRun2', plsqlSleepSeconds number :=0, plsqlRunSeconds number :=0,
javaPlsqlMixRunSeconds number :=0, javaSleepSeconds number :=0, javaRunSeconds number :=0) as
l_run number := TestOraJvmRun_seq.nextval;
l_sid number := sys_context('userenv','sid');
l_wid number := 60;
l_ret VARCHAR2(200);
begin
insert into test_run_tm_stat
select l_run, 1, sysdate, sid, stat_name, round(value/1e6, 2) from V$SESS_TIME_MODEL where sid = l_sid order by value desc;
insert into test_run_tm_stat
select l_run, 1, sysdate, -1, stat_name, round(value/1e6, 2) from V$SYS_TIME_MODEL; -- sid = -1 for V$SYS_TIME_MODEL
l_ret := TestOraJvmRun2_proc(testName, plsqlSleepSeconds, plsqlRunSeconds, javaPlsqlMixRunSeconds, javaSleepSeconds, javaRunSeconds); -- sleep or run x seconds
--dbms_output.put_line(l_ret);
commit;
insert into test_run_tm_stat
select l_run, 2, sysdate, sid, stat_name, round(value/1e6, 2) from V$SESS_TIME_MODEL where sid = l_sid order by value desc;
insert into test_run_tm_stat
select l_run, 2, sysdate, -1, stat_name, round(value/1e6, 2) from V$SYS_TIME_MODEL; -- sid = -1 for V$SYS_TIME_MODEL
commit;
dbms_output.put_line(chr(10)||rpad('=', l_wid, '='));
dbms_output.put_line(rpad('SESS_TIME_MODEL-stat_name (Sid='||l_sid||', Run='||l_run||')', l_wid-10, ' ')||lpad('val', 10, ' '));
dbms_output.put_line(rpad('-', l_wid, '-'));
for c in
(select * from
(select run, seq, sid, stat_name, val-lag(val, 1) over(partition by stat_name order by run, seq) delta from test_run_tm_stat where run = l_run and sid > 0)
where delta >= 1 and seq=2 order by delta desc, stat_name)
loop
dbms_output.put_line(rpad(c.stat_name, l_wid-10, ' ')||lpad(to_char(c.delta, '999.99'), 10, ' '));
end loop;
dbms_output.put_line(chr(10)||rpad('=', l_wid, '='));
dbms_output.put_line(rpad('SYS_TIME_MODEL-stat_name', l_wid-10, ' ')||lpad('val', 10, ' '));
dbms_output.put_line(rpad('-', l_wid, '-'));
for c in
(select * from
(select run, seq, sid, stat_name, val-lag(val, 1) over(partition by stat_name order by run, seq) delta from test_run_tm_stat where run = l_run and sid = -1)
where delta >= 1 and seq=2 order by delta desc, stat_name)
loop
dbms_output.put_line(rpad(c.stat_name, l_wid-10, ' ')||lpad(to_char(c.delta, '999.99'), 10, ' '));
end loop;
end;
/
