Feature/compact event logger

cayenne-server/src/main/java/org/apache/cayenne/log/CompactSlf4jJdbcEventLogger.java

@@ -0,0 +1,196 @@
+/*****************************************************************
+ *   Licensed to the Apache Software Foundation (ASF) under one
+ *  or more contributor license agreements.  See the NOTICE file
+ *  distributed with this work for additional information
+ *  regarding copyright ownership.  The ASF licenses this file
+ *  to you under the Apache License, Version 2.0 (the
+ *  "License"); you may not use this file except in compliance
+ *  with the License.  You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ *  Unless required by applicable law or agreed to in writing,
+ *  software distributed under the License is distributed on an
+ *  "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ *  KIND, either express or implied.  See the License for the
+ *  specific language governing permissions and limitations
+ *  under the License.
+ ****************************************************************/
+package org.apache.cayenne.log;
+
+import org.apache.cayenne.access.translator.DbAttributeBinding;
+import org.apache.cayenne.access.translator.ParameterBinding;
+import org.apache.cayenne.configuration.RuntimeProperties;
+import org.apache.cayenne.di.Inject;
+import org.apache.cayenne.map.DbAttribute;
+
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.HashMap;
+import java.util.List;
+import java.util.Map;
+import java.util.regex.Pattern;
+import java.util.stream.Collectors;
+
+/**
+ * @since 4.1
+ */
+public class CompactSlf4jJdbcEventLogger extends Slf4jJdbcEventLogger {
+
+    private static final String UNION = "UNION";
+    private static final String SELECT = "SELECT";
+    private static final String FROM = "FROM";
+    private static final String SPACE = " ";
+
+    public CompactSlf4jJdbcEventLogger(@Inject RuntimeProperties runtimeProperties) {
+        super(runtimeProperties);
+    }
+
+    @Override
+    public void logQuery(String sql, ParameterBinding[] bindings) {
+        if (!isLoggable()) {
+            return;
+        }
+
+        String str;
+        if (sql.toUpperCase().contains(UNION)) {
+            str = processUnionSql(sql);
+        } else {
+            str = trimSqlSelectColumns(sql);
+        }
+
+        super.logQuery(str, bindings);
+    }
+
+    protected String processUnionSql(String sql) {
+
+        String modified = Pattern.compile(UNION.toLowerCase(), Pattern.CASE_INSENSITIVE).matcher(sql).replaceAll(UNION);
+        String[] queries = modified.split(
+                UNION);
+        List<String> formattedQueries = Arrays.stream(queries).map(this::trimSqlSelectColumns).collect(Collectors.toList());
+        StringBuilder buffer = new StringBuilder();
+        boolean used =  false;
+        for (String q: formattedQueries) {
+            if(!used){
+                used = true;
+            } else {
+                buffer.append(SPACE).append(UNION);
+            }
+            buffer.append(q);
+        }
+        return buffer.toString();
+    }
+
+    protected String trimSqlSelectColumns(String sql) {
+        int selectIndex = sql.toUpperCase().indexOf(SELECT);
+        if (selectIndex == -1) {
+            return sql;
+        }
+        selectIndex += SELECT.length();
+        int fromIndex = sql.toUpperCase().indexOf(FROM);
+        String columns = sql.substring(selectIndex, fromIndex);
+        String[] columnsArray = columns.split(",");
+        if (columnsArray.length <= 3) {
+            return sql;
+        }
+
+        columns = "(" + columnsArray.length + " columns)";
+        return new StringBuilder(sql.substring(0, selectIndex))
+                .append(SPACE)
+                .append(columns)
+                .append(SPACE)
+                .append(sql, fromIndex, sql.length())
+                .toString();
+    }
+
+    @Override
+    protected void appendParameters(StringBuilder buffer, String label, ParameterBinding[] bindings) {
+        int bindingLength = bindings.length;
+        if (bindingLength == 0) {
+            return;
+        }
+
+        buildBinding(buffer, label, collectBindings(bindings));
+    }
+
+    @SuppressWarnings("unchecked")
+    private Map<String, List<String>> collectBindings(ParameterBinding[] bindings) {
+        Map<String, List<String>> bindingsMap = new HashMap<>();
+
+        String key = null;
+        String value;
+        for (int i = 0; i < bindings.length; i++) {
+            ParameterBinding b = bindings[i];
+
+            if (b.isExcluded()) {
+                continue;
+            }
+
+            if (b instanceof DbAttributeBinding) {
+                DbAttribute attribute = ((DbAttributeBinding) b).getAttribute();
+                if (attribute != null) {
+                    key = attribute.getName();
+                }
+            }
+
+            if (b.getExtendedType() != null) {
+                value = b.getExtendedType().toString(b.getValue());
+            } else if(b.getValue() == null) {
+                value = "NULL";
+            } else {
+                value = new StringBuilder(b.getValue().getClass().getName())
+                        .append("@")
+                        .append(System.identityHashCode(b.getValue())).toString();
+            }
+
+            List<String> objects = bindingsMap.computeIfAbsent(key, k -> new ArrayList<>());
+            objects.add(value);
+        }
+
+        return bindingsMap;
+    }
+
+    private void buildBinding(StringBuilder buffer, String label, Map<String, List<String>> bindingsMap) {
+        int j = 1;
+        boolean hasIncluded = false;
+        for (String k : bindingsMap.keySet()) {
+            if (!hasIncluded) {
+                hasIncluded = true;
+                buffer.append("[").append(label).append(": ");
+            } else {
+                buffer.append(", ");
+            }
+            buffer.append(j).append("->").append(k).append(": ");
+
+            List<String> bindingsList = bindingsMap.get(k);
+            if (bindingsList.size() == 1 ) {
+                buffer.append(bindingsList.get(0));
+            } else {
+                buffer.append("{");
+                boolean wasAdded = false;
+                for (Object val : bindingsList) {
+                    if (wasAdded) {
+                        buffer.append(", ");
+                    } else {
+                        wasAdded = true;
+                    }
+                    buffer.append(val);
+                }
+                buffer.append("}");
+            }
+            j++;
+        }
+
+        if (hasIncluded) {
+            buffer.append("]");
+        }
+    }
+
+    @Override
+    public void logBeginTransaction(String transactionLabel) {
+    }
+
+    @Override
+    public void logCommitTransaction(String transactionLabel) {
+    }
+}

cayenne-server/src/main/java/org/apache/cayenne/log/Slf4jJdbcEventLogger.java

@@ -91,7 +91,7 @@ public void logQueryParameters(String label, ParameterBinding[] bindings) {
 	}
 
 	@SuppressWarnings("unchecked")
-	private void appendParameters(StringBuilder buffer, String label, ParameterBinding[] bindings) {
+	protected void appendParameters(StringBuilder buffer, String label, ParameterBinding[] bindings) {
 
 		int len = bindings.length;
 		if (len > 0) {

cayenne-server/src/test/java/org/apache/cayenne/log/CompactSlf4jJdbcEventLoggerTest.java

@@ -0,0 +1,93 @@
+/*****************************************************************
+ *   Licensed to the Apache Software Foundation (ASF) under one
+ *  or more contributor license agreements.  See the NOTICE file
+ *  distributed with this work for additional information
+ *  regarding copyright ownership.  The ASF licenses this file
+ *  to you under the Apache License, Version 2.0 (the
+ *  "License"); you may not use this file except in compliance
+ *  with the License.  You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ *  Unless required by applicable law or agreed to in writing,
+ *  software distributed under the License is distributed on an
+ *  "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ *  KIND, either express or implied.  See the License for the
+ *  specific language governing permissions and limitations
+ *  under the License.
+ ****************************************************************/
+package org.apache.cayenne.log;
+
+import org.apache.cayenne.access.translator.DbAttributeBinding;
+import org.apache.cayenne.access.types.BooleanType;
+import org.apache.cayenne.access.types.CharType;
+import org.apache.cayenne.access.types.ExtendedType;
+import org.apache.cayenne.access.types.IntegerType;
+import org.apache.cayenne.configuration.DefaultRuntimeProperties;
+import org.apache.cayenne.map.DbAttribute;
+import org.junit.Test;
+
+import java.util.Collections;
+
+import static org.hamcrest.CoreMatchers.is;
+import static org.junit.Assert.*;
+
+public class CompactSlf4jJdbcEventLoggerTest {
+
+    @Test
+    public void logWithCompact_Union() {
+
+        CompactSlf4jJdbcEventLogger compactSl4jJdbcEventLogger = new CompactSlf4jJdbcEventLogger(new DefaultRuntimeProperties(Collections.emptyMap()));
+        DbAttributeBinding[] bindings = createBindings();
+
+        String processesSelectSql = compactSl4jJdbcEventLogger.trimSqlSelectColumns("SELECT t0.NAME AS ec0_0, t0.F_KEY1 AS ec0_1, t0.F_KEY2 AS ec0_2," +
+                " t0.PKEY AS ec0_3 FROM COMPOUND_FK_TEST t0 INNER JOIN COMPOUND_PK_TEST " +
+                "t1 ON (t0.F_KEY1 = t1.KEY1 AND t0.F_KEY2 = t1.KEY2) WHERE t1.NAME LIKE ?");
+        assertEquals(processesSelectSql, "SELECT (4 columns) FROM COMPOUND_FK_TEST t0 " +
+                "INNER JOIN COMPOUND_PK_TEST t1 ON (t0.F_KEY1 = t1.KEY1 AND t0.F_KEY2 = t1.KEY2) " +
+                        "WHERE t1.NAME LIKE ?");
+
+        StringBuilder buffer = new StringBuilder();
+        compactSl4jJdbcEventLogger.appendParameters(buffer, "bind", bindings);
+        assertThat(buffer.toString(), is("[bind: 1->t0.NAME: {'', 52, 'true'}, 2->t0.F_KEY1: 'true']"));
+        String processedUnionSql = compactSl4jJdbcEventLogger.processUnionSql(
+                "SELECT t0.NAME AS ec0_0, t0.F_KEY1 AS ec0_1, " +
+                        "t0.PKEY AS ec0_3 FROM COMPOUND_FK_TEST t0 INNER JOIN COMPOUND_PK_TEST " +
+                        "t1 ON (t0.F_KEY1 = t1.KEY1 AND t0.F_KEY2 = t1.KEY2) WHERE t1.NAME LIKE ?" +
+                        "UNION ALL " +
+                        "SELECT t0.NAME AS ec0_0, t0.F_KEY1 AS ec0_1," +
+                        " t0.PKEY AS ec0_3 FROM COMPOUND_FK_TEST t0 INNER JOIN COMPOUND_PK_TEST " +
+                        "t1 ON (t0.F_KEY1 = t1.KEY1 AND t0.F_KEY2 = t1.KEY2) WHERE t1.NAME LIKE ?" +
+                        "union all " +
+                        "SELECT t0.NAME AS ec0_0, t0.F_KEY1 AS ec0_1, t0.F_KEY2 AS ec0_2," +
+                        " t0.PKEY AS ec0_3 FROM COMPOUND_FK_TEST t0 INNER JOIN COMPOUND_PK_TEST " +
+                        "t1 ON (t0.F_KEY1 = t1.KEY1 AND t0.F_KEY2 = t1.KEY2) WHERE t1.NAME LIKE ?");
+
+        assertThat(processedUnionSql, is("SELECT t0.NAME AS ec0_0, t0.F_KEY1 AS ec0_1, t0.PKEY AS ec0_3 FROM COMPOUND_FK_TEST t0 " +
+                "INNER JOIN COMPOUND_PK_TEST t1 ON (t0.F_KEY1 = t1.KEY1 AND t0.F_KEY2 = t1.KEY2) " +
+                "WHERE t1.NAME LIKE ? UNION ALL SELECT t0.NAME AS ec0_0, t0.F_KEY1 AS ec0_1, t0.PKEY AS ec0_3 " +
+                "FROM COMPOUND_FK_TEST t0 INNER JOIN COMPOUND_PK_TEST t1 ON (t0.F_KEY1 = t1.KEY1 AND t0.F_KEY2 = t1.KEY2) " +
+                "WHERE t1.NAME LIKE ? UNION all SELECT (4 columns) FROM COMPOUND_FK_TEST t0 INNER JOIN COMPOUND_PK_TEST t1 ON (t0.F_KEY1 = t1.KEY1 AND t0.F_KEY2 = t1.KEY2) " +
+                "WHERE t1.NAME LIKE ?"));
+
+    }
+
+    private DbAttributeBinding [] createBindings() {
+        return new DbAttributeBinding[] { createBinding("t0.NAME", 1, "", new CharType(false, false)),
+                                            createBinding("t0.NAME", 2, 52, new IntegerType()),
+                                            createBinding("t0.NAME", 3, true, new BooleanType()),
+                                            createBinding("t0.F_KEY1", 4, true, new BooleanType())};
+    }
+
+    private DbAttributeBinding createBinding(String name, int position, Object object, ExtendedType type){
+
+        DbAttributeBinding dbAttributeBinding = new DbAttributeBinding(new DbAttribute(name));
+        dbAttributeBinding.setValue(object);
+        dbAttributeBinding.setStatementPosition(position);
+        if (type != null) {
+            dbAttributeBinding.setExtendedType(type);
+        }
+
+        return dbAttributeBinding;
+    }
+}

cayenne-server/src/test/java/org/apache/cayenne/log/Slf4jJdbcEventLoggerTest.java

@@ -18,14 +18,10 @@
  ****************************************************************/
 package org.apache.cayenne.log;
 
-import org.apache.cayenne.configuration.DefaultRuntimeProperties;
 import org.apache.cayenne.util.IDUtil;
 import org.junit.Test;
 
-import java.util.Collections;
-
 import static org.junit.Assert.assertEquals;
-import static org.junit.Assert.assertTrue;
 
 public class Slf4jJdbcEventLoggerTest {
 

cayenne-server/src/test/resources/logback-test.xml

@@ -0,0 +1,42 @@
+<configuration>
+
+    <statusListener class="ch.qos.logback.core.status.NopStatusListener" />
+
+    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
+        <layout class="ch.qos.logback.classic.PatternLayout">
+            <Pattern>
+                %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
+            </Pattern>
+        </layout>
+    </appender>
+
+
+    <appender name="TEST-INFO"
+              class="org.apache.cayenne.log.TestAppender">
+        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
+            <Pattern>
+                %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
+            </Pattern>
+        </encoder>
+
+        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
+            <!-- rollover daily -->
+            <fileNamePattern>archived/error.%d{yyyy-MM-dd}.%i.log
+            </fileNamePattern>
+            <timeBasedFileNamingAndTriggeringPolicy
+                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
+                <maxFileSize>10MB</maxFileSize>
+            </timeBasedFileNamingAndTriggeringPolicy>
+        </rollingPolicy>
+
+    </appender>
+
+    <root level="info">
+        <appender-ref ref="TEST-INFO" />
+    </root>
+
+    <logger name="org.apache.cayenne" level="info">
+        <appender-ref ref="STDOUT"/>
+    </logger>
+
+</configuration>