Merge pull request #129 from jamezp/LOGMGR-161

[LOGMGR-161] Make best attempt to only calculate caller information i…

src/main/java/org/jboss/logmanager/ExtFormatter.java

@@ -39,4 +39,19 @@ public final String format(final LogRecord record) {
      * @return the formatted message
      */
     public abstract String format(final ExtLogRecord extLogRecord);
+
+    /**
+     * Determines whether or not this formatter will require caller, source level, information when a log record is
+     * formatted.
+     *
+     * @return {@code true} if the formatter will need caller information, otherwise {@code false}
+     *
+     * @see LogRecord#getSourceClassName()
+     * @see ExtLogRecord#getSourceFileName()
+     * @see ExtLogRecord#getSourceLineNumber()
+     * @see LogRecord#getSourceMethodName()
+     */
+    public boolean isCallerCalculationRequired() {
+        return true;
+    }
 }

src/main/java/org/jboss/logmanager/ExtHandler.java

@@ -376,4 +376,43 @@ public void setLevel(final Level newLevel) throws SecurityException {
         checkAccess(this);
         super.setLevel(newLevel);
     }
+
+    /**
+     * Indicates whether or not the {@linkplain #getFormatter() formatter} associated with this handler or a formatter
+     * from a {@linkplain #getHandlers() child handler} requires the caller to be calculated.
+     * <p>
+     * Calculating the caller on a {@linkplain ExtLogRecord log record} can be an expensive operation. Some handlers
+     * may be required to copy some data from the log record, but may not need the caller information. If the
+     * {@linkplain #getFormatter() formatter} is a {@link ExtFormatter} the
+     * {@link ExtFormatter#isCallerCalculationRequired()} is used to determine if calculation of the caller is
+     * required.
+     * </p>
+     *
+     * @return {@code true} if the caller should be calculated, otherwise {@code false} if it can be skipped
+     *
+     * @see LogRecord#getSourceClassName()
+     * @see ExtLogRecord#getSourceFileName()
+     * @see ExtLogRecord#getSourceLineNumber()
+     * @see LogRecord#getSourceMethodName()
+     */
+    @SuppressWarnings("WeakerAccess")
+    public boolean isCallerCalculationRequired() {
+        Formatter formatter = getFormatter();
+        if (formatterRequiresCallerCalculation(formatter)) {
+            return true;
+        } else {
+            final Handler[] handlers = getHandlers();
+            for (Handler handler : handlers) {
+                formatter = handler.getFormatter();
+                if (formatterRequiresCallerCalculation(formatter)) {
+                    return true;
+                }
+            }
+        }
+        return false;
+    }
+
+    private static boolean formatterRequiresCallerCalculation(final Formatter formatter) {
+        return formatter != null && (!(formatter instanceof ExtFormatter) || ((ExtFormatter) formatter).isCallerCalculationRequired());
+    }
 }

src/main/java/org/jboss/logmanager/formatters/FormatStep.java

@@ -41,4 +41,13 @@ public interface FormatStep {
      * @return an estimate
      */
     int estimateLength();
+
+    /**
+     * Indicates whether or not caller information is required for this format step.
+     *
+     * @return {@code true} if caller information is required, otherwise {@code false}
+     */
+    default boolean isCallerInformationRequired() {
+        return false;
+    }
 }

src/main/java/org/jboss/logmanager/formatters/Formatters.java

@@ -335,6 +335,11 @@ public static FormatStep classNameFormatStep(final boolean leftJustify, final in
             public String getSegmentedSubject(final ExtLogRecord record) {
                 return record.getSourceClassName();
             }
+
+            @Override
+            public boolean isCallerInformationRequired() {
+                return true;
+            }
         };
     }
 
@@ -422,6 +427,11 @@ public static FormatStep fileNameFormatStep(final boolean leftJustify, final int
             public void renderRaw(final StringBuilder builder, final ExtLogRecord record) {
                 builder.append(record.getSourceFileName());
             }
+
+            @Override
+            public boolean isCallerInformationRequired() {
+                return true;
+            }
         };
     }
 
@@ -529,6 +539,11 @@ public void renderRaw(final StringBuilder builder, final ExtLogRecord record) {
                 }
                 builder.append(')');
             }
+
+            @Override
+            public boolean isCallerInformationRequired() {
+                return true;
+            }
         };
     }
 
@@ -560,6 +575,11 @@ public static FormatStep lineNumberFormatStep(final boolean leftJustify, final i
             public void renderRaw(final StringBuilder builder, final ExtLogRecord record) {
                 builder.append(record.getSourceLineNumber());
             }
+
+            @Override
+            public boolean isCallerInformationRequired() {
+                return true;
+            }
         };
     }
 
@@ -730,6 +750,11 @@ public static FormatStep methodNameFormatStep(final boolean leftJustify, final i
             public void renderRaw(final StringBuilder builder, final ExtLogRecord record) {
                 builder.append(record.getSourceMethodName());
             }
+
+            @Override
+            public boolean isCallerInformationRequired() {
+                return true;
+            }
         };
     }
 

src/main/java/org/jboss/logmanager/formatters/MultistepFormatter.java

@@ -29,6 +29,7 @@
 public class MultistepFormatter extends ExtFormatter {
     private volatile FormatStep[] steps;
     private volatile int builderLength;
+    private volatile boolean callerCalculationRequired = false;
 
     private static final FormatStep[] EMPTY_STEPS = new FormatStep[0];
 
@@ -43,11 +44,16 @@ public MultistepFormatter(final FormatStep[] steps) {
     }
 
     private void calculateBuilderLength() {
+        boolean callerCalculatedRequired = false;
         int builderLength = 0;
         for (FormatStep step : steps) {
             builderLength += step.estimateLength();
+            if (step.isCallerInformationRequired()) {
+                callerCalculatedRequired = true;
+            }
         }
         this.builderLength = max(32, builderLength);
+        this.callerCalculationRequired = callerCalculatedRequired;
     }
 
     /**
@@ -84,4 +90,9 @@ public String format(final ExtLogRecord record) {
         }
         return builder.toString();
     }
+
+    @Override
+    public boolean isCallerCalculationRequired() {
+        return callerCalculationRequired;
+    }
 }

src/main/java/org/jboss/logmanager/formatters/StructuredFormatter.java

@@ -271,6 +271,11 @@ public final synchronized String format(final ExtLogRecord record) {
         }
     }
 
+    @Override
+    public boolean isCallerCalculationRequired() {
+        return isPrintDetails();
+    }
+
     /**
      * Returns the character used to indicate the record has is complete. This defaults to {@code \n} and may be
      * {@code null} if no end of record character is desired.

src/main/java/org/jboss/logmanager/handlers/AsyncHandler.java

@@ -136,8 +136,18 @@ protected void doPublish(final ExtLogRecord record) {
             }
         }
         final BlockingQueue<ExtLogRecord> recordQueue = this.recordQueue;
-        // prepare record to move to another thread
-        record.copyAll();
+        // Determine if we need to calculate the caller information before we queue the record
+        if (isCallerCalculationRequired()) {
+            // prepare record to move to another thread
+            record.copyAll();
+        } else {
+            // Disable the caller calculation since it's been determined we won't be using it
+            record.disableCallerCalculation();
+            // Copy the MDC over
+            record.copyMdc();
+            // In case serialization is required by a child handler
+            record.getFormattedMessage();
+        }
         if (overflowAction == OverflowAction.DISCARD) {
             recordQueue.offer(record);
         } else {

src/main/java/org/jboss/logmanager/handlers/QueueHandler.java

@@ -71,9 +71,20 @@ public void publish(final LogRecord record) {
     }
 
     protected void doPublish(final ExtLogRecord record) {
-        record.copyAll();
         synchronized (buffer) {
             if (isLoggable(record)) {
+                // Determine if we need to calculate the caller information before we queue the record
+                if (isCallerCalculationRequired()) {
+                    // prepare record to move to another thread
+                    record.copyAll();
+                } else {
+                    // Disable the caller calculation since it's been determined we won't be using it
+                    record.disableCallerCalculation();
+                    // Copy the MDC over
+                    record.copyMdc();
+                    // In case serialization is required by a child handler
+                    record.getFormattedMessage();
+                }
                 if (buffer.size() == limit) { buffer.removeFirst(); }
                 buffer.addLast(record);
             }

src/test/java/org/jboss/logmanager/handlers/ExtHandlerTests.java

@@ -0,0 +1,153 @@
+/*
+ * JBoss, Home of Professional Open Source.
+ *
+ * Copyright 2017 Red Hat, Inc., and individual contributors
+ * as indicated by the @author tags.
+ *
+ * Licensed 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.jboss.logmanager.handlers;
+
+import java.util.logging.SimpleFormatter;
+
+import org.jboss.logmanager.ExtHandler;
+import org.jboss.logmanager.formatters.PatternFormatter;
+import org.junit.Assert;
+import org.junit.Test;
+
+/**
+ * @author <a href="mailto:[email protected]">James R. Perkins</a>
+ */
+public class ExtHandlerTests {
+
+    @Test
+    public void testHandlerClose() throws Exception {
+        final CloseHandler parent = new CloseHandler();
+        final CloseHandler child1 = new CloseHandler();
+        final CloseHandler child2 = new CloseHandler();
+        parent.setHandlers(new CloseHandler[] {child1, child2, new CloseHandler()});
+
+        // Ensure all handlers are not closed
+        Assert.assertFalse(parent.closed);
+        Assert.assertFalse(child1.closed);
+        Assert.assertFalse(child2.closed);
+
+        // Close the parent handler, the children should be closed
+        parent.close();
+        Assert.assertTrue(parent.closed);
+        Assert.assertTrue(child1.closed);
+        Assert.assertTrue(child2.closed);
+
+        // Reset and wrap
+        parent.reset();
+        child1.reset();
+        child2.reset();
+
+        parent.setCloseChildren(false);
+
+        // Ensure all handlers are not closed
+        Assert.assertFalse(parent.closed);
+        Assert.assertFalse(child1.closed);
+        Assert.assertFalse(child2.closed);
+
+        parent.close();
+
+        // The parent should be closed, the others should be open
+        Assert.assertTrue(parent.closed);
+        Assert.assertFalse(child1.closed);
+        Assert.assertFalse(child2.closed);
+
+    }
+
+    @Test
+    public void testCallerCalculationCheckFormatterChange() throws Exception {
+        final CloseHandler parent = new CloseHandler();
+
+        // Create a formatter for the parent that will require caller calculation
+        final PatternFormatter formatter = new PatternFormatter("%d %M %s%e%n");
+        parent.setFormatter(formatter);
+
+        Assert.assertTrue(parent.isCallerCalculationRequired());
+
+        // Change the formatter to not require calculation, this should trigger false to be returned
+        formatter.setPattern("%d %s%e%n");
+        Assert.assertFalse(parent.isCallerCalculationRequired());
+    }
+
+    @Test
+    public void testCallerCalculationCheckNewFormatter() throws Exception {
+        final CloseHandler parent = new CloseHandler();
+
+        // Create a formatter for the parent that will require caller calculation
+        final PatternFormatter formatter = new PatternFormatter("%d %M %s%e%n");
+        parent.setFormatter(formatter);
+
+        Assert.assertTrue(parent.isCallerCalculationRequired());
+
+        // Add a new formatter which should result in the caller calculation not to be required
+        parent.setFormatter(new PatternFormatter("%d %s%e%n"));
+        Assert.assertFalse(parent.isCallerCalculationRequired());
+    }
+
+    @Test
+    public void testCallerCalculationCheckChildFormatter() throws Exception {
+        final CloseHandler parent = new CloseHandler();
+        final CloseHandler child = new CloseHandler();
+        parent.addHandler(child);
+
+        // Create a formatter for the parent that will require caller calculation
+        final PatternFormatter formatter = new PatternFormatter("%d %M %s%e%n");
+        child.setFormatter(formatter);
+        Assert.assertTrue(parent.isCallerCalculationRequired());
+
+        // Remove the child handler which should result in the caller calculation not being required since the formatter
+        // is null
+        parent.removeHandler(child);
+        Assert.assertFalse(parent.isCallerCalculationRequired());
+
+        // Add a formatter to the parent and add he child back, the parent handler will not require calculation, but
+        // the child should
+        parent.setFormatter(new PatternFormatter("%d %s%e%n"));
+        parent.addHandler(child);
+        Assert.assertTrue(parent.isCallerCalculationRequired());
+    }
+
+    @Test
+    public void testCallerCalculationNonExtFormatter() throws Exception {
+        final CloseHandler parent = new CloseHandler();
+        final CloseHandler child = new CloseHandler();
+        parent.addHandler(child);
+
+        // Create a non ExtFormatter for the parent that will require caller calculation
+        child.setFormatter(new SimpleFormatter());
+        Assert.assertTrue(child.isCallerCalculationRequired());
+        Assert.assertTrue(parent.isCallerCalculationRequired());
+        parent.setFormatter(new SimpleFormatter());
+        Assert.assertTrue(parent.isCallerCalculationRequired());
+    }
+
+    static class CloseHandler extends ExtHandler {
+        private boolean closed = false;
+
+        @Override
+        public void close() {
+            closed = true;
+            super.close();
+        }
+
+        void reset() {
+            closed = false;
+        }
+    }
+}