Create a gist now

Instantly share code, notes, and snippets.

What would you like to do?
Benchmarking DBMS_OUTPUT.GET_LINE[S] from JDBC
import java.sql.Array;
import java.sql.CallableStatement;
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.Statement;
import java.sql.Types;
import java.util.Properties;
import java.util.stream.LongStream;
import java.util.stream.Stream;
public class Oracle {
static String lastMessage;
public static void main(String[] args) {
try {
Class.forName("oracle.jdbc.OracleDriver");
String url = "jdbc:oracle:thin:@192.168.99.100:1521:ORCLCDB";
String user = "TEST";
String password = "TEST";
Properties properties = new Properties();
properties.setProperty("user", user);
properties.setProperty("password", password);
int max = 50;
long[] getLines1 = new long[max];
long[] getLines10 = new long[max];
long[] getLines1000 = new long[max];
long[] getLineReusePS = new long[max];
long[] getLineCreatePS = new long[max];
try (Connection c = DriverManager.getConnection(url, properties);
Statement s = c.createStatement()) {
for (int warmup = 0; warmup < 2; warmup++) {
for (int i = 0; i < max; i++) {
s.executeUpdate("begin dbms_output.enable(); end;");
String sql = "begin for i in 1 .. 100 loop dbms_output.put_line('Message ' || i); end loop; end;";
long t1 = System.nanoTime();
logGetLines(c, 100, 1, () -> s.executeUpdate(sql));
long t2 = System.nanoTime();
logGetLines(c, 100, 10, () -> s.executeUpdate(sql));
long t3 = System.nanoTime();
logGetLines(c, 100, 1000, () -> s.executeUpdate(sql));
long t4 = System.nanoTime();
logGetLineReusePS(c, 100, () -> s.executeUpdate(sql));
long t5 = System.nanoTime();
logGetLineCreatePS(c, 100, () -> s.executeUpdate(sql));
long t6 = System.nanoTime();
s.executeUpdate("begin dbms_output.disable(); end;");
if (warmup > 0) {
getLines1[i] = t2 - t1;
getLines10[i] = t3 - t2;
getLines1000[i] = t4 - t3;
getLineReusePS[i] = t5 - t4;
getLineCreatePS[i] = t6 - t5;
}
}
}
}
// LongSummaryStatistics{count=50, sum=67475229, min=1040214, average=1349504.580000, max=2499841}
// LongSummaryStatistics{count=50, sum=73946058, min=1162667, average=1478921.160000, max=2532694}
// LongSummaryStatistics{count=50, sum=74989687, min=1195948, average=1499793.740000, max=2517335}
// LongSummaryStatistics{count=50, sum=1491740368, min=27195319, average=29834807.360000, max=41893138}
// LongSummaryStatistics{count=50, sum=2060018373, min=35052388, average=41200367.460000, max=73077792}
System.out.println(LongStream.of(getLines1).summaryStatistics());
System.out.println(LongStream.of(getLines10).summaryStatistics());
System.out.println(LongStream.of(getLines1000).summaryStatistics());
System.out.println(LongStream.of(getLineReusePS).summaryStatistics());
System.out.println(LongStream.of(getLineCreatePS).summaryStatistics());
} catch (Exception e) {
e.printStackTrace();
}
}
interface WhyUNoCheckedExceptionRunnable {
void run() throws Exception;
}
static void logGetLines(Connection connection, int size, int fetchSize, WhyUNoCheckedExceptionRunnable runnable) throws Exception {
try (Statement s = connection.createStatement()) {
runnable.run();
try (CallableStatement call = connection.prepareCall(
"declare "
+ " num integer := ?;"
+ "begin "
+ " dbms_output.get_lines(?, num);"
+ "end;"
)) {
call.setFetchSize(fetchSize);
call.setInt(1, size);
call.registerOutParameter(2, Types.ARRAY, "DBMSOUTPUT_LINESARRAY");
call.execute();
Array array = null;
try {
array = call.getArray(2);
Stream.of((Object[]) array.getArray())
.forEach(m -> { lastMessage = (String) m; });
}
finally {
if (array != null)
array.free();
}
}
}
}
static void logGetLineReusePS(Connection connection, int size, WhyUNoCheckedExceptionRunnable runnable) throws Exception {
try (Statement s = connection.createStatement()) {
runnable.run();
try (CallableStatement call = connection.prepareCall(
"begin "
+ " dbms_output.get_line(?, ?);"
+ "end;"
)) {
call.registerOutParameter(1, Types.VARCHAR);
call.registerOutParameter(2, Types.INTEGER);
for (int i = 0; i < size; i++) {
call.execute();
lastMessage = call.getString(1);
}
}
}
}
static void logGetLineCreatePS(Connection connection, int size, WhyUNoCheckedExceptionRunnable runnable) throws Exception {
try (Statement s = connection.createStatement()) {
runnable.run();
for (int i = 0; i < size; i++) {
try (CallableStatement call = connection.prepareCall(
"begin "
+ " dbms_output.get_line(?, ?);"
+ "end;"
)) {
call.registerOutParameter(1, Types.VARCHAR);
call.registerOutParameter(2, Types.INTEGER);
call.execute();
lastMessage = call.getString(1);
}
}
}
}
}
@vlsi

This comment has been minimized.

Show comment Hide comment
@vlsi

vlsi Dec 18, 2017

@lukaseder, why do you call prepareCall in a loop inside logGetLine? Why don't you just prepare the call once and execute in a loop?

vlsi commented Dec 18, 2017

@lukaseder, why do you call prepareCall in a loop inside logGetLine? Why don't you just prepare the call once and execute in a loop?

@lukaseder

This comment has been minimized.

Show comment Hide comment
@lukaseder

lukaseder Mar 7, 2018

@vlsi: Sorry, didn't get the notification. Good point, worth exploring. The main reason is because this is what's being done by most clients. I'll re-run the example with your suggestion

Owner

lukaseder commented Mar 7, 2018

@vlsi: Sorry, didn't get the notification. Good point, worth exploring. The main reason is because this is what's being done by most clients. I'll re-run the example with your suggestion

@lukaseder

This comment has been minimized.

Show comment Hide comment
@lukaseder

lukaseder Mar 7, 2018

@vlsi: OK, updated the code and ran the benchmark again. Indeed, there's another significant drawback when re-creating the CallableStatement for every call, but not significant enough:

LongSummaryStatistics{count=50, sum=  74989687, min= 1195948, average= 1499793.740000, max= 2517335}
LongSummaryStatistics{count=50, sum=1491740368, min=27195319, average=29834807.360000, max=41893138}
LongSummaryStatistics{count=50, sum=2060018373, min=35052388, average=41200367.460000, max=73077792}
  1. Moves the loop to PL/SQL
  2. Creates a single statement and loops the executions in the client
  3. Creates a statement per execution
Owner

lukaseder commented Mar 7, 2018

@vlsi: OK, updated the code and ran the benchmark again. Indeed, there's another significant drawback when re-creating the CallableStatement for every call, but not significant enough:

LongSummaryStatistics{count=50, sum=  74989687, min= 1195948, average= 1499793.740000, max= 2517335}
LongSummaryStatistics{count=50, sum=1491740368, min=27195319, average=29834807.360000, max=41893138}
LongSummaryStatistics{count=50, sum=2060018373, min=35052388, average=41200367.460000, max=73077792}
  1. Moves the loop to PL/SQL
  2. Creates a single statement and loops the executions in the client
  3. Creates a statement per execution
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment