Skip to content

Commit f554591

Browse files
committed
redesign query inspector
Signed-off-by: neo <1100909+neowu@users.noreply.github.com>
1 parent 2ebc849 commit f554591

File tree

16 files changed

+86
-61
lines changed

16 files changed

+86
-61
lines changed

CHANGELOG.md

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,10 +1,10 @@
11
## Change log
22

3-
### 9.4.0-b4 (1/26/26 - )
3+
### 9.4.0-b5 (1/26/26 - )
44

55
* log: for rust version of log-processor/log-collector/log-exporter, refer to https://github.com/neowu/core_rs_workspace
66
* db: removed mysql sslmode property, SSL mode will be detected by driver automatically
7-
* db: actively inspect query plan once per SQL
7+
* db: actively inspect query plan every 6 hours per SQL
88
> !!! update MySQL driver to "core.framework.mysql:mysql-connector-j:8.4.0-r6" first if you are using customized mysql driver (due to QueryDiagnostic class deleted)
99
> via `explain`, support both MySQL and PostgreSQL, table scan more than 2000 rows is considered inefficient
1010
> removed Database.suppressSlowSQLWarning(false);

build.gradle.kts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,7 @@ plugins {
66

77
subprojects {
88
group = "core.framework"
9-
version = "9.4.0-b4"
9+
version = "9.4.0-b5"
1010
repositories {
1111
maven {
1212
url = uri("https://neowu.github.io/maven-repo/")

core-ng/src/main/java/core/framework/db/Query.java

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,7 @@
11
package core.framework.db;
22

3+
import org.jspecify.annotations.Nullable;
4+
35
import java.util.List;
46
import java.util.Optional;
57

@@ -13,9 +15,9 @@ public interface Query<T> {
1315

1416
void groupBy(String groupBy);
1517

16-
void skip(Integer skip); // pass null to reset skip
18+
void skip(@Nullable Integer skip); // pass null to reset skip
1719

18-
void limit(Integer limit); // pass null to reset limit
20+
void limit(@Nullable Integer limit); // pass null to reset limit
1921

2022
List<T> fetch();
2123

core-ng/src/main/java/core/framework/internal/db/DatabaseImpl.java

Lines changed: 25 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,8 @@
3434
import java.util.Properties;
3535
import java.util.UUID;
3636

37+
import static core.framework.log.Markers.errorCode;
38+
3739
/**
3840
* @author neo
3941
*/
@@ -224,9 +226,9 @@ public Transaction beginTransaction() {
224226

225227
@Override
226228
public <T> List<T> select(String sql, Class<T> viewClass, Object... params) {
227-
var watch = new StopWatch();
228-
inspector.inspect(sql, params);
229+
String inefficientPlan = inspector.inspect(sql, params);
229230

231+
var watch = new StopWatch();
230232
int returnedRows = 0;
231233
try {
232234
List<T> results = operation.select(sql, rowMapper(viewClass), params);
@@ -236,18 +238,15 @@ public <T> List<T> select(String sql, Class<T> viewClass, Object... params) {
236238
long elapsed = watch.elapsed();
237239
logger.debug("select, sql={}, params={}, returnedRows={}, elapsed={}", sql, new SQLParams(operation.enumMapper, params), returnedRows, elapsed);
238240
boolean slow = track(elapsed, returnedRows, 0, 1); // check after sql debug log, to make log easier to read
239-
if (slow) {
240-
String plan = inspector.explain(sql, params);
241-
logger.debug("plan=\n{}", plan);
242-
}
241+
logQueryPlan(inefficientPlan, slow, sql, params);
243242
}
244243
}
245244

246245
@Override
247246
public <T> Optional<T> selectOne(String sql, Class<T> viewClass, Object... params) {
248-
var watch = new StopWatch();
249-
inspector.inspect(sql, params);
247+
String inefficientPlan = inspector.inspect(sql, params);
250248

249+
var watch = new StopWatch();
251250
int returnedRows = 0;
252251
try {
253252
Optional<T> result = operation.selectOne(sql, rowMapper(viewClass), params);
@@ -257,35 +256,33 @@ public <T> Optional<T> selectOne(String sql, Class<T> viewClass, Object... param
257256
long elapsed = watch.elapsed();
258257
logger.debug("selectOne, sql={}, params={}, returnedRows={}, elapsed={}", sql, new SQLParams(operation.enumMapper, params), returnedRows, elapsed);
259258
boolean slow = track(elapsed, returnedRows, 0, 1);
260-
if (slow) {
261-
String plan = inspector.explain(sql, params);
262-
logger.debug("plan=\n{}", plan);
263-
}
259+
logQueryPlan(inefficientPlan, slow, sql, params);
264260
}
265261
}
266262

267263
@Override
268264
public int execute(String sql, Object... params) {
269-
var watch = new StopWatch();
270-
inspector.inspect(sql, params);
265+
String inefficientPlan = inspector.inspect(sql, params);
271266

267+
var watch = new StopWatch();
272268
int affectedRows = 0;
273269
try {
274270
affectedRows = operation.update(sql, params);
275271
return affectedRows;
276272
} finally {
277273
long elapsed = watch.elapsed();
278274
logger.debug("execute, sql={}, params={}, affectedRows={}, elapsed={}", sql, new SQLParams(operation.enumMapper, params), affectedRows, elapsed);
279-
track(elapsed, 0, affectedRows, 1);
275+
boolean slow = track(elapsed, 0, affectedRows, 1);
276+
logQueryPlan(inefficientPlan, slow, sql, params);
280277
}
281278
}
282279

283280
@Override
284281
public int[] batchExecute(String sql, List<Object[]> params) {
285-
var watch = new StopWatch();
286282
if (params.isEmpty()) throw new Error("params must not be empty");
287-
inspector.inspect(sql, params.getFirst());
283+
String inefficientPlan = inspector.inspect(sql, params.getFirst());
288284

285+
var watch = new StopWatch();
289286
int affectedRows = 0;
290287
try {
291288
int[] results = operation.batchUpdate(sql, params);
@@ -300,11 +297,12 @@ public int[] batchExecute(String sql, List<Object[]> params) {
300297
long elapsed = watch.elapsed();
301298
int size = params.size();
302299
logger.debug("batchExecute, sql={}, params={}, size={}, affectedRows={}, elapsed={}", sql, new SQLBatchParams(operation.enumMapper, params), size, affectedRows, elapsed);
303-
track(elapsed, 0, affectedRows, size);
300+
boolean slow = track(elapsed, 0, affectedRows, size);
301+
logQueryPlan(inefficientPlan, slow, sql, params.getFirst());
304302
}
305303
}
306304

307-
private <T> RowMapper<T> rowMapper(Class<T> viewClass) {
305+
<T> RowMapper<T> rowMapper(Class<T> viewClass) {
308306
@SuppressWarnings("unchecked")
309307
RowMapper<T> mapper = (RowMapper<T>) rowMappers.get(viewClass);
310308
if (mapper == null)
@@ -329,4 +327,12 @@ boolean track(long elapsed, int readRows, int writeRows, int queries) {
329327
}
330328
return false;
331329
}
330+
331+
private void logQueryPlan(@Nullable String inefficientPlan, boolean slow, String sql, Object[] params) {
332+
if (inefficientPlan != null) {
333+
logger.warn(errorCode("INEFFICIENT_QUERY"), "inefficient query, plan:\n{}", inefficientPlan);
334+
} else if (slow) {
335+
logger.debug("plan:\n{}", inspector.explain(sql, params));
336+
}
337+
}
332338
}

core-ng/src/main/java/core/framework/internal/db/InsertQuery.java

Lines changed: 1 addition & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -7,15 +7,13 @@
77
*/
88
final class InsertQuery<T> {
99
final String insertSQL;
10-
@Nullable
1110
final String insertIgnoreSQL;
12-
@Nullable
1311
final String upsertSQL;
1412
@Nullable
1513
final String generatedColumn;
1614
private final InsertQueryParamBuilder<T> paramBuilder;
1715

18-
InsertQuery(String insertSQL, @Nullable String insertIgnoreSQL, @Nullable String upsertSQL, @Nullable String generatedColumn, InsertQueryParamBuilder<T> paramBuilder) {
16+
InsertQuery(String insertSQL, String insertIgnoreSQL, String upsertSQL, @Nullable String generatedColumn, InsertQueryParamBuilder<T> paramBuilder) {
1917
this.insertSQL = insertSQL;
2018
this.insertIgnoreSQL = insertIgnoreSQL;
2119
this.upsertSQL = upsertSQL;

core-ng/src/main/java/core/framework/internal/db/InsertQueryBuilder.java

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -31,9 +31,7 @@ class InsertQueryBuilder<T> {
3131
private String generatedColumn; // db entity must not have more than one auto incremental primary key, validated by DatabaseClassValidator
3232
private List<ParamField> paramFields;
3333
private String insertSQL;
34-
@Nullable
3534
private String insertIgnoreSQL;
36-
@Nullable
3735
private String upsertSQL;
3836

3937
InsertQueryBuilder(Class<T> entityClass, Dialect dialect) {

core-ng/src/main/java/core/framework/internal/db/QueryImpl.java

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -56,12 +56,12 @@ public void groupBy(String groupBy) {
5656
}
5757

5858
@Override
59-
public void skip(Integer skip) {
59+
public void skip(@Nullable Integer skip) {
6060
this.skip = skip;
6161
}
6262

6363
@Override
64-
public void limit(Integer limit) {
64+
public void limit(@Nullable Integer limit) {
6565
if (limit != null && limit <= 0) throw new Error("limit must be greater than 0, limit=" + limit);
6666
this.limit = limit;
6767
}

core-ng/src/main/java/core/framework/internal/db/RepositoryImpl.java

Lines changed: 14 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -49,9 +49,21 @@ public Query<T> select() {
4949

5050
@Override
5151
public Optional<T> get(Object... primaryKeys) {
52-
if (primaryKeys.length != selectQuery.primaryKeyColumns)
52+
var watch = new StopWatch();
53+
if (primaryKeys.length != selectQuery.primaryKeyColumns) {
5354
throw new Error(Strings.format("the length of primary keys does not match columns, primaryKeys={}, columns={}", selectQuery.primaryKeyColumns, primaryKeys.length));
54-
return database.selectOne(selectQuery.getSQL, entityClass, primaryKeys);
55+
}
56+
String sql = selectQuery.getSQL;
57+
int returnedRows = 0;
58+
try {
59+
Optional<T> result = database.operation.selectOne(sql, database.rowMapper(entityClass), primaryKeys);
60+
if (result.isPresent()) returnedRows = 1;
61+
return result;
62+
} finally {
63+
long elapsed = watch.elapsed();
64+
logger.debug("get, sql={}, params={}, returnedRows={}, elapsed={}", sql, new SQLParams(database.operation.enumMapper, primaryKeys), returnedRows, elapsed);
65+
database.track(elapsed, returnedRows, 0, 1);
66+
}
5567
}
5668

5769
@Override

core-ng/src/main/java/core/framework/internal/db/SelectQuery.java

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -54,7 +54,7 @@ private String columns(List<Field> fields) {
5454
return builder.toString();
5555
}
5656

57-
String fetchSQL(StringBuilder where, String sort, Integer skip, Integer limit) {
57+
String fetchSQL(StringBuilder where, String sort, @Nullable Integer skip, @Nullable Integer limit) {
5858
return sql(columns, where, null, sort, skip, limit);
5959
}
6060

core-ng/src/main/java/core/framework/internal/db/inspector/PostgreSQLQueryAnalyzer.java

Lines changed: 9 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -29,21 +29,24 @@ public QueryPlan explain(String sql, Object[] params) {
2929

3030
// Seq Scan on some_table (cost=0.00..657.94 rows=976 width=96)
3131
boolean isEfficient(String queryPlan) {
32-
int index = queryPlan.indexOf("Seq Scan");
33-
if (index >= 0) {
34-
long rows = parseRows(queryPlan, index + 8);
32+
if (queryPlan.contains("Seq Scan")) {
33+
long rows = parseRows(queryPlan);
3534
return rows <= 2000; // accept seq scan for small table
35+
} else if (queryPlan.contains("Hash") && queryPlan.contains("Join")) {
36+
// hash join may load large table into memory, consider inefficient
37+
long rows = parseRows(queryPlan);
38+
return rows <= 50_000;
3639
}
3740
return true;
3841
}
3942

40-
private long parseRows(String queryPlan, int startIndex) {
41-
int rowsIndex = queryPlan.indexOf("rows=", startIndex);
43+
private long parseRows(String queryPlan) {
44+
int rowsIndex = queryPlan.indexOf(" rows=");
4245
if (rowsIndex < 0) return -1;
4346
int spaceIndex = queryPlan.indexOf(' ', rowsIndex + 5);
4447
if (spaceIndex < 0) return -1;
4548
try {
46-
return Long.parseLong(queryPlan.substring(rowsIndex + 5, spaceIndex));
49+
return Long.parseLong(queryPlan.substring(rowsIndex + 6, spaceIndex));
4750
} catch (NumberFormatException e) {
4851
logger.warn("failed to parse query plan, plan={}", queryPlan, e);
4952
return -1;

0 commit comments

Comments
 (0)