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 2b4b617c49c3aec9d421013d58ff3956c98be062 Author: Andrus Adamchik <[email protected]> AuthorDate: Fri Jul 3 18:07:55 2026 -0400 CAY-2912 Compact SQL logger proper batch param truncation --- .../org/apache/cayenne/access/LoggingObserver.java | 15 +++--- .../org/apache/cayenne/log/SqlBindingRenderer.java | 25 +++++++-- .../org/apache/cayenne/log/Slf4jSqlLoggerTest.java | 62 ++++++++++++++++++++-- 3 files changed, 89 insertions(+), 13 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 d908d2140..efc26acca 100644 --- a/cayenne/src/main/java/org/apache/cayenne/access/LoggingObserver.java +++ b/cayenne/src/main/java/org/apache/cayenne/access/LoggingObserver.java @@ -37,8 +37,6 @@ import java.util.Map; * An {@link OperationObserver} decorator that correlates each executed statement (reported via * {@link #nextStatement}) with its results (reported via the {@code next*} callbacks) and drives a {@link SqlLogger} * to emit compact, single-line log messages. All callbacks are delegated to the wrapped observer unchanged. - * - * @since 5.0 */ class LoggingObserver implements OperationObserver { @@ -49,7 +47,9 @@ class LoggingObserver implements OperationObserver { private boolean headerEmitted; private boolean batchHasUpdate; private int batchUpdateSum; - private final List<Map<String, ?>> generatedKeys = new ArrayList<>(); + + // lazily allocated on the first nextGeneratedRows call, since most statements produce no generated keys + private List<Map<String, ?>> generatedKeys; LoggingObserver(OperationObserver delegate, SqlLogger logger) { this.delegate = delegate; @@ -58,7 +58,7 @@ class LoggingObserver implements OperationObserver { private void flushPending() { if (!headerEmitted && batchHasUpdate && current != null) { - logger.logUpdate(current, batchUpdateSum, generatedKeys); + logger.logUpdate(current, batchUpdateSum, generatedKeys != null ? generatedKeys : List.of()); headerEmitted = true; } } @@ -76,7 +76,7 @@ class LoggingObserver implements OperationObserver { if (headerEmitted) { logger.logAlsoUpdate(rowCount); } else { - logger.logUpdate(current, rowCount, generatedKeys); + logger.logUpdate(current, rowCount, generatedKeys != null ? generatedKeys : List.of()); headerEmitted = true; } } @@ -106,7 +106,7 @@ class LoggingObserver implements OperationObserver { this.headerEmitted = false; this.batchHasUpdate = false; this.batchUpdateSum = 0; - this.generatedKeys.clear(); + this.generatedKeys = null; delegate.nextStatement(query, statement); } @@ -158,6 +158,9 @@ class LoggingObserver implements OperationObserver { public void nextGeneratedRows(Query query, List<DataRow> keys, List<ObjectId> idsToUpdate) { // 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 + if (generatedKeys == null) { + generatedKeys = new ArrayList<>(); + } generatedKeys.addAll(keys); delegate.nextGeneratedRows(query, keys, idsToUpdate); } diff --git a/cayenne/src/main/java/org/apache/cayenne/log/SqlBindingRenderer.java b/cayenne/src/main/java/org/apache/cayenne/log/SqlBindingRenderer.java index c763a19fb..4a87fb027 100644 --- a/cayenne/src/main/java/org/apache/cayenne/log/SqlBindingRenderer.java +++ b/cayenne/src/main/java/org/apache/cayenne/log/SqlBindingRenderer.java @@ -109,13 +109,30 @@ class SqlBindingRenderer { return; } + // sanity-check the threshold: <= 0 disables truncation (including a misconfigured negative), while 1 or 2 + // clamp to 2 - the smallest value that yields a head/tail split (one row on each side) + if (batchRowThreshold <= 0) { + batchRowThreshold = Integer.MAX_VALUE; + } else if (batchRowThreshold < 2) { + batchRowThreshold = 2; + } + // rows are delimited by their own [...] brackets, so no extra list bracket is needed: a single-row batch // reads as [bind:[...]] and a multi-row batch as [bind:[...][...]] - never a doubled [[...]] buffer.append("[bind:"); - if (rows > batchRowThreshold && rows > 2) { - appendBatchRow(buffer, bindings, 0); - buffer.append("..").append(rows - 2).append(".."); - appendBatchRow(buffer, bindings, rows - 1); + if (rows > batchRowThreshold) { + // show up to batchRowThreshold rows split evenly between head and tail, eliding the middle. For an odd + // threshold the head gets the extra row, so head + tail == batchRowThreshold and the elided count is + // exactly rows - batchRowThreshold + int head = (batchRowThreshold + 1) / 2; + int tail = batchRowThreshold / 2; + for (int r = 0; r < head; r++) { + appendBatchRow(buffer, bindings, r); + } + buffer.append("..").append(rows - head - tail).append(".."); + for (int r = rows - tail; r < rows; r++) { + appendBatchRow(buffer, bindings, r); + } } else { for (int r = 0; r < rows; r++) { appendBatchRow(buffer, bindings, r); diff --git a/cayenne/src/test/java/org/apache/cayenne/log/Slf4jSqlLoggerTest.java b/cayenne/src/test/java/org/apache/cayenne/log/Slf4jSqlLoggerTest.java index 40bf6cec5..ae43b3e2d 100644 --- a/cayenne/src/test/java/org/apache/cayenne/log/Slf4jSqlLoggerTest.java +++ b/cayenne/src/test/java/org/apache/cayenne/log/Slf4jSqlLoggerTest.java @@ -49,10 +49,26 @@ public class Slf4jSqlLoggerTest { logger = new Slf4jSqlLogger(props); } + private static Slf4jSqlLogger loggerWithThreshold(int threshold) { + RuntimeProperties props = mock(RuntimeProperties.class); + when(props.getInt(eq(Constants.JDBC_LOG_BATCH_ROW_THRESHOLD_PROPERTY), anyInt())).thenReturn(threshold); + return new Slf4jSqlLogger(props); + } + private static PSParameter<?> ps(String name, Object value) { return new PSParameter<>(value, 1, Types.INTEGER, 0, null, new DbAttribute(name)); } + // a single-placeholder batch whose id values are 0..rows-1, so each logged row is identifiable by its value + private static TranslatedBatch idBatch(int rows) { + Object[] values = new Object[rows]; + for (int i = 0; i < rows; i++) { + values[i] = i; + } + PSBatchParameter id = new PSBatchParameter(values, 1, Types.INTEGER, 0, new DbAttribute("id")); + return new TranslatedBatch("INSERT INTO t(id) VALUES(?)", new PSBatchParameter[]{id}); + } + @Test public void selectLineWithSingleBinding() { TranslatedSelect select = new TranslatedSelect( @@ -74,8 +90,8 @@ public class Slf4jSqlLoggerTest { } @Test - public void batchLineTruncatesToFirstAndLastRow() { - // 5 rows, 2 placeholders (id, name); with threshold 3 the middle 3 rows are elided + public void batchLineSplitsHeadAndTailAroundElision() { + // 5 rows, 2 placeholders (id, name); odd threshold 3 -> head 2, tail 1, middle 2 rows elided PSBatchParameter id = new PSBatchParameter( new Object[]{3, 1, 5, 4, 2}, 1, Types.INTEGER, 0, new DbAttribute("id")); PSBatchParameter name = new PSBatchParameter( @@ -84,7 +100,8 @@ public class Slf4jSqlLoggerTest { TranslatedBatch batch = new TranslatedBatch( "INSERT INTO table1(id, name) VALUES(?, ?)", new PSBatchParameter[]{id, name}); - assertEquals("INSERT INTO table1(id, name) VALUES(?, ?) [bind:[id:3,name:'n3']..3..[id:2,name:'n2']] [updated:5]", + assertEquals("INSERT INTO table1(id, name) VALUES(?, ?) " + + "[bind:[id:3,name:'n3'][id:1,name:'n1']..2..[id:2,name:'n2']] [updated:5]", logger.buildStatementLine(batch, "updated:", 5)); } @@ -113,4 +130,43 @@ public class Slf4jSqlLoggerTest { assertEquals("INSERT INTO table1(id) VALUES(?) [bind:[id:3][id:2]] [updated:2]", logger.buildStatementLine(batch, "updated:", 2)); } + + @Test + public void batchLineEvenThresholdSplitsEvenly() { + // even threshold 4 -> head 2, tail 2; 10 rows -> middle 6 elided + assertEquals("INSERT INTO t(id) VALUES(?) [bind:[id:0][id:1]..6..[id:8][id:9]] [updated:10]", + loggerWithThreshold(4).buildStatementLine(idBatch(10), "updated:", 10)); + } + + @Test + public void batchLineShowsAllRowsAtThreshold() { + // exactly threshold rows -> nothing elided + assertEquals("INSERT INTO t(id) VALUES(?) [bind:[id:0][id:1][id:2][id:3]] [updated:4]", + loggerWithThreshold(4).buildStatementLine(idBatch(4), "updated:", 4)); + } + + @Test + public void batchLineElidesExactlyOneAboveThreshold() { + // one row above threshold 4 -> head 2, tail 2, a single row elided + assertEquals("INSERT INTO t(id) VALUES(?) [bind:[id:0][id:1]..1..[id:3][id:4]] [updated:5]", + loggerWithThreshold(4).buildStatementLine(idBatch(5), "updated:", 5)); + } + + @Test + public void batchLineThresholdOfOneOrTwoClampsToTwo() { + // threshold 1 and 2 both clamp to 2 -> head 1, tail 1 + assertEquals("INSERT INTO t(id) VALUES(?) [bind:[id:0]..3..[id:4]] [updated:5]", + loggerWithThreshold(1).buildStatementLine(idBatch(5), "updated:", 5)); + assertEquals("INSERT INTO t(id) VALUES(?) [bind:[id:0]..3..[id:4]] [updated:5]", + loggerWithThreshold(2).buildStatementLine(idBatch(5), "updated:", 5)); + } + + @Test + public void batchLineNonPositiveThresholdDisablesTruncation() { + // threshold 0 or negative -> no truncation, every row logged + assertEquals("INSERT INTO t(id) VALUES(?) [bind:[id:0][id:1][id:2][id:3][id:4]] [updated:5]", + loggerWithThreshold(0).buildStatementLine(idBatch(5), "updated:", 5)); + assertEquals("INSERT INTO t(id) VALUES(?) [bind:[id:0][id:1][id:2][id:3][id:4]] [updated:5]", + loggerWithThreshold(-1).buildStatementLine(idBatch(5), "updated:", 5)); + } }
