Skip to content

Commit db82c2c

Browse files
committed
* db: removed mysql sslmode property, SSL mode will be detected by driver automatically
* db: actively inspect query plan once every 24 hours > via `explain`, support both MySQL and PostgreSQL, table scan more than 2000 rows is considered inefficient > removed Database.suppressSlowSQLWarning(false); > removed old error code `SLOW_SQL`, replaced with `INEFFICIENT_QUERY` > print query plan if SLOW_DB * log: make ActionLogContext.track() return void Signed-off-by: neo <1100909+neowu@users.noreply.github.com>
1 parent db0f91c commit db82c2c

26 files changed

+434
-230
lines changed

CHANGELOG.md

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,15 @@
11
## Change log
22

3-
### 9.3.2 ( - )
3+
### 9.4.0-b0 (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
6+
* db: removed mysql sslmode property, SSL mode will be detected by driver automatically
7+
* db: actively inspect query plan once every 24 hours
8+
> via `explain`, support both MySQL and PostgreSQL, table scan more than 2000 rows is considered inefficient
9+
> removed Database.suppressSlowSQLWarning(false);
10+
> removed old error code `SLOW_SQL`, replaced with `INEFFICIENT_QUERY`
11+
> print query plan if SLOW_DB
12+
* log: make ActionLogContext.track() return void
613

714
### 9.3.1 (10/8/2025 - 11/7/2025)
815

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.3.1"
9+
version = "9.4.0-b0"
1010
repositories {
1111
maven {
1212
url = uri("https://neowu.github.io/maven-repo/")

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

Lines changed: 0 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -1,35 +1,12 @@
11
package core.framework.db;
22

3-
import core.framework.internal.log.ActionLog;
4-
import core.framework.internal.log.LogManager;
5-
63
import java.util.List;
74
import java.util.Optional;
85

96
/**
107
* @author neo
118
*/
129
public interface Database {
13-
/**
14-
* for expected slow sql, such as query with small table or db chooses different query plan,
15-
* disable warning then enable after<p>
16-
* e.g.
17-
* <blockquote><pre>
18-
* Database.suppressSlowSQLWarning(false);
19-
* database.select(...);
20-
* Database.suppressSlowSQLWarning(true);
21-
* </pre></blockquote>
22-
*
23-
* @param suppress whether suppress slow sql warning
24-
*/
25-
static void suppressSlowSQLWarning(boolean suppress) {
26-
// pass flag thru thread local to MySQLQueryInterceptor, and put in action log to reset for every action
27-
ActionLog actionLog = LogManager.currentActionLog();
28-
if (actionLog != null) {
29-
actionLog.warningContext.suppressSlowSQLWarning = suppress;
30-
}
31-
}
32-
3310
<T> List<T> select(String sql, Class<T> viewClass, Object... params);
3411

3512
<T> Optional<T> selectOne(String sql, Class<T> viewClass, Object... params);

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

Lines changed: 0 additions & 9 deletions
This file was deleted.

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

Lines changed: 33 additions & 44 deletions
Original file line numberDiff line numberDiff line change
@@ -7,10 +7,13 @@
77
import core.framework.db.Repository;
88
import core.framework.db.Transaction;
99
import core.framework.db.UncheckedSQLException;
10+
import core.framework.internal.db.inspector.MySQLQueryAnalyzer;
11+
import core.framework.internal.db.inspector.PostgreSQLQueryAnalyzer;
12+
import core.framework.internal.db.inspector.QueryInspector;
1013
import core.framework.internal.log.ActionLog;
1114
import core.framework.internal.log.LogManager;
15+
import core.framework.internal.log.TrackResult;
1216
import core.framework.internal.resource.Pool;
13-
import core.framework.util.ASCII;
1417
import core.framework.util.StopWatch;
1518
import org.jspecify.annotations.Nullable;
1619
import org.slf4j.Logger;
@@ -57,6 +60,7 @@ public final class DatabaseImpl implements Database {
5760
private @Nullable Properties driverProperties;
5861
private Duration timeout;
5962
private Driver driver;
63+
private QueryInspector inspector;
6064

6165
public DatabaseImpl(String name) {
6266
initializeRowMappers();
@@ -130,17 +134,12 @@ Properties driverProperties(String url) {
130134
properties.setProperty("logger", "Slf4JLogger");
131135
properties.setProperty("cachePrepStmts", "true");
132136

133-
int index = url.indexOf('?');
134-
// mysql with ssl has overhead, usually we ensure security on arch level, e.g. gcloud sql proxy or firewall rule
135-
// with gcloud/azure iam / clear_text_password plugin, ssl is required
136-
// refer to https://cloud.google.com/sql/docs/mysql/authentication
137+
// with gcloud/azure iam / clear_text_password plugin, ssl is required, refer to https://cloud.google.com/sql/docs/mysql/authentication
137138
if (authProvider != null) {
138-
properties.setProperty("sslMode", "PREFERRED");
139139
properties.setProperty(CloudAuthProvider.Provider.CLOUD_AUTH, "true");
140-
} else if (index == -1 || url.indexOf("sslMode=", index + 1) == -1) {
141-
properties.setProperty("sslMode", "DISABLED");
142140
}
143141
// refer to https://dev.mysql.com/doc/connector-j/en/connector-j-reference-charsets.html
142+
int index = url.indexOf('?');
144143
if (index == -1 || url.indexOf("characterEncoding=", index + 1) == -1)
145144
properties.setProperty("characterEncoding", "utf-8");
146145
} else if (url.startsWith("jdbc:postgresql:")) {
@@ -175,12 +174,15 @@ public void url(String url) {
175174
private Driver driver(String url) {
176175
if (url.startsWith("jdbc:mysql:")) {
177176
operation.dialect = Dialect.MYSQL;
177+
inspector = new QueryInspector(new MySQLQueryAnalyzer(operation));
178178
return createDriver("com.mysql.cj.jdbc.Driver");
179179
} else if (url.startsWith("jdbc:postgresql:")) {
180180
operation.dialect = Dialect.POSTGRESQL;
181+
inspector = new QueryInspector(new PostgreSQLQueryAnalyzer(operation));
181182
return createDriver("org.postgresql.Driver");
182183
} else if (url.startsWith("jdbc:hsqldb:")) {
183184
operation.dialect = Dialect.MYSQL; // unit test use mysql dialect
185+
inspector = new QueryInspector(null);
184186
return createDriver("org.hsqldb.jdbc.JDBCDriver");
185187
} else {
186188
throw new Error("not supported database, url=" + url);
@@ -224,7 +226,8 @@ public Transaction beginTransaction() {
224226
@Override
225227
public <T> List<T> select(String sql, Class<T> viewClass, Object... params) {
226228
var watch = new StopWatch();
227-
validateSQL(sql);
229+
inspector.inspect(sql, params);
230+
228231
int returnedRows = 0;
229232
try {
230233
List<T> results = operation.select(sql, rowMapper(viewClass), params);
@@ -233,14 +236,19 @@ public <T> List<T> select(String sql, Class<T> viewClass, Object... params) {
233236
} finally {
234237
long elapsed = watch.elapsed();
235238
logger.debug("select, sql={}, params={}, returnedRows={}, elapsed={}", sql, new SQLParams(operation.enumMapper, params), returnedRows, elapsed);
236-
track(elapsed, returnedRows, 0, 1); // check after sql debug log, to make log easier to read
239+
boolean slow = track(elapsed, returnedRows, 0, 1); // check after sql debug log, to make log easier to read
240+
if (slow) {
241+
String plan = inspector.explain(sql, params);
242+
logger.debug("plan=\n{}", plan);
243+
}
237244
}
238245
}
239246

240247
@Override
241248
public <T> Optional<T> selectOne(String sql, Class<T> viewClass, Object... params) {
242249
var watch = new StopWatch();
243-
validateSQL(sql);
250+
inspector.inspect(sql, params);
251+
244252
int returnedRows = 0;
245253
try {
246254
Optional<T> result = operation.selectOne(sql, rowMapper(viewClass), params);
@@ -249,14 +257,19 @@ public <T> Optional<T> selectOne(String sql, Class<T> viewClass, Object... param
249257
} finally {
250258
long elapsed = watch.elapsed();
251259
logger.debug("selectOne, sql={}, params={}, returnedRows={}, elapsed={}", sql, new SQLParams(operation.enumMapper, params), returnedRows, elapsed);
252-
track(elapsed, returnedRows, 0, 1);
260+
boolean slow = track(elapsed, returnedRows, 0, 1);
261+
if (slow) {
262+
String plan = inspector.explain(sql, params);
263+
logger.debug("plan=\n{}", plan);
264+
}
253265
}
254266
}
255267

256268
@Override
257269
public int execute(String sql, Object... params) {
258270
var watch = new StopWatch();
259-
validateSQL(sql);
271+
inspector.inspect(sql, params);
272+
260273
int affectedRows = 0;
261274
try {
262275
affectedRows = operation.update(sql, params);
@@ -271,8 +284,9 @@ public int execute(String sql, Object... params) {
271284
@Override
272285
public int[] batchExecute(String sql, List<Object[]> params) {
273286
var watch = new StopWatch();
274-
validateSQL(sql);
275287
if (params.isEmpty()) throw new Error("params must not be empty");
288+
inspector.inspect(sql, params.getFirst());
289+
276290
int affectedRows = 0;
277291
try {
278292
int[] results = operation.batchUpdate(sql, params);
@@ -307,39 +321,14 @@ private <T> void registerViewClass(Class<T> viewClass) {
307321
rowMappers.put(viewClass, mapper);
308322
}
309323

310-
void track(long elapsed, int readRows, int writeRows, int queries) {
324+
// return if slow
325+
boolean track(long elapsed, int readRows, int writeRows, int queries) {
311326
ActionLog actionLog = LogManager.currentActionLog();
312327
if (actionLog != null) {
313328
actionLog.stats.compute("db_queries", (k, oldValue) -> (oldValue == null) ? queries : oldValue + queries);
314-
actionLog.track("db", elapsed, readRows, writeRows, 0, 0);
315-
}
316-
}
317-
318-
void validateSQL(String sql) {
319-
if (sql.startsWith("CREATE ")) return; // ignore DDL
320-
321-
// validate asterisk
322-
// execute() could have select part, e.g. insert into select
323-
int index = sql.indexOf('*');
324-
while (index > -1) { // check whether it's wildcard or multiply operator
325-
int length = sql.length();
326-
char ch = 0;
327-
index++;
328-
for (; index < length; index++) {
329-
ch = sql.charAt(index);
330-
if (ch != ' ') break; // seek to next non-whitespace
331-
}
332-
if (ch == ','
333-
|| index == length // sql ends with *
334-
|| index + 4 <= length && ASCII.toUpperCase(ch) == 'F' && "FROM".equals(ASCII.toUpperCase(sql.substring(index, index + 4))))
335-
throw new Error("sql must not contain wildcard(*), please only select columns needed, sql=" + sql);
336-
index = sql.indexOf('*', index + 1);
329+
TrackResult result = actionLog.track("db", elapsed, readRows, writeRows, 0, 0);
330+
return result.slow();
337331
}
338-
339-
// validate string value
340-
// by this way, it also disallows functions with string values, e.g. IFNULL(column, 'value'), but it usually can be prevented by different design,
341-
// and we prefer to simplify db usage if possible, and shift complexity to application layer
342-
if (sql.indexOf('\'') != -1)
343-
throw new Error("sql must not contain single quote('), please use prepared statement and question mark(?), sql=" + sql);
332+
return false;
344333
}
345334
}

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

Lines changed: 3 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -1,15 +1,10 @@
11
package core.framework.internal.db;
22

33
import core.framework.db.Dialect;
4-
import core.framework.db.QueryDiagnostic;
54
import core.framework.db.UncheckedSQLException;
6-
import core.framework.internal.log.ActionLog;
7-
import core.framework.internal.log.LogManager;
85
import core.framework.internal.resource.PoolItem;
96
import core.framework.util.Lists;
107
import org.jspecify.annotations.Nullable;
11-
import org.slf4j.Logger;
12-
import org.slf4j.LoggerFactory;
138

149
import java.math.BigDecimal;
1510
import java.sql.Connection;
@@ -26,15 +21,13 @@
2621
import java.util.OptionalLong;
2722
import java.util.UUID;
2823

29-
import static core.framework.log.Markers.errorCode;
3024
import static core.framework.util.Strings.format;
3125

3226
/**
3327
* @author neo
3428
*/
3529
public class DatabaseOperation {
3630
final EnumDBMapper enumMapper = new EnumDBMapper();
37-
private final Logger logger = LoggerFactory.getLogger(DatabaseOperation.class);
3831
private final TransactionManager transactionManager;
3932
Dialect dialect;
4033
int queryTimeoutInSeconds;
@@ -50,9 +43,7 @@ int update(String sql, Object... params) {
5043
try (PreparedStatement statement = connection.resource.prepareStatement(sql)) {
5144
statement.setQueryTimeout(queryTimeoutInSeconds);
5245
setParams(statement, params);
53-
int result = statement.executeUpdate();
54-
logSlowQuery(statement);
55-
return result;
46+
return statement.executeUpdate();
5647
} catch (SQLException e) {
5748
Connections.checkConnectionState(connection, e);
5849
throw new UncheckedSQLException(e);
@@ -71,9 +62,7 @@ int[] batchUpdate(String sql, List<Object[]> params) {
7162
setParams(statement, batchParams);
7263
statement.addBatch();
7364
}
74-
int[] results = statement.executeBatch();
75-
logSlowQuery(statement);
76-
return results;
65+
return statement.executeBatch();
7766
} catch (SQLException e) {
7867
Connections.checkConnectionState(connection, e);
7968
throw new UncheckedSQLException(e);
@@ -96,7 +85,7 @@ <T> Optional<T> selectOne(String sql, RowMapper<T> mapper, Object... params) {
9685
}
9786
}
9887

99-
<T> List<T> select(String sql, RowMapper<T> mapper, Object... params) {
88+
public <T> List<T> select(String sql, RowMapper<T> mapper, Object... params) {
10089
PoolItem<Connection> connection = transactionManager.getConnection();
10190
try (PreparedStatement statement = connection.resource.prepareStatement(sql)) {
10291
statement.setQueryTimeout(queryTimeoutInSeconds);
@@ -155,8 +144,6 @@ private PreparedStatement insertStatement(Connection connection, String sql, @Nu
155144

156145
private <T> Optional<T> fetchOne(PreparedStatement statement, RowMapper<T> mapper) throws SQLException {
157146
try (ResultSet resultSet = statement.executeQuery()) {
158-
logSlowQuery(statement);
159-
160147
T result = null;
161148
if (resultSet.next()) {
162149
result = mapper.map(new ResultSetWrapper(resultSet, dialect));
@@ -169,8 +156,6 @@ private <T> Optional<T> fetchOne(PreparedStatement statement, RowMapper<T> mappe
169156

170157
private <T> List<T> fetch(PreparedStatement statement, RowMapper<T> mapper) throws SQLException {
171158
try (ResultSet resultSet = statement.executeQuery()) {
172-
logSlowQuery(statement);
173-
174159
var wrapper = new ResultSetWrapper(resultSet, dialect);
175160
List<T> results = Lists.newArrayList();
176161
while (resultSet.next()) {
@@ -266,22 +251,4 @@ private void setParam(PreparedStatement statement, int index, @Nullable Object p
266251
default -> throw new Error(format("unsupported param type, type={}, value={}", param.getClass().getCanonicalName(), param));
267252
}
268253
}
269-
270-
void logSlowQuery(PreparedStatement statement) {
271-
if (statement instanceof QueryDiagnostic diagnostic) {
272-
boolean noIndexUsed = diagnostic.noIndexUsed();
273-
boolean badIndexUsed = diagnostic.noGoodIndexUsed();
274-
if (!noIndexUsed && !badIndexUsed) return;
275-
276-
ActionLog actionLog = LogManager.currentActionLog();
277-
boolean warning = actionLog == null || !actionLog.warningContext.suppressSlowSQLWarning;
278-
String message = noIndexUsed ? "no index used" : "bad index used";
279-
String sqlValue = diagnostic.sql();
280-
if (warning) {
281-
logger.warn(errorCode("SLOW_SQL"), "{}, sql={}", message, sqlValue);
282-
} else {
283-
logger.debug("{}, sql={}", message, sqlValue);
284-
}
285-
}
286-
}
287254
}

0 commit comments

Comments
 (0)