I’ve run across a fun little trick to simulate latency in your development environments when testing some SQL queries. Possible use-cases including to validate that backend latency won’t bring down your frontend, or that your UX is still bearable, etc.
The solution is PostgreSQL and Hibernate specific, though to doesn’t have to be. Besides, it uses a stored function to work around the limitations of a VOID function in PostgreSQL, but that can be worked around differently as well, without storing anything auxiliary to the catalog.
To remove the Hibernate dependency, you can just use the pg_sleep function directly using a NULL predicate, but don’t try it like this!
select 1
from t_book
-- Don't do this!
where pg_sleep(1) is not null;
This will sleep 1 second per row (!). As can be seen in the explain plan. Let’s limit to 3 rows to see:
explain analyze
select 1
from t_book
where pg_sleep(1) is not null
limit 3;
And the result is:
Limit (cost=0.00..1.54 rows=3 width=4) (actual time=1002.142..3005.374 rows=3 loops=1)
-> Seq Scan on t_book (cost=0.00..2.05 rows=4 width=4) (actual time=1002.140..3005.366 rows=3 loops=1)
Filter: (pg_sleep('1'::double precision) IS NOT NULL)
Planning Time: 2.036 ms
Execution Time: 3005.401 ms
As you can see, the whole query took about 3 seconds for 3 rows. In fact, this is also what happens in Gunnar’s example from the tweet, except that he was filtering by ID, which “helps” hide this effect.
We can use what Oracle calls scalar subquery caching, the fact that a scalar subquery can be reasonably expected to be side-effect free (despite the obvious side-effect of pg_sleep), meaning that some RDBMS cache its result per query execution.
explain analyze
select 1
from t_book
where (select pg_sleep(1)) is not null
limit 3;
The result is now:
Limit (cost=0.01..1.54 rows=3 width=4) (actual time=1001.177..1001.178 rows=3 loops=1)
InitPlan 1 (returns $0)
-> Result (cost=0.00..0.01 rows=1 width=4) (actual time=1001.148..1001.148 rows=1 loops=1)
-> Result (cost=0.00..2.04 rows=4 width=4) (actual time=1001.175..1001.176 rows=3 loops=1)
One-Time Filter: ($0 IS NOT NULL)
-> Seq Scan on t_book (cost=0.00..2.04 rows=4 width=0) (actual time=0.020..0.021 rows=3 loops=1)
Planning Time: 0.094 ms
Execution Time: 1001.223 ms
We’re now getting the desired one-time filter. However, I don’t really like this hack, because it depends on an optimisation, which is optional, not a formal guarantee. This may be good enough for a quick simulation of latency, but don’t depend on this kind of optimisation in production lightheartedly.
Another approach that seems to guarantee this behaviour would be to use a MATERIALIZED CTE:
explain
with s (x) as materialized (select pg_sleep(1))
select *
from t_book
where (select x from s) is not null;
I’m now again using a scalar subquery, because I somehow need to access the CTE, and I don’t want to place it in the FROM clause, where it would impact my projection.
The plan being:
Result (cost=0.03..2.07 rows=4 width=943) (actual time=1001.289..1001.292 rows=4 loops=1)
One-Time Filter: ($1 IS NOT NULL)
CTE s
-> Result (...) (actual time=1001.262..1001.263 rows=1 loops=1)
InitPlan 2 (returns $1)
-> CTE Scan on s (cost=0.00..0.02 rows=1 width=4) (actual time=1001.267..1001.268 rows=1 loops=1)
-> Seq Scan on t_book (cost=0.03..2.07 rows=4 width=943) (actual time=0.015..0.016 rows=4 loops=1)
Planning Time: 0.049 ms
Execution Time: 1001.308 ms
Again, containing a one-time filter, which is what we want here.
Using a JDBC based approach
If your application is JDBC based, you don’t have to simulate the latency by tweaking the query. You can simply proxy JDBC in one way or another. Let’s look at this little program:
try (Connection c1 = db.getConnection()) {
// A Connection proxy that intercepts preparedStatement() calls
Connection c2 = new DefaultConnection(c1) {
@Override
public PreparedStatement prepareStatement(String sql)
throws SQLException {
sleep(1000L);
return super.prepareStatement(sql);
}
};
long time = System.nanoTime();
String sql = "SELECT id FROM book";
// This call now has a 1 second "latency"
try (PreparedStatement s = c2.prepareStatement(sql);
ResultSet rs = s.executeQuery()) {
while (rs.next())
System.out.println(rs.getInt(1));
}
System.out.println("Time taken: " +
(System.nanoTime() - time) / 1_000_000L + "ms");
}
Where:
public static void sleep(long time) {
try {
Thread.sleep(time);
}
catch (InterruptedException e) {
Thread.currentThread().interrupt();
}
}
For simplicity reasons, this uses jOOQ’s DefaultConnection which acts as a proxy, conveniently delegating all the methods to some delegate connection, allowing for overriding only specific methods. The output of the program is:
1 2 3 4 Time taken: 1021ms
This simulates the latency on the prepareStatement() event. Obviously, you’d be extracting the proxying into some utility in order not to clutter your code. You could even proxy all your queries in development and enable the sleep call only based on a system property.
Alternatively, we could also simulate it on the executeQuery() event:
try (Connection c = db.getConnection()) {
long time = System.nanoTime();
// A PreparedStatement proxy intercepting executeQuery() calls
try (PreparedStatement s = new DefaultPreparedStatement(
c.prepareStatement("SELECT id FROM t_book")
) {
@Override
public ResultSet executeQuery() throws SQLException {
sleep(1000L);
return super.executeQuery();
};
};
// This call now has a 1 second "latency"
ResultSet rs = s.executeQuery()) {
while (rs.next())
System.out.println(rs.getInt(1));
}
System.out.println("Time taken: " +
(System.nanoTime() - time) / 1_000_000L + "ms");
}
This is now using the jOOQ convenience class DefaultPreparedStatement. If you need these, just add the jOOQ Open Source Edition dependency (there’s nothing RDBMS specific in these classes), with any JDBC based application, including Hibernate:
<dependency>
<groupId>org.jooq</groupId>
<artifactId>jooq</artifactId>
</dependency>
Alternatively, just copy the sources of the classes DefaultConnection or DefaultPreparedStatement if you don’t need the entire dependency, or you just proxy the JDBC API yourself.
A jOOQ based solution
If you’re already using jOOQ (and you should be!), you can do this even more easily, by implementing an ExecuteListener. Our program would now look like this:
try (Connection c = db.getConnection()) {
DSLContext ctx = DSL.using(new DefaultConfiguration()
.set(c)
.set(new CallbackExecuteListener()
.onExecuteStart(x -> sleep(1000L))
)
);
long time = System.nanoTime();
System.out.println(ctx.fetch("SELECT id FROM t_book"));
System.out.println("Time taken: " +
(System.nanoTime() - time) / 1_000_000L + "ms");
}
Still the same result:
+----+ |id | +----+ |1 | |2 | |3 | |4 | +----+ Time taken: 1025ms
The difference is that with a single intercepting callback, we can now add this sleep to all types of statements, including prepared statements, static statements, statements returning result sets, or update counts, or both.