This is an automated email from the ASF dual-hosted git repository. asf-gitbox-commits pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/cayenne.git
commit 8ae00984fc8b74353dc7da706e2084c23ec725b4 Author: Andrus Adamchik <[email protected]> AuthorDate: Fri Jul 3 18:07:55 2026 -0400 CAY-2912 Compact SQL logger batching generated keys logging --- .../org/apache/cayenne/access/LoggingObserver.java | 14 ++++++---- .../java/org/apache/cayenne/log/NoopSqlLogger.java | 7 ++--- .../org/apache/cayenne/log/Slf4jSqlLogger.java | 24 +++++++++-------- .../java/org/apache/cayenne/log/SqlLogger.java | 15 ++++++----- .../apache/cayenne/access/LoggingObserverTest.java | 31 ++++++++++++---------- 5 files changed, 49 insertions(+), 42 deletions(-) diff --git a/cayenne/src/main/java/org/apache/cayenne/access/LoggingObserver.java b/cayenne/src/main/java/org/apache/cayenne/access/LoggingObserver.java index f27c296ee..d908d2140 100644 --- a/cayenne/src/main/java/org/apache/cayenne/access/LoggingObserver.java +++ b/cayenne/src/main/java/org/apache/cayenne/access/LoggingObserver.java @@ -28,8 +28,10 @@ import org.apache.cayenne.log.SqlLogger; import org.apache.cayenne.query.Query; import java.sql.Statement; +import java.util.ArrayList; import java.util.Iterator; import java.util.List; +import java.util.Map; /** * An {@link OperationObserver} decorator that correlates each executed statement (reported via @@ -47,6 +49,7 @@ class LoggingObserver implements OperationObserver { private boolean headerEmitted; private boolean batchHasUpdate; private int batchUpdateSum; + private final List<Map<String, ?>> generatedKeys = new ArrayList<>(); LoggingObserver(OperationObserver delegate, SqlLogger logger) { this.delegate = delegate; @@ -55,7 +58,7 @@ class LoggingObserver implements OperationObserver { private void flushPending() { if (!headerEmitted && batchHasUpdate && current != null) { - logger.logUpdate(current, batchUpdateSum); + logger.logUpdate(current, batchUpdateSum, generatedKeys); headerEmitted = true; } } @@ -73,7 +76,7 @@ class LoggingObserver implements OperationObserver { if (headerEmitted) { logger.logAlsoUpdate(rowCount); } else { - logger.logUpdate(current, rowCount); + logger.logUpdate(current, rowCount, generatedKeys); headerEmitted = true; } } @@ -103,6 +106,7 @@ class LoggingObserver implements OperationObserver { this.headerEmitted = false; this.batchHasUpdate = false; this.batchUpdateSum = 0; + this.generatedKeys.clear(); delegate.nextStatement(query, statement); } @@ -152,9 +156,9 @@ class LoggingObserver implements OperationObserver { @Override public void nextGeneratedRows(Query query, List<DataRow> keys, List<ObjectId> idsToUpdate) { - for (DataRow key : keys) { - logger.logGeneratedKey(key); - } + // buffer the keys and emit them as a trailing "generated:[...]" block on the statement's own update line, + // rather than as separate lines that would print before the INSERT that produced them + generatedKeys.addAll(keys); delegate.nextGeneratedRows(query, keys, idsToUpdate); } diff --git a/cayenne/src/main/java/org/apache/cayenne/log/NoopSqlLogger.java b/cayenne/src/main/java/org/apache/cayenne/log/NoopSqlLogger.java index 1f83ed813..248842d96 100644 --- a/cayenne/src/main/java/org/apache/cayenne/log/NoopSqlLogger.java +++ b/cayenne/src/main/java/org/apache/cayenne/log/NoopSqlLogger.java @@ -20,6 +20,7 @@ package org.apache.cayenne.log; import org.apache.cayenne.access.translator.TranslatedStatement; +import java.util.List; import java.util.Map; /** @@ -50,7 +51,7 @@ public class NoopSqlLogger implements SqlLogger { } @Override - public void logUpdate(TranslatedStatement statement, int rowCount) { + public void logUpdate(TranslatedStatement statement, int rowCount, List<? extends Map<String, ?>> generatedKeys) { } @Override @@ -61,10 +62,6 @@ public class NoopSqlLogger implements SqlLogger { public void logAlsoUpdate(int rowCount) { } - @Override - public void logGeneratedKey(Map<String, ?> keys) { - } - @Override public void logTransactionStart() { } diff --git a/cayenne/src/main/java/org/apache/cayenne/log/Slf4jSqlLogger.java b/cayenne/src/main/java/org/apache/cayenne/log/Slf4jSqlLogger.java index cafb92bed..c482eabe2 100644 --- a/cayenne/src/main/java/org/apache/cayenne/log/Slf4jSqlLogger.java +++ b/cayenne/src/main/java/org/apache/cayenne/log/Slf4jSqlLogger.java @@ -26,6 +26,7 @@ import org.apache.cayenne.di.Inject; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import java.util.List; import java.util.Map; /** @@ -55,8 +56,18 @@ public class Slf4jSqlLogger implements SqlLogger { } @Override - public void logUpdate(TranslatedStatement statement, int rowCount) { - logStatement(statement, "updated:", rowCount); + public void logUpdate(TranslatedStatement statement, int rowCount, List<? extends Map<String, ?>> generatedKeys) { + if (LOGGER.isInfoEnabled()) { + StringBuilder buffer = new StringBuilder(buildStatementLine(statement, "updated:", rowCount)); + if (generatedKeys != null && !generatedKeys.isEmpty()) { + buffer.append(" [generated:"); + for (Map<String, ?> keys : generatedKeys) { + SqlBindingRenderer.appendGeneratedKeys(buffer, keys); + } + buffer.append(']'); + } + LOGGER.info(buffer.toString()); + } } protected void logStatement(TranslatedStatement statement, String resultLabel, int rowCount) { @@ -88,15 +99,6 @@ public class Slf4jSqlLogger implements SqlLogger { } } - @Override - public void logGeneratedKey(Map<String, ?> keys) { - if (LOGGER.isInfoEnabled()) { - StringBuilder buffer = new StringBuilder("generated PK "); - SqlBindingRenderer.appendGeneratedKeys(buffer, keys); - LOGGER.info(buffer.toString()); - } - } - @Override public void logTransactionStart() { LOGGER.debug("tx started"); diff --git a/cayenne/src/main/java/org/apache/cayenne/log/SqlLogger.java b/cayenne/src/main/java/org/apache/cayenne/log/SqlLogger.java index 3d2d469d7..91120a750 100644 --- a/cayenne/src/main/java/org/apache/cayenne/log/SqlLogger.java +++ b/cayenne/src/main/java/org/apache/cayenne/log/SqlLogger.java @@ -21,6 +21,7 @@ package org.apache.cayenne.log; import org.apache.cayenne.access.translator.TranslatedStatement; +import java.util.List; import java.util.Map; /** @@ -45,9 +46,14 @@ public interface SqlLogger { void logSelect(TranslatedStatement statement, int rowCount); /** - * Logs the main line for a statement that performed an update. + * Logs the main line for a statement that performed an update: SQL + {@code bind:[...]} + {@code updated:N}, + * optionally followed by a {@code generated:[...]} block listing any database-generated keys. + * + * @param statement the translated statement carrying SQL and bindings + * @param rowCount the number of updated rows + * @param generatedKeys the database-generated keys of the inserted rows, or an empty list if none */ - void logUpdate(TranslatedStatement statement, int rowCount); + void logUpdate(TranslatedStatement statement, int rowCount, List<? extends Map<String, ?>> generatedKeys); /** * Logs a select count continuation line for the statement whose header was already logged. @@ -59,11 +65,6 @@ public interface SqlLogger { */ void logAlsoUpdate(int rowCount); - /** - * Logs the database-generated keys of a single inserted row as one compact, comma-separated line. - */ - void logGeneratedKey(Map<String, ?> keys); - /** * Logs a transaction start boundary (emitted at DEBUG level). */ diff --git a/cayenne/src/test/java/org/apache/cayenne/access/LoggingObserverTest.java b/cayenne/src/test/java/org/apache/cayenne/access/LoggingObserverTest.java index 5269686f7..9b7b50491 100644 --- a/cayenne/src/test/java/org/apache/cayenne/access/LoggingObserverTest.java +++ b/cayenne/src/test/java/org/apache/cayenne/access/LoggingObserverTest.java @@ -68,8 +68,12 @@ public class LoggingObserverTest { } @Override - public void logUpdate(TranslatedStatement statement, int rowCount) { - calls.add("updated:" + rowCount); + public void logUpdate(TranslatedStatement statement, int rowCount, List<? extends Map<String, ?>> generatedKeys) { + StringBuilder buffer = new StringBuilder("updated:").append(rowCount); + for (Map<String, ?> keys : generatedKeys) { + keys.forEach((name, value) -> buffer.append(" generated:").append(name).append('=').append(value)); + } + calls.add(buffer.toString()); } @Override @@ -82,13 +86,6 @@ public class LoggingObserverTest { calls.add("also updated:" + rowCount); } - @Override - public void logGeneratedKey(Map<String, ?> keys) { - StringBuilder buffer = new StringBuilder("generated PK"); - keys.forEach((name, value) -> buffer.append(' ').append(name).append('=').append(value)); - calls.add(buffer.toString()); - } - @Override public void logTransactionStart() { } @@ -165,16 +162,22 @@ public class LoggingObserverTest { } @Test - public void generatedRowsLogKeysUsingDataRowLabels() { + public void generatedKeysAppendedToUpdateLine() { CapturingLogger logger = new CapturingLogger(); LoggingObserver observer = observer(logger); - DataRow row = new DataRow(1); - row.put("ARTIST_ID", 42L); + DataRow row1 = new DataRow(1); + row1.put("ARTIST_ID", 1L); + DataRow row2 = new DataRow(1); + row2.put("ARTIST_ID", 2L); - observer.nextGeneratedRows(null, List.of(row), List.of()); + observer.nextStatement(null, batch()); + observer.nextGeneratedRows(null, asList(row1, row2), List.of()); + observer.nextCount(null, 1); + observer.nextCount(null, 1); + observer.onSuccess(); - assertEquals(List.of("generated PK ARTIST_ID=42"), logger.calls); + assertEquals(List.of("updated:2 generated:ARTIST_ID=1 generated:ARTIST_ID=2"), logger.calls); } @Test
