From bc4d9837c6b3fa73194abc06011117e31f075660 Mon Sep 17 00:00:00 2001 From: Rob Bygrave Date: Thu, 1 Dec 2022 23:45:27 +1300 Subject: [PATCH 1/3] Modify SpiLogger removing isTrace(), trace() and the 2 uses - Not bothered to log when changing isolation level - Not bothering to log at end of query only transaction --- .../main/java/io/ebeaninternal/api/SpiLogger.java | 9 --------- .../io/ebeaninternal/server/logger/DSpiLogger.java | 9 --------- .../server/transaction/TransactionFactory.java | 3 --- .../server/transaction/TransactionManager.java | 3 --- .../src/main/java/io/ebean/test/CaptureLogger.java | 13 ------------- .../java/io/ebean/test/CapturingLoggerFactory.java | 9 --------- .../EbeanServerFactory_ServerConfigStart_Test.java | 9 --------- 7 files changed, 55 deletions(-) diff --git a/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogger.java b/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogger.java index 8e6d5e71c..a2fafd796 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogger.java +++ b/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogger.java @@ -14,18 +14,9 @@ public interface SpiLogger { */ boolean isDebug(); - /** - * Is trace logging enabled. - */ - boolean isTrace(); - /** * Log a debug level message. */ void debug(String msg); - /** - * Log a trace level message. - */ - void trace(String msg); } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/logger/DSpiLogger.java b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DSpiLogger.java index 922667037..341898ac1 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/logger/DSpiLogger.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DSpiLogger.java @@ -18,18 +18,9 @@ final class DSpiLogger implements SpiLogger { return logger.isLoggable(DEBUG); } - @Override - public boolean isTrace() { - return logger.isLoggable(TRACE); - } - @Override public void debug(String msg) { logger.log(DEBUG, msg); } - @Override - public void trace(String msg) { - logger.log(TRACE, msg); - } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionFactory.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionFactory.java index cf8f4591b..dcd6e73ea 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionFactory.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionFactory.java @@ -43,9 +43,6 @@ abstract class TransactionFactory { throw new PersistenceException(e); } } - if (explicit && manager.log().txn().isTrace()) { - manager.log().txn().trace(t.getLogPrefix() + "Begin"); - } return t; } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionManager.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionManager.java index 0a306640d..c7f0dde62 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionManager.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionManager.java @@ -347,9 +347,6 @@ public class TransactionManager implements SpiTransactionManager { @Override public final void notifyOfQueryOnly(SpiTransaction transaction) { // Nothing that interesting here - if (txnLogger.isTrace()) { - txnLogger.trace(transaction.getLogPrefix() + "Commit - query only"); - } } private String formatThrowable(Throwable e) { diff --git a/ebean-test/src/main/java/io/ebean/test/CaptureLogger.java b/ebean-test/src/main/java/io/ebean/test/CaptureLogger.java index f76368f6c..6c6468570 100644 --- a/ebean-test/src/main/java/io/ebean/test/CaptureLogger.java +++ b/ebean-test/src/main/java/io/ebean/test/CaptureLogger.java @@ -23,11 +23,6 @@ final class CaptureLogger implements SpiLogger { return true; } - @Override - public boolean isTrace() { - return true; - } - @Override public void debug(String msg) { if (active) { @@ -36,14 +31,6 @@ final class CaptureLogger implements SpiLogger { wrapped.debug(msg); } - @Override - public void trace(String msg) { - if (active) { - messages.add(msg); - } - wrapped.trace(msg); - } - List start() { this.active = true; return collect(); diff --git a/ebean-test/src/main/java/io/ebean/test/CapturingLoggerFactory.java b/ebean-test/src/main/java/io/ebean/test/CapturingLoggerFactory.java index c7887dd75..1e56f87d0 100644 --- a/ebean-test/src/main/java/io/ebean/test/CapturingLoggerFactory.java +++ b/ebean-test/src/main/java/io/ebean/test/CapturingLoggerFactory.java @@ -37,19 +37,10 @@ public class CapturingLoggerFactory implements SpiLoggerFactory { return logger.isLoggable(DEBUG); } - @Override - public boolean isTrace() { - return logger.isLoggable(TRACE); - } - @Override public void debug(String msg) { logger.log(DEBUG, msg); } - @Override - public void trace(String msg) { - logger.log(TRACE, msg); - } } } diff --git a/ebean-test/src/test/java/io/ebean/xtest/base/EbeanServerFactory_ServerConfigStart_Test.java b/ebean-test/src/test/java/io/ebean/xtest/base/EbeanServerFactory_ServerConfigStart_Test.java index 113596331..f597705e7 100644 --- a/ebean-test/src/test/java/io/ebean/xtest/base/EbeanServerFactory_ServerConfigStart_Test.java +++ b/ebean-test/src/test/java/io/ebean/xtest/base/EbeanServerFactory_ServerConfigStart_Test.java @@ -34,18 +34,9 @@ public class EbeanServerFactory_ServerConfigStart_Test { return false; } - @Override - public boolean isTrace() { - return false; - } - @Override public void debug(String msg) { } - - @Override - public void trace(String msg) { - } }; } From 9720cd81892c723bab2b84447b1bb44a66171f0b Mon Sep 17 00:00:00 2001 From: Rob Bygrave Date: Fri, 2 Dec 2022 02:34:14 +1300 Subject: [PATCH 2/3] Add SpiTxnLogger as main point to log SQL, SUM and TXN messages on a per transaction basis --- .../io/ebeaninternal/api/SpiLogManager.java | 29 +++--- .../io/ebeaninternal/api/SpiTransaction.java | 10 +- .../api/SpiTransactionProxy.java | 13 +-- .../io/ebeaninternal/api/SpiTxnLogger.java | 49 ++++++++++ .../server/core/AbstractSqlQueryRequest.java | 2 +- .../server/core/OrmQueryRequest.java | 2 +- .../server/core/PersistRequestBean.java | 8 +- .../core/PersistRequestCallableSql.java | 8 +- .../server/core/PersistRequestOrmUpdate.java | 2 +- .../server/core/PersistRequestUpdateSql.java | 4 +- .../server/core/RelationalQueryRequest.java | 2 +- .../server/logger/DLogManager.java | 21 +++- .../server/logger/DTxnLogger.java | 96 +++++++++++++++++++ .../server/persist/BatchControl.java | 2 +- .../ebeaninternal/server/persist/Binder.java | 2 +- .../server/persist/DefaultPersister.java | 10 +- .../persist/DeleteUnloadedForeignKeys.java | 2 +- .../server/persist/dml/DmlHandler.java | 8 +- .../server/query/CQueryEngine.java | 8 +- .../transaction/DocStoreOnlyTransaction.java | 4 +- .../DocStoreTransactionManager.java | 4 +- .../transaction/ExternalJdbcTransaction.java | 6 +- .../ImplicitReadOnlyTransaction.java | 24 ++--- .../server/transaction/JdbcTransaction.java | 48 +++++----- .../server/transaction/JtaTransaction.java | 4 +- .../transaction/JtaTransactionManager.java | 3 +- .../server/transaction/NoTransaction.java | 13 +-- .../transaction/SavepointTransaction.java | 15 +-- .../transaction/TransactionManager.java | 84 ++-------------- .../io/ebeaninternal/server/util/Str.java | 20 ++++ .../transaction/TransactionManagerTest.java | 2 +- 31 files changed, 307 insertions(+), 198 deletions(-) create mode 100644 ebean-core/src/main/java/io/ebeaninternal/api/SpiTxnLogger.java create mode 100644 ebean-core/src/main/java/io/ebeaninternal/server/logger/DTxnLogger.java diff --git a/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogManager.java b/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogManager.java index ed8f0a3ff..ed6512a5d 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogManager.java +++ b/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogManager.java @@ -10,18 +10,25 @@ package io.ebeaninternal.api; public interface SpiLogManager { /** - * Return the SQL logger. + * Enable bind logging. + */ + boolean enableBindLog(); + + /** + * Logger used for general transactions. + */ + SpiTxnLogger logger(); + + /** + * Logger used for read only transactions. + */ + SpiTxnLogger readOnlyLogger(); + + /** + * Hmmmm, return the SQL logger for logging truncate statements. + *

+ * Maybe we should get rid of this */ SpiLogger sql(); - /** - * Return the TXN logger. - */ - SpiLogger txn(); - - /** - * Return the Summary logger. - */ - SpiLogger sum(); - } diff --git a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransaction.java index 6708d1a45..d21dbd88d 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransaction.java @@ -27,10 +27,6 @@ public interface SpiTransaction extends Transaction { */ String getLabel(); - /** - * Return the string prefix with the transaction id and label used in logging. - */ - String getLogPrefix(); /** * Return true if generated SQL and Bind values should be logged to the @@ -47,12 +43,14 @@ public interface SpiTransaction extends Transaction { /** * Log a message to the SQL logger. */ - void logSql(String msg); + void logSql(String... msg); /** * Log a message to the SUMMARY logger. */ - void logSummary(String msg); + void logSummary(String... msg); + + void logTxn(String... args); /** * Register a "Deferred Relationship" that requires an additional update later. diff --git a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransactionProxy.java b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransactionProxy.java index a46bf033f..12a242722 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransactionProxy.java +++ b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransactionProxy.java @@ -137,10 +137,6 @@ public abstract class SpiTransactionProxy implements SpiTransaction { transaction.setDocStoreBatchSize(batchSize); } - @Override - public String getLogPrefix() { - return transaction.getLogPrefix(); - } @Override public boolean isLogSql() { @@ -153,15 +149,20 @@ public abstract class SpiTransactionProxy implements SpiTransaction { } @Override - public void logSql(String msg) { + public void logSql(String... msg) { transaction.logSql(msg); } @Override - public void logSummary(String msg) { + public void logSummary(String... msg) { transaction.logSummary(msg); } + @Override + public void logTxn(String... args) { + transaction.logTxn(args); + } + @Override public void setSkipCache(boolean skipCache) { transaction.setSkipCache(skipCache); diff --git a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTxnLogger.java b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTxnLogger.java new file mode 100644 index 000000000..e1eb240c2 --- /dev/null +++ b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTxnLogger.java @@ -0,0 +1,49 @@ +package io.ebeaninternal.api; + +/** + * Per Transaction logging of SQL, TXN and Summary messages. + */ +public interface SpiTxnLogger { + + String id(); + + /** + * Is debug logging enabled. + */ + boolean isLogSql(); + + /** + * Is summary logging enabled. + */ + boolean isLogSummary(); + + /** + * Log a SQL message. + */ + void sql(String[] msg); + + /** + * Log a Summary message. + */ + void sum(String[] msg); + + /** + * Log a Transaction message. + */ + void txn(String[] args); + + /** + * Transaction Committed. + */ + void notifyCommit(); + + /** + * Query only transaction completed. + */ + void notifyQueryOnly(); + + /** + * Transaction Rolled back. + */ + void notifyRollback(Throwable cause); +} diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/AbstractSqlQueryRequest.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/AbstractSqlQueryRequest.java index 2424dd2b3..7dc041401 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/AbstractSqlQueryRequest.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/AbstractSqlQueryRequest.java @@ -151,7 +151,7 @@ public abstract class AbstractSqlQueryRequest implements CancelableQuery { } if (isLogSql()) { long micros = (System.nanoTime() - startNano) / 1000L; - transaction.logSql(Str.add(TrimLogSql.trim(sql), "; --bind(", bindLog, ") --micros(", micros + ")")); + transaction.logSql(TrimLogSql.trim(sql), "; --bind(", bindLog, ") --micros(", String.valueOf(micros), ")"); } } finally { lock.unlock(); diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java index 29dd4ac1d..4a60a1755 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java @@ -691,7 +691,7 @@ public final class OrmQueryRequest extends BeanRequest implements SpiOrmQuery /** * Log the SQL if the logLevel is appropriate. */ - public void logSql(String sql) { + public void logSql(String... sql) { transaction.logSql(sql); } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestBean.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestBean.java index 4016596f0..239bfa1a8 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestBean.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestBean.java @@ -932,16 +932,16 @@ public final class PersistRequestBean extends PersistRequest implements BeanP String name = beanDescriptor.name(); switch (type) { case INSERT: - transaction.logSummary("Inserted [" + name + "] [" + (idValue == null ? "" : idValue) + draft); + transaction.logSummary("Inserted [" , name , "] [" , (idValue == null ? "" : idValue.toString()) , draft); break; case UPDATE: - transaction.logSummary("Updated [" + name + "] [" + idValue + draft); + transaction.logSummary("Updated [" , name , "] [" , idValue.toString() , draft); break; case DELETE: - transaction.logSummary("Deleted [" + name + "] [" + idValue + draft); + transaction.logSummary("Deleted [" , name , "] [" , idValue.toString() , draft); break; case DELETE_SOFT: - transaction.logSummary("SoftDelete [" + name + "] [" + idValue + draft); + transaction.logSummary("SoftDelete [" , name , "] [" , idValue.toString() , draft); break; default: break; diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestCallableSql.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestCallableSql.java index 70eebd927..0bc8133df 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestCallableSql.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestCallableSql.java @@ -1,12 +1,8 @@ package io.ebeaninternal.server.core; import io.ebean.CallableSql; -import io.ebeaninternal.api.BindParams; +import io.ebeaninternal.api.*; import io.ebeaninternal.api.BindParams.Param; -import io.ebeaninternal.api.SpiCallableSql; -import io.ebeaninternal.api.SpiEbeanServer; -import io.ebeaninternal.api.SpiTransaction; -import io.ebeaninternal.api.TransactionEventTable; import io.ebeaninternal.server.persist.PersistExecute; import java.sql.CallableStatement; @@ -86,7 +82,7 @@ public final class PersistRequestCallableSql extends PersistRequest { persistExecute.collectSqlCall(label, startNanos); } if (transaction.isLogSummary()) { - transaction.logSummary("CallableSql label[" + callableSql.getLabel() + "]" + " rows[" + rowCount + "]" + " bind[" + bindLog + "]"); + transaction.logSummary("CallableSql label[", callableSql.getLabel(), "] rows[", String.valueOf(rowCount), "] bind[", bindLog, "]"); } // register table modifications with the transaction event diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestOrmUpdate.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestOrmUpdate.java index eb865a0bd..9ddf0459d 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestOrmUpdate.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestOrmUpdate.java @@ -83,7 +83,7 @@ public final class PersistRequestOrmUpdate extends PersistRequest { OrmUpdateType ormUpdateType = ormUpdate.getOrmUpdateType(); String tableName = ormUpdate.getBaseTable(); if (transaction.isLogSummary()) { - transaction.logSummary(ormUpdateType + " table[" + tableName + "] rows[" + rowCount + "] bind[" + bindLog + "]"); + transaction.logSummary(ormUpdateType.toString(), " table[", tableName, "] rows[", String.valueOf(rowCount), "] bind[", bindLog, "]"); } if (ormUpdate.isNotifyCache()) { // add the modification info to the TransactionEvent diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestUpdateSql.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestUpdateSql.java index e2f898e3c..6138e90af 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestUpdateSql.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestUpdateSql.java @@ -148,7 +148,7 @@ public final class PersistRequestUpdateSql extends PersistRequest { */ public void logSqlBatchBind() { if (transaction.isLogSql()) { - transaction.logSql(Str.add(" -- bind(", bindLog, ")")); + transaction.logSql(" -- bind(", bindLog, ")"); } } @@ -161,7 +161,7 @@ public final class PersistRequestUpdateSql extends PersistRequest { persistExecute.collectSqlUpdate(label, startNanos); } if (transaction.isLogSql() && !batchThisRequest) { - transaction.logSql(Str.add(TrimLogSql.trim(updateSql.getGeneratedSql()), "; -- bind(", bindLog, ") rows(", String.valueOf(rowCount), ")")); + transaction.logSql(TrimLogSql.trim(updateSql.getGeneratedSql()), "; -- bind(", bindLog, ") rows(", String.valueOf(rowCount), ")"); } if (updateSql.isAutoTableMod()) { // add the modification info to the TransactionEvent diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/RelationalQueryRequest.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/RelationalQueryRequest.java index 1b25a56a6..b27b3ab2e 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/RelationalQueryRequest.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/RelationalQueryRequest.java @@ -123,7 +123,7 @@ public final class RelationalQueryRequest extends AbstractSqlQueryRequest { public void logSummary() { if (transaction.isLogSummary()) { long micros = (System.nanoTime() - startNano) / 1000L; - transaction.logSummary("SqlQuery rows[" + rows + "] micros[" + micros + "] bind[" + bindLog + "]"); + transaction.logSummary("SqlQuery rows[", String.valueOf(rows), "] micros[", String.valueOf(micros), "] bind[", bindLog, "]"); } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/logger/DLogManager.java b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DLogManager.java index 31c42f2fd..ed45dd08a 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/logger/DLogManager.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DLogManager.java @@ -2,22 +2,30 @@ package io.ebeaninternal.server.logger; import io.ebeaninternal.api.SpiLogManager; import io.ebeaninternal.api.SpiLogger; +import io.ebeaninternal.api.SpiTxnLogger; + +import java.util.concurrent.atomic.AtomicLong; public final class DLogManager implements SpiLogManager { private final SpiLogger sql; private final SpiLogger summary; private final SpiLogger txn; + private final boolean useIds; + private final AtomicLong counter = new AtomicLong(1000); + private final DTxnLogger readOnly; public DLogManager(SpiLogger sql, SpiLogger summary, SpiLogger txn) { this.sql = sql; this.summary = summary; this.txn = txn; + this.useIds = txn.isDebug(); + this.readOnly = new DTxnLogger(null, sql, summary, txn); } @Override - public SpiLogger txn() { - return txn; + public boolean enableBindLog() { + return sql.isDebug(); } @Override @@ -26,8 +34,13 @@ public final class DLogManager implements SpiLogManager { } @Override - public SpiLogger sum() { - return summary; + public SpiTxnLogger logger() { + String id = useIds ? Long.toString(counter.incrementAndGet()) : ""; + return new DTxnLogger(id, sql, summary, txn); } + @Override + public SpiTxnLogger readOnlyLogger() { + return readOnly; + } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/logger/DTxnLogger.java b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DTxnLogger.java new file mode 100644 index 000000000..f71b4d7ce --- /dev/null +++ b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DTxnLogger.java @@ -0,0 +1,96 @@ +package io.ebeaninternal.server.logger; + +import io.ebeaninternal.api.SpiLogger; +import io.ebeaninternal.api.SpiTxnLogger; +import io.ebeaninternal.server.util.Str; + +final class DTxnLogger implements SpiTxnLogger { + + private final String id; + private final String logPrefix; + private final SpiLogger sql; + private final SpiLogger sum; + private final SpiLogger txn; + + DTxnLogger(String id, SpiLogger sql, SpiLogger sum, SpiLogger txn) { + this.id = id; + this.logPrefix = id == null ? "" : "txn[" + id + "] "; + this.sql = sql; + this.sum = sum; + this.txn = txn; + } + + @Override + public String id() { + return id; + } + + @Override + public boolean isLogSql() { + return sql.isDebug(); + } + + @Override + public boolean isLogSummary() { + return sum.isDebug(); + } + + @Override + public void sql(String[] msg) { + sql.debug(Str.add(logPrefix, msg)); + } + + @Override + public void sum(String[] msg) { + sum.debug(Str.add(logPrefix, msg)); + } + + @Override + public void txn(String[] msg) { + txn.debug(Str.add(logPrefix, msg)); + } + + @Override + public void notifyCommit() { + txn.debug(Str.add(logPrefix, "Commit")); + } + + @Override + public void notifyQueryOnly() { + // do nothing + } + + @Override + public void notifyRollback(Throwable cause) { + if (txn.isDebug()) { + String msg = logPrefix + "Rollback"; + if (cause != null) { + msg += " error: " + formatThrowable(cause); + } + txn.debug(msg); + } + } + + private String formatThrowable(Throwable e) { + if (e == null) { + return ""; + } + StringBuilder sb = new StringBuilder(); + formatThrowable(e, sb); + return sb.toString(); + } + + private void formatThrowable(Throwable e, StringBuilder sb) { + sb.append(e.toString()); + StackTraceElement[] stackTrace = e.getStackTrace(); + if (stackTrace.length > 0) { + sb.append(" stack0: "); + sb.append(stackTrace[0]); + } + Throwable cause = e.getCause(); + if (cause != null) { + sb.append(" cause: "); + formatThrowable(cause, sb); + } + } +} diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/persist/BatchControl.java b/ebean-core/src/main/java/io/ebeaninternal/server/persist/BatchControl.java index b17dfb1be..2f721b369 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/persist/BatchControl.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/persist/BatchControl.java @@ -313,7 +313,7 @@ public final class BatchControl { BatchedBeanHolder[] bsArray = beanHolderArray(); Arrays.sort(bsArray, depthComparator); if (transaction.isLogSummary()) { - transaction.logSummary("BatchControl flush " + Arrays.toString(bsArray)); + transaction.logSummary("BatchControl flush " , Arrays.toString(bsArray)); } for (BatchedBeanHolder beanHolder : bsArray) { beanHolder.executeNow(); diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/persist/Binder.java b/ebean-core/src/main/java/io/ebeaninternal/server/persist/Binder.java index 008163c30..c63f32674 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/persist/Binder.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/persist/Binder.java @@ -44,7 +44,7 @@ public final class Binder { this.dbExpressionHandler = dbExpressionHandler; this.dataTimeZone = dataTimeZone; this.multiValueBind = multiValueBind; - this.enableBindLog = logManager.sql().isDebug(); + this.enableBindLog = logManager.enableBindLog(); } /** diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/persist/DefaultPersister.java b/ebean-core/src/main/java/io/ebeaninternal/server/persist/DefaultPersister.java index f78e11ea8..ad9494b4a 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/persist/DefaultPersister.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/persist/DefaultPersister.java @@ -672,7 +672,7 @@ public final class DefaultPersister implements Persister { if (idList != null) { q.where().idIn(idList); if (t.isLogSummary()) { - t.logSummary("-- DeleteById of " + descriptor.name() + " ids[" + idList + "] requires fetch of foreign key values"); + t.logSummary("-- DeleteById of ", descriptor.name(), " ids[", idList.toString(), "] requires fetch of foreign key values"); } List beanList = server.findList(q, t); deleteCascade(beanList, t, deleteMode, false); @@ -681,7 +681,7 @@ public final class DefaultPersister implements Persister { } else { q.where().idEq(id); if (t.isLogSummary()) { - t.logSummary("-- DeleteById of " + descriptor.name() + " id[" + id + "] requires fetch of foreign key values"); + t.logSummary("-- DeleteById of ", descriptor.name(), " id[", String.valueOf(id), "] requires fetch of foreign key values"); } EntityBean bean = (EntityBean) server.findOne(q, t); if (bean == null) { @@ -741,7 +741,7 @@ public final class DefaultPersister implements Persister { for (BeanPropertyAssocMany many : manys) { SqlUpdate sqlDelete = many.deleteByParentId(id, idList); if (t.isLogSummary()) { - t.logSummary("-- Deleting intersection table entries: " + many.fullName()); + t.logSummary("-- Deleting intersection table entries: ", many.fullName()); } executeSqlUpdate(sqlDelete, t); } @@ -751,9 +751,9 @@ public final class DefaultPersister implements Persister { SqlUpdate deleteById = descriptor.deleteById(id, idList, deleteMode); if (t.isLogSummary()) { if (idList != null) { - t.logSummary("-- Deleting " + descriptor.name() + " Ids: " + idList); + t.logSummary("-- Deleting ", descriptor.name(), " Ids: ", idList.toString()); } else { - t.logSummary("-- Deleting " + descriptor.name() + " Id: " + id); + t.logSummary("-- Deleting ", descriptor.name(), " Id: ", String.valueOf(id)); } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/persist/DeleteUnloadedForeignKeys.java b/ebean-core/src/main/java/io/ebeaninternal/server/persist/DeleteUnloadedForeignKeys.java index ad16a3fa8..847f7a343 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/persist/DeleteUnloadedForeignKeys.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/persist/DeleteUnloadedForeignKeys.java @@ -69,7 +69,7 @@ final class DeleteUnloadedForeignKeys { SpiTransaction t = request.transaction(); if (t.isLogSummary()) { - t.logSummary("-- Ebean fetching foreign key values for delete of " + descriptor.name() + " id:" + id); + t.logSummary("-- Ebean fetching foreign key values for delete of ", descriptor.name(), " id:", String.valueOf(id)); } beanWithForeignKeys = (EntityBean) server.findOne(q, t); } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/persist/dml/DmlHandler.java b/ebean-core/src/main/java/io/ebeaninternal/server/persist/dml/DmlHandler.java index 58ec931fc..39ceedf4a 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/persist/dml/DmlHandler.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/persist/dml/DmlHandler.java @@ -102,7 +102,7 @@ public abstract class DmlHandler implements PersistHandler, BindableRequest { } catch (OptimisticLockException e) { // add the SQL and bind values to error message final String m = e.getMessage() + " sql[" + sql + "] bind[" + bindLog + "]"; - persistRequest.transaction().logSummary("OptimisticLockException:" + m); + persistRequest.transaction().logSummary("OptimisticLockException:", m); throw new OptimisticLockException(m, null, e.getEntity()); } } @@ -146,15 +146,15 @@ public abstract class DmlHandler implements PersistHandler, BindableRequest { switch (batchedStatus) { case BATCHED_FIRST: { transaction.logSql(sql); - transaction.logSql(Str.add(" -- bind(", bindLog.toString(), ")")); + transaction.logSql(" -- bind(", bindLog.toString(), ")"); return; } case BATCHED: { - transaction.logSql(Str.add(" -- bind(", bindLog.toString(), ")")); + transaction.logSql(" -- bind(", bindLog.toString(), ")"); return; } default: { - transaction.logSql(Str.add(sql, "; -- bind(", bindLog.toString(), ")")); + transaction.logSql(sql, "; -- bind(", bindLog.toString(), ")"); } } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/query/CQueryEngine.java b/ebean-core/src/main/java/io/ebeaninternal/server/query/CQueryEngine.java index 4a2686f16..7cc6e9b37 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/query/CQueryEngine.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/query/CQueryEngine.java @@ -73,7 +73,7 @@ public final class CQueryEngine { try { int rows = query.execute(); if (request.logSql()) { - request.logSql(Str.add(query.generatedSql(), "; --bind(", query.bindLog(), ") --micros(", query.micros() + ") --rows(", rows + ")")); + request.logSql(query.generatedSql(), "; --bind(", query.bindLog(), ") --micros(", query.micros() + ") --rows(", rows + ")"); } return rows; } catch (SQLException e) { @@ -129,7 +129,7 @@ public final class CQueryEngine { SpiTransaction t = request.transaction(); if (t.isLogSummary()) { // log the error to the transaction log - t.logSummary("ERROR executing query, bindLog[" + bindLog + "] error:" + StringHelper.removeNewLines(e.getMessage())); + t.logSummary("ERROR executing query, bindLog[", bindLog, "] error:", StringHelper.removeNewLines(e.getMessage())); } // ensure 'rollback' is logged if queryOnly transaction t.connection(); @@ -147,7 +147,7 @@ public final class CQueryEngine { } private void logGeneratedSql(OrmQueryRequest request, String sql, String bindLog, long micros) { - request.logSql(Str.add(sql, "; --bind(", bindLog, ") --micros(", micros + ")")); + request.logSql(sql, "; --bind(", bindLog, ") --micros(", micros + ")"); } /** @@ -403,7 +403,7 @@ public final class CQueryEngine { * Log the generated SQL to the transaction log. */ private void logSql(CQuery query) { - query.transaction().logSql(Str.add(query.generatedSql(), "; --bind(", query.bindLog(), ") --micros(", query.micros() + ")")); + query.transaction().logSql(query.generatedSql(), "; --bind(", query.bindLog(), ") --micros(", String.valueOf(query.micros()), ")"); } /** diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/DocStoreOnlyTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/DocStoreOnlyTransaction.java index 9ff36d545..55e4eb0f5 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/DocStoreOnlyTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/DocStoreOnlyTransaction.java @@ -10,8 +10,8 @@ public final class DocStoreOnlyTransaction extends JdbcTransaction { /** * Create a new DocStore only Transaction. */ - public DocStoreOnlyTransaction(String id, boolean explicit, TransactionManager manager) { - super(id, explicit, null, manager); + public DocStoreOnlyTransaction(boolean explicit, TransactionManager manager) { + super(explicit, null, manager); } @Override diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/DocStoreTransactionManager.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/DocStoreTransactionManager.java index d23476c25..a6f58c228 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/DocStoreTransactionManager.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/DocStoreTransactionManager.java @@ -25,11 +25,11 @@ public final class DocStoreTransactionManager extends TransactionManager { @Override public SpiTransaction createReadOnlyTransaction(Object tenantId) { - return new DocStoreOnlyTransaction("", false, this); + return new DocStoreOnlyTransaction(false, this); } @Override protected SpiTransaction createTransaction(boolean explicit, Connection c) { - return new DocStoreOnlyTransaction(nextTxnId(), explicit, this); + return new DocStoreOnlyTransaction(explicit, this); } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ExternalJdbcTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ExternalJdbcTransaction.java index 867472be6..c40a83a12 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ExternalJdbcTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ExternalJdbcTransaction.java @@ -25,14 +25,14 @@ public class ExternalJdbcTransaction extends JdbcTransaction { *

*/ public ExternalJdbcTransaction(Connection connection) { - super(null, true, connection, null); + super(true, connection, null); } /** * Construct will all explicit parameters. */ - public ExternalJdbcTransaction(String id, boolean explicit, Connection connection, TransactionManager manager) { - super(id, explicit, connection, manager); + public ExternalJdbcTransaction(boolean explicit, Connection connection, TransactionManager manager) { + super(explicit, connection, manager); } /** diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ImplicitReadOnlyTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ImplicitReadOnlyTransaction.java index 7ffa36f8d..ef959742d 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ImplicitReadOnlyTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ImplicitReadOnlyTransaction.java @@ -33,6 +33,7 @@ final class ImplicitReadOnlyTransaction implements SpiTransaction, TxnProfileEve private static final String notExpectedMessage = "Not expected on read only transaction"; private final TransactionManager manager; + private final SpiTxnLogger logger; private final boolean logSql; private final boolean logSummary; @@ -61,8 +62,9 @@ final class ImplicitReadOnlyTransaction implements SpiTransaction, TxnProfileEve */ ImplicitReadOnlyTransaction(TransactionManager manager, Connection connection) { this.manager = manager; - this.logSql = manager.isLogSql(); - this.logSummary = manager.isLogSummary(); + this.logger = manager.loggerReadOnly(); + this.logSql = logger.isLogSql(); + this.logSummary = logger.isLogSummary(); this.active = true; this.connection = connection; this.persistenceContext = new DefaultPersistenceContext(); @@ -147,11 +149,6 @@ final class ImplicitReadOnlyTransaction implements SpiTransaction, TxnProfileEve public void setSkipCache(boolean skipCache) { } - @Override - public String getLogPrefix() { - return null; - } - @Override public void addBeanChange(BeanChange beanChange) { throw new IllegalStateException(notExpectedMessage); @@ -433,13 +430,18 @@ final class ImplicitReadOnlyTransaction implements SpiTransaction, TxnProfileEve } @Override - public void logSql(String msg) { - manager.log().sql().debug(msg); + public void logSql(String... msg) { + logger.sql(msg); } @Override - public void logSummary(String msg) { - manager.log().sum().debug(msg); + public void logSummary(String... msg) { + logger.sum(msg); + } + + @Override + public void logTxn(String... args) { + // never called } /** diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JdbcTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JdbcTransaction.java index 4b8408c27..4ebfd8082 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JdbcTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JdbcTransaction.java @@ -11,7 +11,6 @@ import io.ebeaninternal.server.core.PersistDeferredRelationship; import io.ebeaninternal.server.core.PersistRequestBean; import io.ebeaninternal.server.persist.BatchControl; import io.ebeaninternal.server.persist.BatchedSqlException; -import io.ebeaninternal.server.util.Str; import io.ebeanservice.docstore.api.DocStoreTransaction; import javax.persistence.PersistenceException; @@ -33,8 +32,8 @@ class JdbcTransaction implements SpiTransaction, TxnProfileEventCodes { private static final String illegalStateMessage = "Transaction is Inactive"; final TransactionManager manager; + private final SpiTxnLogger logger; private final String id; - private final String logPrefix; private final boolean logSql; private final boolean logSummary; private final boolean explicit; @@ -95,17 +94,17 @@ class JdbcTransaction implements SpiTransaction, TxnProfileEventCodes { private final long startNanos; private boolean autoPersistUpdates; - JdbcTransaction(String id, boolean explicit, Connection connection, TransactionManager manager) { + JdbcTransaction(boolean explicit, Connection connection, TransactionManager manager) { try { this.active = true; - this.id = id; - this.logPrefix = deriveLogPrefix(id); this.explicit = explicit; this.manager = manager; this.connection = connection; this.persistenceContext = new DefaultPersistenceContext(); this.startNanos = System.nanoTime(); if (manager == null) { + this.logger = null; + this.id = ""; this.logSql = false; this.logSummary = false; this.skipCacheAfterWrite = true; @@ -113,9 +112,11 @@ class JdbcTransaction implements SpiTransaction, TxnProfileEventCodes { this.batchOnCascadeMode = false; this.onQueryOnlyCommit = false; } else { + this.logger = manager.logger(); + this.id = logger.id(); this.autoPersistUpdates = explicit && manager.isAutoPersistUpdates(); - this.logSql = manager.isLogSql(); - this.logSummary = manager.isLogSummary(); + this.logSql = logger.isLogSql(); + this.logSummary = logger.isLogSummary(); this.skipCacheAfterWrite = manager.isSkipCacheAfterWrite(); this.batchMode = manager.isPersistBatch(); this.batchOnCascadeMode = manager.isPersistBatchOnCascade(); @@ -188,16 +189,7 @@ class JdbcTransaction implements SpiTransaction, TxnProfileEventCodes { } } - private static String deriveLogPrefix(String id) { - StringBuilder sb = new StringBuilder(); - sb.append("txn["); - if (id != null) { - sb.append(id); - } - sb.append("] "); - return sb.toString(); - } @Override public final void setAutoPersistUpdates(boolean autoPersistUpdates) { @@ -226,17 +218,13 @@ class JdbcTransaction implements SpiTransaction, TxnProfileEventCodes { this.skipCache = skipCache; } - @Override - public final String getLogPrefix() { - return logPrefix; - } @Override public String toString() { if (active) { - return logPrefix; + return id; } else { - return logPrefix + "(inactive)"; + return id + "(inactive)"; } } @@ -726,13 +714,18 @@ class JdbcTransaction implements SpiTransaction, TxnProfileEventCodes { } @Override - public final void logSql(String msg) { - manager.log().sql().debug(Str.add(logPrefix, msg)); + public final void logSql(String... msg) { + logger.sql(msg); } @Override - public final void logSummary(String msg) { - manager.log().sum().debug(Str.add(logPrefix, msg)); + public final void logSummary(String... msg) { + logger.sum(msg); + } + + @Override + public void logTxn(String... args) { + logger.txn(args); } /** @@ -805,9 +798,11 @@ class JdbcTransaction implements SpiTransaction, TxnProfileEventCodes { final void notifyCommit() { if (manager != null) { if (queryOnly) { + logger.notifyQueryOnly(); manager.notifyOfQueryOnly(this); } else { manager.notifyOfCommit(this); + logger.notifyCommit(); } } } @@ -966,6 +961,7 @@ class JdbcTransaction implements SpiTransaction, TxnProfileEventCodes { manager.notifyOfQueryOnly(this); } else { manager.notifyOfRollback(this, cause); + logger.notifyRollback(cause); } } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JtaTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JtaTransaction.java index cfd76c581..66f1a1c78 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JtaTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JtaTransaction.java @@ -20,8 +20,8 @@ public final class JtaTransaction extends JdbcTransaction { /** * Create the JtaTransaction. */ - public JtaTransaction(String id, boolean explicit, UserTransaction utx, DataSource ds, TransactionManager manager) { - super(id, explicit, null, manager); + public JtaTransaction(boolean explicit, UserTransaction utx, DataSource ds, TransactionManager manager) { + super(explicit, null, manager); userTransaction = utx; try { newTransaction = userTransaction.getStatus() == Status.STATUS_NO_TRANSACTION; diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JtaTransactionManager.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JtaTransactionManager.java index 73bc98981..c4027ff04 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JtaTransactionManager.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JtaTransactionManager.java @@ -105,8 +105,7 @@ public final class JtaTransactionManager implements ExternalTransactionManager { // This is a transaction that Ebean has not seen before. // "wrap" it in a Ebean specific JtaTransaction - String txnId = String.valueOf(System.currentTimeMillis()); - JtaTransaction newTrans = new JtaTransaction(txnId, true, ut, dataSource(), transactionManager); + JtaTransaction newTrans = new JtaTransaction( true, ut, dataSource(), transactionManager); // create and register transaction listener JtaTxnListener txnListener = createJtaTxnListener(newTrans); diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/NoTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/NoTransaction.java index ff094b643..e5a0104a9 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/NoTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/NoTransaction.java @@ -117,10 +117,6 @@ final class NoTransaction implements SpiTransaction { // do nothing } - @Override - public String getLogPrefix() { - return null; - } @Override public boolean isLogSql() { @@ -133,12 +129,17 @@ final class NoTransaction implements SpiTransaction { } @Override - public void logSql(String msg) { + public void logSql(String... msg) { } @Override - public void logSummary(String msg) { + public void logSummary(String... msg) { + + } + + @Override + public void logTxn(String... args) { } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/SavepointTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/SavepointTransaction.java index e35a8c30f..df4502983 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/SavepointTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/SavepointTransaction.java @@ -21,7 +21,6 @@ final class SavepointTransaction extends SpiTransactionProxy { private final TransactionManager manager; private final Savepoint savepoint; private final Connection connection; - private final String logPrefix; private final String spPrefix; private boolean rollbackOnly; @@ -33,13 +32,12 @@ final class SavepointTransaction extends SpiTransactionProxy { this.transaction = transaction; this.connection = transaction.getInternalConnection(); this.savepoint = connection.setSavepoint(); - if (manager.isTxnDebug()) { + if (transaction.isLogSql()) { int savepointId = manager.isSupportsSavepointId() ? savepoint.getSavepointId() : 0; this.spPrefix = "sp[" + savepointId + "] "; } else { this.spPrefix = "sp[] "; } - this.logPrefix = transaction.getLogPrefix() + spPrefix; } @Override @@ -51,17 +49,12 @@ final class SavepointTransaction extends SpiTransactionProxy { } @Override - public String getLogPrefix() { - return logPrefix; - } - - @Override - public void logSql(String msg) { + public void logSql(String... msg) { transaction.logSql(Str.add(spPrefix, msg)); } @Override - public void logSummary(String msg) { + public void logSummary(String... msg) { transaction.logSummary(Str.add(spPrefix, msg)); } @@ -99,6 +92,7 @@ final class SavepointTransaction extends SpiTransactionProxy { connection.releaseSavepoint(savepoint); state = STATE_COMMITTED; manager.notifyOfCommit(this); + transaction.logTxn(spPrefix, "commit"); } catch (SQLException e) { throw new PersistenceException("Error trying to commit/release Savepoint", e); } @@ -109,6 +103,7 @@ final class SavepointTransaction extends SpiTransactionProxy { connection.rollback(savepoint); state = STATE_ROLLED_BACK; manager.notifyOfRollback(this, cause); + transaction.logTxn(spPrefix, "rollback");//TODO: Pass the cause } catch (SQLException e) { throw new PersistenceException("Error trying to rollback Savepoint", e); } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionManager.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionManager.java index c7f0dde62..442a25ff8 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionManager.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/TransactionManager.java @@ -36,7 +36,6 @@ import java.sql.SQLException; import java.util.List; import java.util.Set; import java.util.concurrent.ConcurrentHashMap; -import java.util.concurrent.atomic.AtomicLong; import static java.lang.System.Logger.Level.DEBUG; import static java.lang.System.Logger.Level.ERROR; @@ -63,8 +62,6 @@ public class TransactionManager implements SpiTransactionManager { * Prefix for transaction id's (logging). */ final String prefix; - private final String externalTransPrefix; - private final AtomicLong counter = new AtomicLong(1000L); /** * The dataSource of connections. @@ -96,8 +93,6 @@ public class TransactionManager implements SpiTransactionManager { private final boolean skipCacheAfterWrite; private final TransactionFactory transactionFactory; private final SpiLogManager logManager; - private final SpiLogger txnLogger; - private final boolean txnDebug; private final DatabasePlatform databasePlatform; private final SpiProfileHandler profileHandler; private final TimedMetric txnMain; @@ -115,8 +110,6 @@ public class TransactionManager implements SpiTransactionManager { public TransactionManager(TransactionManagerOptions options) { this.server = options.server; this.logManager = options.logManager; - this.txnLogger = logManager.txn(); - this.txnDebug = txnLogger.isDebug(); this.databasePlatform = options.config.getDatabasePlatform(); this.supportsSavepointId = databasePlatform.supportsSavepointId(); this.skipCacheAfterWrite = options.config.isSkipCacheAfterWrite(); @@ -142,7 +135,6 @@ public class TransactionManager implements SpiTransactionManager { this.profileHandler = options.profileHandler; this.bulkEventListenerMap = new BulkEventListenerMap(options.config.getBulkTableEventListeners()); this.prefix = ""; - this.externalTransPrefix = "e"; CurrentTenantProvider tenantProvider = options.config.getCurrentTenantProvider(); this.transactionFactory = TransactionFactoryBuilder.build(this, dataSourceSupplier, tenantProvider); @@ -273,14 +265,7 @@ public class TransactionManager implements SpiTransactionManager { * Wrap the externally supplied Connection. */ public SpiTransaction wrapExternalConnection(Connection c) { - return wrapExternalConnection(externalTransPrefix + c.hashCode(), c); - } - - /** - * Wrap an externally supplied Connection with a known transaction id. - */ - private SpiTransaction wrapExternalConnection(String id, Connection c) { - ExternalJdbcTransaction t = new ExternalJdbcTransaction(id, true, c, this); + ExternalJdbcTransaction t = new ExternalJdbcTransaction(true, c, this); // set the default batch mode t.setBatchMode(persistBatch); t.setBatchOnCascade(persistBatchOnCascade); @@ -313,14 +298,7 @@ public class TransactionManager implements SpiTransactionManager { * Create a new transaction. */ SpiTransaction createTransaction(boolean explicit, Connection c) { - return new JdbcTransaction(nextTxnId(), explicit, c, this); - } - - /** - * Return the next transaction id. - */ - String nextTxnId() { - return txnDebug ? prefix + counter.incrementAndGet() : prefix; + return new JdbcTransaction(explicit, c, this); } /** @@ -328,17 +306,7 @@ public class TransactionManager implements SpiTransactionManager { */ @Override public final void notifyOfRollback(SpiTransaction transaction, Throwable cause) { - try { - if (txnLogger.isDebug()) { - String msg = transaction.getLogPrefix() + "Rollback"; - if (cause != null) { - msg += " error: " + formatThrowable(cause); - } - txnLogger.debug(msg); - } - } catch (Exception ex) { - log.log(ERROR, "Error while notifying TransactionEventListener of rollback event", ex); - } + // Do nothing now } /** @@ -349,38 +317,12 @@ public class TransactionManager implements SpiTransactionManager { // Nothing that interesting here } - private String formatThrowable(Throwable e) { - if (e == null) { - return ""; - } - StringBuilder sb = new StringBuilder(); - formatThrowable(e, sb); - return sb.toString(); - } - - private void formatThrowable(Throwable e, StringBuilder sb) { - sb.append(e.toString()); - StackTraceElement[] stackTrace = e.getStackTrace(); - if (stackTrace.length > 0) { - sb.append(" stack0: "); - sb.append(stackTrace[0]); - } - Throwable cause = e.getCause(); - if (cause != null) { - sb.append(" cause: "); - formatThrowable(cause, sb); - } - } - /** * Process a local committed transaction. */ @Override public final void notifyOfCommit(SpiTransaction transaction) { try { - if (txnLogger.isDebug()) { - txnLogger.debug(transaction.getLogPrefix() + "Commit"); - } PostCommitProcessing postCommit = new PostCommitProcessing(clusterManager, this, transaction); postCommit.notifyLocalCache(); backgroundExecutor.execute(postCommit.backgroundNotify()); @@ -673,25 +615,18 @@ public class TransactionManager implements SpiTransactionManager { } } - /** - * Return true if Transaction debug is on. - */ - public final boolean isTxnDebug() { - return txnDebug; + public SpiTxnLogger logger() { + return logManager.logger(); + } + + public SpiTxnLogger loggerReadOnly() { + return logManager.readOnlyLogger(); } public final SpiLogManager log() { return logManager; } - public final boolean isLogSql() { - return logManager.sql().isDebug(); - } - - public final boolean isLogSummary() { - return logManager.sum().isDebug(); - } - /** * Experimental - find dirty beans in the persistence context and persist them. */ @@ -701,4 +636,5 @@ public class TransactionManager implements SpiTransactionManager { server.updateAll(dirtyBeans, transaction); } } + } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/util/Str.java b/ebean-core/src/main/java/io/ebeaninternal/server/util/Str.java index c49032c86..31d21bc5e 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/util/Str.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/util/Str.java @@ -43,4 +43,24 @@ public final class Str { return sb.append(s0).append(s1).toString(); } + public static String add(String s0, String[] s1) { + if (s1 == null || s1.length == 0) { + return s0; + } + int len = s0.length(); + for (String s : s1) { + if (s != null) { + len += s.length(); + } + } + StringBuilder sb = new StringBuilder(len); + sb.append(s0); + for (String s : s1) { + if (s != null) { + sb.append(s); + } + } + return sb.toString(); + } + } diff --git a/ebean-test/src/test/java/io/ebean/xtest/internal/server/transaction/TransactionManagerTest.java b/ebean-test/src/test/java/io/ebean/xtest/internal/server/transaction/TransactionManagerTest.java index 0229250b7..5b97c8b0c 100644 --- a/ebean-test/src/test/java/io/ebean/xtest/internal/server/transaction/TransactionManagerTest.java +++ b/ebean-test/src/test/java/io/ebean/xtest/internal/server/transaction/TransactionManagerTest.java @@ -34,7 +34,7 @@ public class TransactionManagerTest extends BaseTestCase { DataSource dataSource = transactionManager.dataSource(); Connection connection = dataSource.getConnection(); try { - SpiTransaction externalTxn = new ExternalJdbcTransaction("external0", true, connection, null); + SpiTransaction externalTxn = new ExternalJdbcTransaction(true, connection, null); // push an externally managed transaction onto scope ScopedTransaction scopedTransaction = transactionManager.externalBeginTransaction(externalTxn, TxScope.required()); From 2c8ae16179dfe2d690777abd8af02e9a8338bb0d Mon Sep 17 00:00:00 2001 From: rob Date: Tue, 14 Feb 2023 14:54:23 +1300 Subject: [PATCH 3/3] Update to use String format and Object varargs --- .../main/java/io/ebeaninternal/api/SpiLogger.java | 2 +- .../java/io/ebeaninternal/api/SpiTransaction.java | 11 +++++++---- .../io/ebeaninternal/api/SpiTransactionProxy.java | 12 ++++++------ .../main/java/io/ebeaninternal/api/SpiTxnLogger.java | 6 +++--- .../server/core/AbstractSqlQueryRequest.java | 3 +-- .../ebeaninternal/server/core/OrmQueryRequest.java | 4 ++-- .../server/core/PersistRequestBean.java | 10 +++++----- .../server/core/PersistRequestCallableSql.java | 2 +- .../server/core/PersistRequestOrmUpdate.java | 2 +- .../server/core/PersistRequestUpdateSql.java | 5 ++--- .../server/core/RelationalQueryRequest.java | 2 +- .../io/ebeaninternal/server/logger/DSpiLogger.java | 6 ++---- .../io/ebeaninternal/server/logger/DTxnLogger.java | 12 ++++++------ .../ebeaninternal/server/persist/BatchControl.java | 2 +- .../server/persist/DefaultPersister.java | 10 +++++----- .../server/persist/DeleteUnloadedForeignKeys.java | 2 +- .../ebeaninternal/server/persist/dml/DmlHandler.java | 9 ++++----- .../io/ebeaninternal/server/query/CQueryEngine.java | 9 ++++----- .../transaction/ImplicitReadOnlyTransaction.java | 10 +++++----- .../server/transaction/JdbcTransaction.java | 12 ++++++------ .../server/transaction/NoTransaction.java | 6 +++--- .../server/transaction/SavepointTransaction.java | 12 ++++++------ .../src/main/java/io/ebean/test/CaptureLogger.java | 7 ++++--- .../java/io/ebean/test/CapturingLoggerFactory.java | 6 ++---- .../EbeanServerFactory_ServerConfigStart_Test.java | 2 +- 25 files changed, 80 insertions(+), 84 deletions(-) diff --git a/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogger.java b/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogger.java index a2fafd796..b3507cd19 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogger.java +++ b/ebean-core/src/main/java/io/ebeaninternal/api/SpiLogger.java @@ -17,6 +17,6 @@ public interface SpiLogger { /** * Log a debug level message. */ - void debug(String msg); + void debug(String msg, Object... args); } diff --git a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransaction.java index d21dbd88d..a8acdb45a 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransaction.java @@ -43,14 +43,17 @@ public interface SpiTransaction extends Transaction { /** * Log a message to the SQL logger. */ - void logSql(String... msg); + void logSql(String msg, Object... args); /** - * Log a message to the SUMMARY logger. + * Log a summary message to the SUMMARY logger. */ - void logSummary(String... msg); + void logSummary(String msg, Object... args); - void logTxn(String... args); + /** + * Log a transaction message to the transaction logger. + */ + void logTxn(String msg, Object... args); /** * Register a "Deferred Relationship" that requires an additional update later. diff --git a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransactionProxy.java b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransactionProxy.java index 12a242722..87c2f606a 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransactionProxy.java +++ b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTransactionProxy.java @@ -149,18 +149,18 @@ public abstract class SpiTransactionProxy implements SpiTransaction { } @Override - public void logSql(String... msg) { - transaction.logSql(msg); + public void logSql(String msg, Object... args) { + transaction.logSql(msg, args); } @Override - public void logSummary(String... msg) { - transaction.logSummary(msg); + public void logSummary(String msg, Object... args) { + transaction.logSummary(msg, args); } @Override - public void logTxn(String... args) { - transaction.logTxn(args); + public void logTxn(String msg, Object... args) { + transaction.logTxn(msg, args); } @Override diff --git a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTxnLogger.java b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTxnLogger.java index e1eb240c2..62fd51169 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/api/SpiTxnLogger.java +++ b/ebean-core/src/main/java/io/ebeaninternal/api/SpiTxnLogger.java @@ -20,17 +20,17 @@ public interface SpiTxnLogger { /** * Log a SQL message. */ - void sql(String[] msg); + void sql(String msg, Object... args); /** * Log a Summary message. */ - void sum(String[] msg); + void sum(String msg, Object... args); /** * Log a Transaction message. */ - void txn(String[] args); + void txn(String msg, Object... args); /** * Transaction Committed. diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/AbstractSqlQueryRequest.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/AbstractSqlQueryRequest.java index 7dc041401..b4a0c5b20 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/AbstractSqlQueryRequest.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/AbstractSqlQueryRequest.java @@ -4,7 +4,6 @@ import io.ebean.CancelableQuery; import io.ebean.Transaction; import io.ebean.util.JdbcClose; import io.ebeaninternal.api.*; -import io.ebeaninternal.server.util.Str; import io.ebeaninternal.server.persist.Binder; import io.ebeaninternal.server.persist.TrimLogSql; import io.ebeaninternal.server.util.BindParamsParser; @@ -151,7 +150,7 @@ public abstract class AbstractSqlQueryRequest implements CancelableQuery { } if (isLogSql()) { long micros = (System.nanoTime() - startNano) / 1000L; - transaction.logSql(TrimLogSql.trim(sql), "; --bind(", bindLog, ") --micros(", String.valueOf(micros), ")"); + transaction.logSql("{0}; --bind({1}) --micros({2})", TrimLogSql.trim(sql), bindLog, micros); } } finally { lock.unlock(); diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java index 4a60a1755..3631968ba 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java @@ -691,8 +691,8 @@ public final class OrmQueryRequest extends BeanRequest implements SpiOrmQuery /** * Log the SQL if the logLevel is appropriate. */ - public void logSql(String... sql) { - transaction.logSql(sql); + public void logSql(String msg, Object... args) { + transaction.logSql(msg, args); } /** diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestBean.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestBean.java index 239bfa1a8..c176c3e90 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestBean.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestBean.java @@ -928,20 +928,20 @@ public final class PersistRequestBean extends PersistRequest implements BeanP } private void logSummaryMessage() { - String draft = (beanDescriptor.isDraftable() && !publish) ? "] draft[true]" : "]"; + String draft = (beanDescriptor.isDraftable() && !publish) ? " draft[true]" : ""; String name = beanDescriptor.name(); switch (type) { case INSERT: - transaction.logSummary("Inserted [" , name , "] [" , (idValue == null ? "" : idValue.toString()) , draft); + transaction.logSummary("Inserted [{0}] [{1}]{2}", name, (idValue == null ? "" : idValue), draft); break; case UPDATE: - transaction.logSummary("Updated [" , name , "] [" , idValue.toString() , draft); + transaction.logSummary("Updated [{0}] [{1}]{2}", name, idValue , draft); break; case DELETE: - transaction.logSummary("Deleted [" , name , "] [" , idValue.toString() , draft); + transaction.logSummary("Deleted [{0}] [{1}]{2}", name, idValue , draft); break; case DELETE_SOFT: - transaction.logSummary("SoftDelete [" , name , "] [" , idValue.toString() , draft); + transaction.logSummary("SoftDelete [{0}] [{1}]{2}", name, idValue , draft); break; default: break; diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestCallableSql.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestCallableSql.java index 0bc8133df..217bb0e5c 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestCallableSql.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestCallableSql.java @@ -82,7 +82,7 @@ public final class PersistRequestCallableSql extends PersistRequest { persistExecute.collectSqlCall(label, startNanos); } if (transaction.isLogSummary()) { - transaction.logSummary("CallableSql label[", callableSql.getLabel(), "] rows[", String.valueOf(rowCount), "] bind[", bindLog, "]"); + transaction.logSummary("CallableSql label[{0}] rows[{1}] bind[{2}]", callableSql.getLabel(), rowCount, bindLog); } // register table modifications with the transaction event diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestOrmUpdate.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestOrmUpdate.java index 9ddf0459d..7707be1db 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestOrmUpdate.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestOrmUpdate.java @@ -83,7 +83,7 @@ public final class PersistRequestOrmUpdate extends PersistRequest { OrmUpdateType ormUpdateType = ormUpdate.getOrmUpdateType(); String tableName = ormUpdate.getBaseTable(); if (transaction.isLogSummary()) { - transaction.logSummary(ormUpdateType.toString(), " table[", tableName, "] rows[", String.valueOf(rowCount), "] bind[", bindLog, "]"); + transaction.logSummary("{0} table[{1}] rows[{2}] bind[{3}]", ormUpdateType, tableName, rowCount, bindLog); } if (ormUpdate.isNotifyCache()) { // add the modification info to the TransactionEvent diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestUpdateSql.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestUpdateSql.java index 6138e90af..f0b5f31fa 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestUpdateSql.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/PersistRequestUpdateSql.java @@ -3,7 +3,6 @@ package io.ebeaninternal.server.core; import io.ebeaninternal.api.SpiEbeanServer; import io.ebeaninternal.api.SpiSqlUpdate; import io.ebeaninternal.api.SpiTransaction; -import io.ebeaninternal.server.util.Str; import io.ebeaninternal.server.persist.BatchControl; import io.ebeaninternal.server.persist.PersistExecute; import io.ebeaninternal.server.persist.TrimLogSql; @@ -148,7 +147,7 @@ public final class PersistRequestUpdateSql extends PersistRequest { */ public void logSqlBatchBind() { if (transaction.isLogSql()) { - transaction.logSql(" -- bind(", bindLog, ")"); + transaction.logSql(" -- bind({0})", bindLog); } } @@ -161,7 +160,7 @@ public final class PersistRequestUpdateSql extends PersistRequest { persistExecute.collectSqlUpdate(label, startNanos); } if (transaction.isLogSql() && !batchThisRequest) { - transaction.logSql(TrimLogSql.trim(updateSql.getGeneratedSql()), "; -- bind(", bindLog, ") rows(", String.valueOf(rowCount), ")"); + transaction.logSql("{0}; -- bind({1}) rows({2})", TrimLogSql.trim(updateSql.getGeneratedSql()), bindLog, rowCount); } if (updateSql.isAutoTableMod()) { // add the modification info to the TransactionEvent diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/core/RelationalQueryRequest.java b/ebean-core/src/main/java/io/ebeaninternal/server/core/RelationalQueryRequest.java index b27b3ab2e..8b5002b45 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/core/RelationalQueryRequest.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/core/RelationalQueryRequest.java @@ -123,7 +123,7 @@ public final class RelationalQueryRequest extends AbstractSqlQueryRequest { public void logSummary() { if (transaction.isLogSummary()) { long micros = (System.nanoTime() - startNano) / 1000L; - transaction.logSummary("SqlQuery rows[", String.valueOf(rows), "] micros[", String.valueOf(micros), "] bind[", bindLog, "]"); + transaction.logSummary("SqlQuery rows[{0}] micros[{1}] bind[{2}]", rows, micros, bindLog); } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/logger/DSpiLogger.java b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DSpiLogger.java index 341898ac1..f9713b407 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/logger/DSpiLogger.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DSpiLogger.java @@ -3,7 +3,6 @@ package io.ebeaninternal.server.logger; import io.ebeaninternal.api.SpiLogger; import static java.lang.System.Logger.Level.DEBUG; -import static java.lang.System.Logger.Level.TRACE; final class DSpiLogger implements SpiLogger { @@ -19,8 +18,7 @@ final class DSpiLogger implements SpiLogger { } @Override - public void debug(String msg) { - logger.log(DEBUG, msg); + public void debug(String msg, Object... args) { + logger.log(DEBUG, msg, args); } - } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/logger/DTxnLogger.java b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DTxnLogger.java index f71b4d7ce..5e498cae8 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/logger/DTxnLogger.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/logger/DTxnLogger.java @@ -36,18 +36,18 @@ final class DTxnLogger implements SpiTxnLogger { } @Override - public void sql(String[] msg) { - sql.debug(Str.add(logPrefix, msg)); + public void sql(String msg, Object... args) { + sql.debug(Str.add(logPrefix, msg), args); } @Override - public void sum(String[] msg) { - sum.debug(Str.add(logPrefix, msg)); + public void sum(String msg, Object... args) { + sum.debug(Str.add(logPrefix, msg), args); } @Override - public void txn(String[] msg) { - txn.debug(Str.add(logPrefix, msg)); + public void txn(String msg, Object... args) { + txn.debug(Str.add(logPrefix, msg), args); } @Override diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/persist/BatchControl.java b/ebean-core/src/main/java/io/ebeaninternal/server/persist/BatchControl.java index 2f721b369..10cd8f519 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/persist/BatchControl.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/persist/BatchControl.java @@ -313,7 +313,7 @@ public final class BatchControl { BatchedBeanHolder[] bsArray = beanHolderArray(); Arrays.sort(bsArray, depthComparator); if (transaction.isLogSummary()) { - transaction.logSummary("BatchControl flush " , Arrays.toString(bsArray)); + transaction.logSummary("BatchControl flush {0}", Arrays.toString(bsArray)); } for (BatchedBeanHolder beanHolder : bsArray) { beanHolder.executeNow(); diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/persist/DefaultPersister.java b/ebean-core/src/main/java/io/ebeaninternal/server/persist/DefaultPersister.java index ad9494b4a..97b6943ba 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/persist/DefaultPersister.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/persist/DefaultPersister.java @@ -672,7 +672,7 @@ public final class DefaultPersister implements Persister { if (idList != null) { q.where().idIn(idList); if (t.isLogSummary()) { - t.logSummary("-- DeleteById of ", descriptor.name(), " ids[", idList.toString(), "] requires fetch of foreign key values"); + t.logSummary("-- DeleteById of {0} ids[{1}] requires fetch of foreign key values", descriptor.name(), idList); } List beanList = server.findList(q, t); deleteCascade(beanList, t, deleteMode, false); @@ -681,7 +681,7 @@ public final class DefaultPersister implements Persister { } else { q.where().idEq(id); if (t.isLogSummary()) { - t.logSummary("-- DeleteById of ", descriptor.name(), " id[", String.valueOf(id), "] requires fetch of foreign key values"); + t.logSummary("-- DeleteById of {0} id[{1}] requires fetch of foreign key values", descriptor.name(), id); } EntityBean bean = (EntityBean) server.findOne(q, t); if (bean == null) { @@ -741,7 +741,7 @@ public final class DefaultPersister implements Persister { for (BeanPropertyAssocMany many : manys) { SqlUpdate sqlDelete = many.deleteByParentId(id, idList); if (t.isLogSummary()) { - t.logSummary("-- Deleting intersection table entries: ", many.fullName()); + t.logSummary("-- Deleting intersection table entries: {0}", many.fullName()); } executeSqlUpdate(sqlDelete, t); } @@ -751,9 +751,9 @@ public final class DefaultPersister implements Persister { SqlUpdate deleteById = descriptor.deleteById(id, idList, deleteMode); if (t.isLogSummary()) { if (idList != null) { - t.logSummary("-- Deleting ", descriptor.name(), " Ids: ", idList.toString()); + t.logSummary("-- Deleting {0} Ids: {1}", descriptor.name(), idList); } else { - t.logSummary("-- Deleting ", descriptor.name(), " Id: ", String.valueOf(id)); + t.logSummary("-- Deleting {0} Id: {1}", descriptor.name(), id); } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/persist/DeleteUnloadedForeignKeys.java b/ebean-core/src/main/java/io/ebeaninternal/server/persist/DeleteUnloadedForeignKeys.java index 847f7a343..ab935a09e 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/persist/DeleteUnloadedForeignKeys.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/persist/DeleteUnloadedForeignKeys.java @@ -69,7 +69,7 @@ final class DeleteUnloadedForeignKeys { SpiTransaction t = request.transaction(); if (t.isLogSummary()) { - t.logSummary("-- Ebean fetching foreign key values for delete of ", descriptor.name(), " id:", String.valueOf(id)); + t.logSummary("-- Ebean fetching foreign key values for delete of {0} id:{1}", descriptor.name(), id); } beanWithForeignKeys = (EntityBean) server.findOne(q, t); } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/persist/dml/DmlHandler.java b/ebean-core/src/main/java/io/ebeaninternal/server/persist/dml/DmlHandler.java index 39ceedf4a..54d318a0a 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/persist/dml/DmlHandler.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/persist/dml/DmlHandler.java @@ -8,7 +8,6 @@ import io.ebeaninternal.server.persist.BatchedPstmt; import io.ebeaninternal.server.persist.BatchedPstmtHolder; import io.ebeaninternal.server.persist.dmlbind.BindableRequest; import io.ebeaninternal.server.bind.DataBind; -import io.ebeaninternal.server.util.Str; import javax.persistence.OptimisticLockException; import java.sql.Connection; @@ -102,7 +101,7 @@ public abstract class DmlHandler implements PersistHandler, BindableRequest { } catch (OptimisticLockException e) { // add the SQL and bind values to error message final String m = e.getMessage() + " sql[" + sql + "] bind[" + bindLog + "]"; - persistRequest.transaction().logSummary("OptimisticLockException:", m); + persistRequest.transaction().logSummary("OptimisticLockException:{0}", m); throw new OptimisticLockException(m, null, e.getEntity()); } } @@ -146,15 +145,15 @@ public abstract class DmlHandler implements PersistHandler, BindableRequest { switch (batchedStatus) { case BATCHED_FIRST: { transaction.logSql(sql); - transaction.logSql(" -- bind(", bindLog.toString(), ")"); + transaction.logSql(" -- bind({0})", bindLog); return; } case BATCHED: { - transaction.logSql(" -- bind(", bindLog.toString(), ")"); + transaction.logSql(" -- bind({0})", bindLog); return; } default: { - transaction.logSql(sql, "; -- bind(", bindLog.toString(), ")"); + transaction.logSql("{0}; -- bind({1})", sql, bindLog); } } } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/query/CQueryEngine.java b/ebean-core/src/main/java/io/ebeaninternal/server/query/CQueryEngine.java index 7cc6e9b37..8a3307b8f 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/query/CQueryEngine.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/query/CQueryEngine.java @@ -18,7 +18,6 @@ import io.ebeaninternal.server.core.OrmQueryRequest; import io.ebeaninternal.server.core.SpiResultSet; import io.ebeaninternal.server.deploy.BeanDescriptor; import io.ebeaninternal.server.persist.Binder; -import io.ebeaninternal.server.util.Str; import javax.persistence.PersistenceException; import java.sql.ResultSet; @@ -73,7 +72,7 @@ public final class CQueryEngine { try { int rows = query.execute(); if (request.logSql()) { - request.logSql(query.generatedSql(), "; --bind(", query.bindLog(), ") --micros(", query.micros() + ") --rows(", rows + ")"); + request.logSql("{0}; --bind({1}) --micros({2}) --rows({3})", query.generatedSql(), query.bindLog(), query.micros(), rows); } return rows; } catch (SQLException e) { @@ -129,7 +128,7 @@ public final class CQueryEngine { SpiTransaction t = request.transaction(); if (t.isLogSummary()) { // log the error to the transaction log - t.logSummary("ERROR executing query, bindLog[", bindLog, "] error:", StringHelper.removeNewLines(e.getMessage())); + t.logSummary("ERROR executing query, bindLog[{0}] error:{1}", bindLog, StringHelper.removeNewLines(e.getMessage())); } // ensure 'rollback' is logged if queryOnly transaction t.connection(); @@ -147,7 +146,7 @@ public final class CQueryEngine { } private void logGeneratedSql(OrmQueryRequest request, String sql, String bindLog, long micros) { - request.logSql(sql, "; --bind(", bindLog, ") --micros(", micros + ")"); + request.logSql("{0}; --bind({1}) --micros({2})", sql, bindLog, micros); } /** @@ -403,7 +402,7 @@ public final class CQueryEngine { * Log the generated SQL to the transaction log. */ private void logSql(CQuery query) { - query.transaction().logSql(query.generatedSql(), "; --bind(", query.bindLog(), ") --micros(", String.valueOf(query.micros()), ")"); + query.transaction().logSql("{0}; --bind({1}) --micros({2})", query.generatedSql(), query.bindLog(), query.micros()); } /** diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ImplicitReadOnlyTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ImplicitReadOnlyTransaction.java index ef959742d..f665662f6 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ImplicitReadOnlyTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/ImplicitReadOnlyTransaction.java @@ -430,17 +430,17 @@ final class ImplicitReadOnlyTransaction implements SpiTransaction, TxnProfileEve } @Override - public void logSql(String... msg) { - logger.sql(msg); + public void logSql(String msg, Object... args) { + logger.sql(msg, args); } @Override - public void logSummary(String... msg) { - logger.sum(msg); + public void logSummary(String msg, Object... args) { + logger.sum(msg, args); } @Override - public void logTxn(String... args) { + public void logTxn(String msg, Object... args) { // never called } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JdbcTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JdbcTransaction.java index 4ebfd8082..a432a54d4 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JdbcTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/JdbcTransaction.java @@ -714,18 +714,18 @@ class JdbcTransaction implements SpiTransaction, TxnProfileEventCodes { } @Override - public final void logSql(String... msg) { - logger.sql(msg); + public void logSql(String msg, Object... args) { + logger.sql(msg, args); } @Override - public final void logSummary(String... msg) { - logger.sum(msg); + public final void logSummary(String msg, Object... args) { + logger.sum(msg, args); } @Override - public void logTxn(String... args) { - logger.txn(args); + public void logTxn(String msg, Object... args) { + logger.txn(msg, args); } /** diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/NoTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/NoTransaction.java index e5a0104a9..b0ee596df 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/NoTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/NoTransaction.java @@ -129,17 +129,17 @@ final class NoTransaction implements SpiTransaction { } @Override - public void logSql(String... msg) { + public void logSql(String msg, Object... args) { } @Override - public void logSummary(String... msg) { + public void logSummary(String msg, Object... args) { } @Override - public void logTxn(String... args) { + public void logTxn(String msg, Object... args) { } diff --git a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/SavepointTransaction.java b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/SavepointTransaction.java index df4502983..b9e3f8b8a 100644 --- a/ebean-core/src/main/java/io/ebeaninternal/server/transaction/SavepointTransaction.java +++ b/ebean-core/src/main/java/io/ebeaninternal/server/transaction/SavepointTransaction.java @@ -49,13 +49,13 @@ final class SavepointTransaction extends SpiTransactionProxy { } @Override - public void logSql(String... msg) { - transaction.logSql(Str.add(spPrefix, msg)); + public void logSql(String msg, Object... args) { + transaction.logSql(Str.add(spPrefix, msg), args); } @Override - public void logSummary(String... msg) { - transaction.logSummary(Str.add(spPrefix, msg)); + public void logSummary(String msg, Object... args) { + transaction.logSummary(Str.add(spPrefix, msg), args); } @Override @@ -92,7 +92,7 @@ final class SavepointTransaction extends SpiTransactionProxy { connection.releaseSavepoint(savepoint); state = STATE_COMMITTED; manager.notifyOfCommit(this); - transaction.logTxn(spPrefix, "commit"); + transaction.logTxn(spPrefix + "commit"); } catch (SQLException e) { throw new PersistenceException("Error trying to commit/release Savepoint", e); } @@ -103,7 +103,7 @@ final class SavepointTransaction extends SpiTransactionProxy { connection.rollback(savepoint); state = STATE_ROLLED_BACK; manager.notifyOfRollback(this, cause); - transaction.logTxn(spPrefix, "rollback");//TODO: Pass the cause + transaction.logTxn(spPrefix + "rollback");//TODO: Pass the cause } catch (SQLException e) { throw new PersistenceException("Error trying to rollback Savepoint", e); } diff --git a/ebean-test/src/main/java/io/ebean/test/CaptureLogger.java b/ebean-test/src/main/java/io/ebean/test/CaptureLogger.java index 6c6468570..b02413f91 100644 --- a/ebean-test/src/main/java/io/ebean/test/CaptureLogger.java +++ b/ebean-test/src/main/java/io/ebean/test/CaptureLogger.java @@ -2,6 +2,7 @@ package io.ebean.test; import io.ebeaninternal.api.SpiLogger; +import java.text.MessageFormat; import java.util.ArrayList; import java.util.List; @@ -24,11 +25,11 @@ final class CaptureLogger implements SpiLogger { } @Override - public void debug(String msg) { + public void debug(String msg, Object... args) { if (active) { - messages.add(msg); + messages.add(MessageFormat.format(msg, args)); } - wrapped.debug(msg); + wrapped.debug(msg, args); } List start() { diff --git a/ebean-test/src/main/java/io/ebean/test/CapturingLoggerFactory.java b/ebean-test/src/main/java/io/ebean/test/CapturingLoggerFactory.java index 1e56f87d0..25cce8abb 100644 --- a/ebean-test/src/main/java/io/ebean/test/CapturingLoggerFactory.java +++ b/ebean-test/src/main/java/io/ebean/test/CapturingLoggerFactory.java @@ -5,7 +5,6 @@ import io.ebeaninternal.api.SpiLogger; import io.ebeaninternal.api.SpiLoggerFactory; import static java.lang.System.Logger.Level.DEBUG; -import static java.lang.System.Logger.Level.TRACE; /** * Create a logger that captures the SQL and register it for later access in tests. @@ -38,9 +37,8 @@ public class CapturingLoggerFactory implements SpiLoggerFactory { } @Override - public void debug(String msg) { - logger.log(DEBUG, msg); + public void debug(String msg, Object... args) { + logger.log(DEBUG, msg, args); } - } } diff --git a/ebean-test/src/test/java/io/ebean/xtest/base/EbeanServerFactory_ServerConfigStart_Test.java b/ebean-test/src/test/java/io/ebean/xtest/base/EbeanServerFactory_ServerConfigStart_Test.java index f597705e7..841a552fa 100644 --- a/ebean-test/src/test/java/io/ebean/xtest/base/EbeanServerFactory_ServerConfigStart_Test.java +++ b/ebean-test/src/test/java/io/ebean/xtest/base/EbeanServerFactory_ServerConfigStart_Test.java @@ -35,7 +35,7 @@ public class EbeanServerFactory_ServerConfigStart_Test { } @Override - public void debug(String msg) { + public void debug(String msg, Object... args) { } };