lxy/redkale
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

增加慢sql告警日志

Browse Source
This commit is contained in:
Redkale
2022-12-17 11:07:34 +08:00
parent 8fd679d21f
commit 543db6f8ab
5 changed files with 146 additions and 5 deletions
Download Patch File Download Diff File Expand all files Collapse all files

8
src/main/java/org/redkale/net/ProtocolCodec.java
View File

@@ -138,7 +138,9 @@ class ProtocolCodec implements CompletionHandler<Integer, ByteBuffer> {
LongAdder ec = preparer.executeCounter;
if (ec != null) ec.increment();
channel.offerBuffer(buffer);
if (rs != Integer.MIN_VALUE && preparer.illRequestCounter != null) preparer.illRequestCounter.increment();
if (rs != Integer.MIN_VALUE && preparer.illRequestCounter != null) {
preparer.illRequestCounter.increment();
}
response.finish(true);
if (context.logger.isLoggable(Level.FINEST)) {
context.logger.log(Level.FINEST, "request.readHeader erroneous (" + rs + "), force to close channel ");
@@ -186,7 +188,9 @@ class ProtocolCodec implements CompletionHandler<Integer, ByteBuffer> {
@Override
public void failed(Throwable exc, ByteBuffer attachment) {
if (context.prepare.illRequestCounter != null) context.prepare.illRequestCounter.increment();
if (context.prepare.illRequestCounter != null) {
context.prepare.illRequestCounter.increment();
}
channel.offerBuffer(attachment);
response.finish(true);
if (exc != null) request.context.logger.log(Level.FINER, "Servlet read channel erroneous, force to close channel ", exc);

3
src/main/java/org/redkale/net/http/HttpRequest.java
View File

@@ -926,8 +926,7 @@ public class HttpRequest extends Request<HttpContext> {
start = 0;
len = index;
}
if (charset == null) return new String(bs, start, len, StandardCharsets.UTF_8);
return new String(bs, start, len, charset);
return new String(bs, start, len, charset == null ? StandardCharsets.UTF_8 : charset);
}
private static int hexBit(byte b) {

3
src/main/java/org/redkale/source/AbstractDataSource.java
View File

@@ -65,6 +65,9 @@ public abstract class AbstractDataSource extends AbstractService implements Data
//@since 2.7.0
public static final String DATA_SOURCE_PIPELINES = "pipelines";
//@since 2.7.0 //超过多少毫秒视为慢, 会打印警告级别的日志, 默认值: 3000
public static final String DATA_SOURCE_SLOWMS = "slowms";
//@since 2.7.0
public static final String DATA_SOURCE_AUTOMAPPING = "auto-mapping";

130
src/main/java/org/redkale/source/DataJdbcSource.java
View File

@@ -127,6 +127,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Integer> insertDB(EntityInfo<T> info, T... entitys) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
int c = 0;
conn = writePool.pollConnection();
@@ -268,6 +269,12 @@ public class DataJdbcSource extends DataSqlSource {
if (info.isLoggable(logger, Level.FINEST, debugsql)) logger.finest(info.getType().getSimpleName() + " insert sql=" + debugsql.replaceAll("(\r|\n)", "\\n"));
}
} //打印结束
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(c);
} catch (SQLException e) {
return CompletableFuture.failedFuture(e);
@@ -312,6 +319,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Integer> deleteDB(EntityInfo<T> info, Flipper flipper, String sql) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = writePool.pollConnection();
conn.setReadOnly(false);
@@ -321,6 +329,12 @@ public class DataJdbcSource extends DataSqlSource {
final Statement stmt = conn.createStatement();
int c = stmt.executeUpdate(sql);
stmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(c);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -338,6 +352,12 @@ public class DataJdbcSource extends DataSqlSource {
st.executeBatch();
}
st.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(0);
} catch (SQLException e2) {
return CompletableFuture.failedFuture(e2);
@@ -354,6 +374,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Integer> clearTableDB(EntityInfo<T> info, final String table, String sql) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = writePool.pollConnection();
conn.setReadOnly(false);
@@ -361,6 +382,12 @@ public class DataJdbcSource extends DataSqlSource {
final Statement stmt = conn.createStatement();
int c = stmt.executeUpdate(sql);
stmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(c);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) return CompletableFuture.completedFuture(-1);
@@ -373,6 +400,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Integer> dropTableDB(EntityInfo<T> info, final String table, String sql) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = writePool.pollConnection();
conn.setReadOnly(false);
@@ -384,6 +412,12 @@ public class DataJdbcSource extends DataSqlSource {
String tablekey = table.indexOf('.') > 0 ? table : (conn.getCatalog() + '.' + table);
info.removeDisTable(tablekey);
}
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(c);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) return CompletableFuture.completedFuture(-1);
@@ -396,6 +430,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Integer> updateEntityDB(EntityInfo<T> info, T... entitys) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = writePool.pollConnection();
conn.setReadOnly(false);
@@ -436,6 +471,12 @@ public class DataJdbcSource extends DataSqlSource {
if (p >= 0) c += p;
}
prestmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + updateSQL);
}
}
return CompletableFuture.completedFuture(c);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -468,6 +509,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Integer> updateColumnDB(EntityInfo<T> info, Flipper flipper, String sql, boolean prepared, Object... params) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = writePool.pollConnection();
conn.setReadOnly(false);
@@ -482,12 +524,24 @@ public class DataJdbcSource extends DataSqlSource {
}
int c = prestmt.executeUpdate();
prestmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(c);
} else {
if (info.isLoggable(logger, Level.FINEST, sql)) logger.finest(info.getType().getSimpleName() + " update sql=" + sql);
final Statement stmt = conn.createStatement();
int c = stmt.executeUpdate(sql);
stmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(c);
}
} catch (SQLException e) {
@@ -522,6 +576,7 @@ public class DataJdbcSource extends DataSqlSource {
protected <T, N extends Number> CompletableFuture<Map<String, N>> getNumberMapDB(EntityInfo<T> info, String sql, FilterFuncColumn... columns) {
Connection conn = null;
final Map map = new HashMap<>();
final long s = System.currentTimeMillis();
try {
conn = readPool.pollConnection();
//conn.setReadOnly(true);
@@ -540,6 +595,12 @@ public class DataJdbcSource extends DataSqlSource {
}
set.close();
stmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(map);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -572,6 +633,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Number> getNumberResultDB(EntityInfo<T> info, String sql, Number defVal, String column) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = readPool.pollConnection();
//conn.setReadOnly(true);
@@ -584,6 +646,12 @@ public class DataJdbcSource extends DataSqlSource {
}
set.close();
stmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(rs);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -616,6 +684,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T, K extends Serializable, N extends Number> CompletableFuture<Map<K, N>> queryColumnMapDB(EntityInfo<T> info, String sql, String keyColumn) {
Connection conn = null;
final long s = System.currentTimeMillis();
Map<K, N> rs = new LinkedHashMap<>();
try {
conn = readPool.pollConnection();
@@ -629,6 +698,12 @@ public class DataJdbcSource extends DataSqlSource {
}
set.close();
stmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(rs);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -662,6 +737,7 @@ public class DataJdbcSource extends DataSqlSource {
protected <T, K extends Serializable, N extends Number> CompletableFuture<Map<K[], N[]>> queryColumnMapDB(EntityInfo<T> info, String sql, final ColumnNode[] funcNodes, final String[] groupByColumns) {
Connection conn = null;
Map rs = new LinkedHashMap<>();
final long s = System.currentTimeMillis();
try {
conn = readPool.pollConnection();
//conn.setReadOnly(true);
@@ -689,6 +765,12 @@ public class DataJdbcSource extends DataSqlSource {
}
set.close();
stmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(rs);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -721,6 +803,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<T> findDB(EntityInfo<T> info, String sql, boolean onlypk, SelectColumn selects) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = readPool.pollConnection();
//conn.setReadOnly(true);
@@ -730,6 +813,12 @@ public class DataJdbcSource extends DataSqlSource {
T rs = set.next() ? selects == null ? info.getFullEntityValue(set) : info.getEntityValue(selects, set) : null;
set.close();
ps.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(rs);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -762,6 +851,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Serializable> findColumnDB(EntityInfo<T> info, String sql, boolean onlypk, String column, Serializable defValue) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = readPool.pollConnection();
//conn.setReadOnly(true);
@@ -775,6 +865,12 @@ public class DataJdbcSource extends DataSqlSource {
}
set.close();
ps.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(val == null ? defValue : val);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -807,6 +903,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Boolean> existsDB(EntityInfo<T> info, String sql, boolean onlypk) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = readPool.pollConnection();
//conn.setReadOnly(true);
@@ -816,6 +913,12 @@ public class DataJdbcSource extends DataSqlSource {
set.close();
ps.close();
if (info.isLoggable(logger, Level.FINEST, sql)) logger.finest(info.getType().getSimpleName() + " exists (" + rs + ") sql=" + sql);
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return CompletableFuture.completedFuture(rs);
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -848,6 +951,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
protected <T> CompletableFuture<Sheet<T>> querySheetDB(EntityInfo<T> info, final boolean readcache, boolean needtotal, final boolean distinct, SelectColumn selects, Flipper flipper, FilterNode node) {
Connection conn = null;
final long s = System.currentTimeMillis();
try {
conn = readPool.pollConnection();
//conn.setReadOnly(true);
@@ -883,6 +987,12 @@ public class DataJdbcSource extends DataSqlSource {
set.close();
ps.close();
}
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, sheet-content: " + listsql);
}
}
return CompletableFuture.completedFuture(new Sheet<>(total, list));
}
final String listsql = "SELECT " + (distinct ? "DISTINCT " : "") + info.getFullQueryColumns("a", selects) + " FROM " + info.getTable(node) + " a" + (join == null ? "" : join)
@@ -918,6 +1028,12 @@ public class DataJdbcSource extends DataSqlSource {
}
set.close();
ps.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + listsql);
}
}
return CompletableFuture.completedFuture(new Sheet<>(total, list));
} catch (SQLException e) {
if (isTableNotExist(info, e.getSQLState())) {
@@ -973,6 +1089,7 @@ public class DataJdbcSource extends DataSqlSource {
@Override
public int[] directExecute(String... sqls) {
if (sqls.length == 0) return new int[0];
final long s = System.currentTimeMillis();
Connection conn = writePool.pollConnection();
try {
conn.setReadOnly(false);
@@ -983,6 +1100,12 @@ public class DataJdbcSource extends DataSqlSource {
rs[++i] = stmt.execute(sql) ? 1 : 0;
}
stmt.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + Arrays.toString(sqls));
}
}
return rs;
} catch (SQLException e) {
throw new RuntimeException(e);
@@ -1004,6 +1127,7 @@ public class DataJdbcSource extends DataSqlSource {
@Local
@Override
public <V> V directQuery(String sql, Function<DataResultSet, V> handler) {
final long s = System.currentTimeMillis();
final Connection conn = readPool.pollConnection();
try {
if (logger.isLoggable(Level.FINEST)) logger.finest("direct query sql=" + sql);
@@ -1014,6 +1138,12 @@ public class DataJdbcSource extends DataSqlSource {
V rs = handler.apply(createDataResultSet(null, set));
set.close();
statement.close();
if (slowms > 0) {
long cost = System.currentTimeMillis() - s;
if (cost > slowms) {
logger.log(Level.WARNING, DataSource.class.getSimpleName() + "(name='" + resourceName() + "') slow sql cost " + cost + " ms, content: " + sql);
}
}
return rs;
} catch (Exception ex) {
throw new RuntimeException(ex);

7
src/main/java/org/redkale/source/DataSqlSource.java
View File

@@ -40,7 +40,7 @@ public abstract class DataSqlSource extends AbstractDataSource implements Functi
protected final Logger logger = Logger.getLogger(this.getClass().getSimpleName());
protected String name;
protected boolean cacheForbidden;
protected String dbtype;
@@ -66,6 +66,9 @@ public abstract class DataSqlSource extends AbstractDataSource implements Functi
protected final BiFunction<DataSource, EntityInfo, CompletableFuture<List>> fullloader = (s, i)
-> ((CompletableFuture<Sheet>) querySheetDB(i, false, false, false, null, null, (FilterNode) null)).thenApply(e -> e == null ? new ArrayList() : e.list(true));
//超过多少毫秒视为慢, 会打印警告级别的日志, 默认值: 3000
protected long slowms;
//用于反向LIKE使用
protected String containSQL;
@@ -117,7 +120,9 @@ public abstract class DataSqlSource extends AbstractDataSource implements Functi
this.tableNotExistSqlstates = ";" + readConfProps.getProperty(DATA_SOURCE_TABLENOTEXIST_SQLSTATES, "42000;42S02") + ";";
this.tablecopySQL = readConfProps.getProperty(DATA_SOURCE_TABLECOPY_SQLTEMPLATE, "CREATE TABLE IF NOT EXISTS ${newtable} LIKE ${oldtable}");
this.cacheForbidden = "NONE".equalsIgnoreCase(readConfProps.getProperty(DATA_SOURCE_CACHEMODE));
this.slowms = Integer.parseInt(readConfProps.getProperty(DATA_SOURCE_SLOWMS, "3000").trim());
}
@Override