Skip to content

Instantly share code, notes, and snippets.

@lukaseder

lukaseder/JDBCSpeedTest.java

Created February 18, 2021 08:44
Show Gist options
  • Save lukaseder/6e8f86b5cf91fcbdf561419e1af748ad to your computer and use it in GitHub Desktop.
Save lukaseder/6e8f86b5cf91fcbdf561419e1af748ad to your computer and use it in GitHub Desktop.
Download ZIP
Raw
JDBCSpeedTest.java
package org.jooq.testscripts;
import java.sql.Connection;
import java.sql.PreparedStatement;
import java.sql.Statement;
import org.jooq.SQLDialect;
import org.jooq.test.setup.DatabaseSetup;
import org.jooq.test.setup.DatabaseSetup.Config;
import org.jooq.tools.StopWatch;
public class JDBCSpeedTest {
public static void main(String[] args) throws Exception {
SQLDialect dialect = SQLDialect.BIGQUERY;
DatabaseSetup dbSetup = new DatabaseSetup(new Config(dialect, "", false));
try (Connection c = dbSetup.getConnection()) {
StopWatch watch;
watch = new StopWatch();
int repetitions = 30;
for (int i = 0; i < repetitions; i++) {
try (PreparedStatement s = c.prepareStatement("insert into t (i) values (?)")) {
s.setInt(1, i);
s.executeUpdate();
}
progress(watch, i);
}
watch.splitInfo("Finished prepared statements");
watch = new StopWatch();
try (PreparedStatement s = c.prepareStatement("insert into t (i) values (?)")) {
for (int i = 0; i < repetitions; i++) {
s.setInt(1, i);
s.executeUpdate();
progress(watch, i);
}
}
watch.splitInfo("Finished prepared statements keeping them open");
watch = new StopWatch();
try (PreparedStatement s = c.prepareStatement("insert into t (i) values (?)")) {
for (int i = 0; i < repetitions; i++) {
s.setInt(1, i);
s.addBatch();
progress(watch, i);
}
s.executeBatch();
}
watch.splitInfo("Finished prepared statement batch");
watch = new StopWatch();
try (Statement s = c.createStatement()) {
for (int i = 0; i < repetitions; i++) {
s.executeUpdate("insert into t (i) values (" + i + ")");
progress(watch, i);
}
}
watch.splitInfo("Finished static statements");
watch = new StopWatch();
try (Statement s = c.createStatement()) {
for (int i = 0; i < repetitions; i++) {
s.addBatch("insert into t (i) values (" + i + ")");
progress(watch, i);
}
s.executeBatch();
}
watch.splitInfo("Finished static statement batch");
}
}
private static void progress(StopWatch watch, int i) {
if (i % 5 == 0)
watch.splitInfo("Insertions: " + i);
}
}
/*
09:33:18,214 INFO [org.jooq.tools.StopWatch ] - Insertions: 0 : Total: 1.206s
09:33:40,595 INFO [org.jooq.tools.StopWatch ] - Insertions: 5 : Total: 23.586s, +22.38s
09:34:09,560 INFO [org.jooq.tools.StopWatch ] - Insertions: 10 : Total: 52.552s, +28.965s
09:34:49,082 INFO [org.jooq.tools.StopWatch ] - Insertions: 15 : Total: 01:32, +39.521s
09:35:23,959 INFO [org.jooq.tools.StopWatch ] - Insertions: 20 : Total: 02:06, +34.877s
09:35:30,419 INFO [org.jooq.tools.StopWatch ] - Insertions: 25 : Total: 02:13, +6.46s
09:35:57,834 INFO [org.jooq.tools.StopWatch ] - Finished prepared statements: Total: 02:40, +27.415s
09:35:58,984 INFO [org.jooq.tools.StopWatch ] - Insertions: 0 : Total: 1.149s
09:36:38,774 INFO [org.jooq.tools.StopWatch ] - Insertions: 5 : Total: 40.939s, +39.789s
09:36:43,959 INFO [org.jooq.tools.StopWatch ] - Insertions: 10 : Total: 46.123s, +5.184s
09:37:18,241 INFO [org.jooq.tools.StopWatch ] - Insertions: 15 : Total: 01:20, +34.282s
09:37:23,789 INFO [org.jooq.tools.StopWatch ] - Insertions: 20 : Total: 01:25, +5.548s
09:37:49,033 INFO [org.jooq.tools.StopWatch ] - Insertions: 25 : Total: 01:51, +25.244s
09:37:53,471 INFO [org.jooq.tools.StopWatch ] - Finished prepared statements keeping them open: Total: 01:55, +4.438s
09:37:53,633 INFO [org.jooq.tools.StopWatch ] - Insertions: 0 : Total: 161.281ms
09:37:53,633 INFO [org.jooq.tools.StopWatch ] - Insertions: 5 : Total: 161.41ms, +0.129ms
09:37:53,634 INFO [org.jooq.tools.StopWatch ] - Insertions: 10 : Total: 161.476ms, +0.065ms
09:37:53,634 INFO [org.jooq.tools.StopWatch ] - Insertions: 15 : Total: 161.547ms, +0.07ms
09:37:53,634 INFO [org.jooq.tools.StopWatch ] - Insertions: 20 : Total: 161.675ms, +0.128ms
09:37:53,634 INFO [org.jooq.tools.StopWatch ] - Insertions: 25 : Total: 161.748ms, +0.073ms
09:40:20,556 INFO [org.jooq.tools.StopWatch ] - Finished prepared statement batch: Total: 02:27, +02:26
09:40:21,518 INFO [org.jooq.tools.StopWatch ] - Insertions: 0 : Total: 962.172ms
09:40:28,501 INFO [org.jooq.tools.StopWatch ] - Insertions: 5 : Total: 7.944s, +6.982s
09:40:34,824 INFO [org.jooq.tools.StopWatch ] - Insertions: 10 : Total: 14.267s, +6.323s
09:40:41,208 INFO [org.jooq.tools.StopWatch ] - Insertions: 15 : Total: 20.652s, +6.384s
09:40:46,789 INFO [org.jooq.tools.StopWatch ] - Insertions: 20 : Total: 26.233s, +5.581s
09:40:52,153 INFO [org.jooq.tools.StopWatch ] - Insertions: 25 : Total: 31.596s, +5.363s
09:40:56,200 INFO [org.jooq.tools.StopWatch ] - Finished static statements: Total: 35.644s, +4.047s
09:40:56,200 INFO [org.jooq.tools.StopWatch ] - Insertions: 0 : Total: 0.061ms
09:40:56,200 INFO [org.jooq.tools.StopWatch ] - Insertions: 5 : Total: 0.142ms, +0.081ms
09:40:56,200 INFO [org.jooq.tools.StopWatch ] - Insertions: 10 : Total: 0.189ms, +0.046ms
09:40:56,200 INFO [org.jooq.tools.StopWatch ] - Insertions: 15 : Total: 0.239ms, +0.049ms
09:40:56,200 INFO [org.jooq.tools.StopWatch ] - Insertions: 20 : Total: 0.283ms, +0.044ms
09:40:56,200 INFO [org.jooq.tools.StopWatch ] - Insertions: 25 : Total: 0.331ms, +0.047ms
09:43:13,014 INFO [org.jooq.tools.StopWatch ] - Finished static statement batch: Total: 02:16, +02:16
*/
@lukaseder
Copy link
Author

A second run of the "benchmark" yielded different results:

09:52:30,052  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 1.231s
09:52:36,363  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 7.541s, +6.31s
09:53:03,623  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 34.801s, +27.259s
09:53:09,514  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 40.692s, +5.891s
09:53:50,482  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 01:21, +40.967s
09:54:21,879  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 01:53, +31.396s
09:54:54,985  INFO [org.jooq.tools.StopWatch                          ] - Finished prepared statements: Total: 02:26, +33.105s
09:54:56,108  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 1.123s
09:55:23,840  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 28.855s, +27.732s
09:55:28,926  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 33.942s, +5.086s
09:55:55,427  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 01:00, +26.5s
09:56:01,065  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 01:06, +5.637s
09:56:31,498  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 01:36, +30.433s
09:57:07,468  INFO [org.jooq.tools.StopWatch                          ] - Finished prepared statements keeping them open: Total: 02:12, +35.969s
09:57:07,639  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 171.179ms
09:57:07,639  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 171.344ms, +0.164ms
09:57:07,639  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 171.425ms, +0.081ms
09:57:07,640  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 171.495ms, +0.069ms
09:57:07,640  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 171.585ms, +0.09ms
09:57:07,640  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 171.656ms, +0.07ms
09:58:59,002  INFO [org.jooq.tools.StopWatch                          ] - Finished prepared statement batch: Total: 01:51, +01:51
09:59:00,054  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 1.05s
09:59:05,386  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 6.382s, +5.332s
09:59:10,679  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 11.677s, +5.294s
09:59:36,662  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 37.659s, +25.982s
09:59:42,925  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 43.923s, +6.263s
10:00:14,207  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 01:15, +31.281s
10:00:19,285  INFO [org.jooq.tools.StopWatch                          ] - Finished static statements: Total: 01:20, +5.078s
10:00:19,285  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 0.07ms
10:00:19,285  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 0.232ms, +0.162ms
10:00:19,285  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 0.375ms, +0.143ms
10:00:19,286  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 0.493ms, +0.117ms
10:00:19,286  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 0.577ms, +0.083ms
10:00:19,286  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 0.639ms, +0.061ms
10:01:20,468  INFO [org.jooq.tools.StopWatch                          ] - Finished static statement batch: Total: 01:01, +01:01

Static statements still seem consistently faster than prepared statements. Batching doens't seem to have a significant effect.

@lukaseder
Copy link
Author

A third run:

10:05:21,490  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 1.213s
10:05:27,259  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 6.982s, +5.769s
10:05:53,140  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 32.863s, +25.88s
10:05:58,909  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 38.632s, +5.768s
10:06:39,672  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 01:19, +40.763s
10:06:46,008  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 01:25, +6.336s
10:06:50,967  INFO [org.jooq.tools.StopWatch                          ] - Finished prepared statements: Total: 01:30, +4.958s
10:06:52,158  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 1.191s
10:07:33,998  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 43.031s, +41.839s
10:07:39,284  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 48.316s, +5.285s
10:07:44,620  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 53.654s, +5.337s
10:07:49,709  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 58.741s, +5.087s
10:07:54,820  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 01:03, +5.111s
10:07:59,153  INFO [org.jooq.tools.StopWatch                          ] - Finished prepared statements keeping them open: Total: 01:08, +4.333s
10:07:59,317  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 163.697ms
10:07:59,317  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 163.86ms, +0.163ms
10:07:59,317  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 163.933ms, +0.073ms
10:07:59,317  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 164.002ms, +0.069ms
10:07:59,317  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 164.071ms, +0.068ms
10:07:59,317  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 164.141ms, +0.069ms
10:09:50,740  INFO [org.jooq.tools.StopWatch                          ] - Finished prepared statement batch: Total: 01:51, +01:51
10:09:52,032  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 1.291s
10:09:57,338  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 6.597s, +5.306s
10:10:02,824  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 12.083s, +5.485s
10:10:07,975  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 17.233s, +5.15s
10:10:12,938  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 22.197s, +4.963s
10:10:17,990  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 27.249s, +5.051s
10:10:22,043  INFO [org.jooq.tools.StopWatch                          ] - Finished static statements: Total: 31.302s, +4.053s
10:10:22,043  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 0.057ms
10:10:22,043  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 0.121ms, +0.063ms
10:10:22,043  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 0.175ms, +0.053ms
10:10:22,043  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 0.221ms, +0.045ms
10:10:22,043  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 0.263ms, +0.042ms
10:10:22,043  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 0.312ms, +0.049ms
10:12:07,408  INFO [org.jooq.tools.StopWatch                          ] - Finished static statement batch: Total: 01:45, +01:45

Again, static statements had fewest outliers

@lukaseder
Copy link
Author

Another run, and proof that any experienced effect is merely due to random outliers, not systematic:

14:27:26,257 DEBUG [org.jooq.tools.LoggerListener                     ] - Executing query          : create or replace table speed_test (i int64)
14:27:26,803 DEBUG [org.jooq.tools.LoggerListener                     ] - Affected row(s)          : 0
14:27:27,762  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 956.938ms
14:28:04,674  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 37.868s, +36.912s
14:28:10,257  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 43.452s, +5.583s
14:28:50,845  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 01:24, +40.586s
14:29:30,662  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 02:03, +39.817s
14:29:56,245  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 02:29, +25.582s
14:30:00,703  INFO [org.jooq.tools.StopWatch                          ] - Finished prepared statements: Total: 02:33, +4.458s
14:30:01,814  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 1.111s
14:30:26,649  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 25.946s, +24.834s
14:31:04,576  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 01:03, +37.926s
14:31:09,070  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 01:08, +4.493s
14:31:13,562  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 01:12, +4.492s
14:31:40,401  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 01:39, +26.84s
14:32:08,975  INFO [org.jooq.tools.StopWatch                          ] - Finished prepared statements keeping them open: Total: 02:08, +28.573s
14:32:09,195  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 219.719ms
14:32:09,195  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 220.106ms, +0.387ms
14:32:09,195  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 220.382ms, +0.275ms
14:32:09,196  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 220.638ms, +0.256ms
14:32:09,196  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 220.881ms, +0.242ms
14:32:09,196  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 221.15ms, +0.269ms
14:33:31,574  INFO [org.jooq.tools.StopWatch                          ] - Finished prepared statement batch: Total: 01:22, +01:22
14:33:32,474  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 900.605ms
14:33:58,912  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 27.337s, +26.437s
14:34:03,312  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 31.737s, +4.4s
14:34:39,642  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 01:08, +36.33s
14:35:06,393  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 01:34, +26.751s
14:35:10,910  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 01:39, +4.517s
14:35:42,597  INFO [org.jooq.tools.StopWatch                          ] - Finished static statements: Total: 02:11, +31.687s
14:35:42,597  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 0            : Total: 0.075ms
14:35:42,597  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 5            : Total: 0.136ms, +0.061ms
14:35:42,597  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 10           : Total: 0.191ms, +0.054ms
14:35:42,597  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 15           : Total: 0.236ms, +0.045ms
14:35:42,598  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 20           : Total: 0.282ms, +0.045ms
14:35:42,598  INFO [org.jooq.tools.StopWatch                          ] - Insertions: 25           : Total: 0.333ms, +0.05ms
14:37:13,959  INFO [org.jooq.tools.StopWatch                          ] - Finished static statement batch: Total: 01:31, +01:31

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment