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

…f the formatter being used requires it.

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/PatternFormatter.java

@@ -19,14 +19,20 @@
 
 package org.jboss.logmanager.formatters;
 
+import java.util.regex.Pattern;
+
 /**
  * A formatter which uses a text pattern to format messages.
  */
 public class PatternFormatter extends MultistepFormatter {
+    private static final Pattern CALLER_CHECK_PATTERN = Pattern.compile(".*(%M|%C|%F|%L|%l).*");
 
     private volatile String pattern;
 
     private volatile ColorMap colors;
+
+    private volatile boolean callerCalculationRequired = false;
+
     /**
      * Construct a new instance.
      */
@@ -43,6 +49,7 @@ public PatternFormatter(String pattern) {
         super(FormatStringParser.getSteps(pattern, ColorMap.DEFAULT_COLOR_MAP));
         this.colors = ColorMap.DEFAULT_COLOR_MAP;
         this.pattern = pattern;
+        callerCalculationRequired = containsCallerPattern(pattern);
     }
 
     /**
@@ -55,6 +62,7 @@ public PatternFormatter(String pattern, String colors) {
         ColorMap colorMap = ColorMap.create(colors);
         this.colors = colorMap;
         this.pattern = pattern;
+        callerCalculationRequired = containsCallerPattern(pattern);
         setSteps(FormatStringParser.getSteps(pattern, colorMap));
     }
 
@@ -75,6 +83,7 @@ public String getPattern() {
     public void setPattern(final String pattern) {
         setSteps(FormatStringParser.getSteps(pattern, colors));
         this.pattern = pattern;
+        callerCalculationRequired = containsCallerPattern(pattern);
     }
 
     /**
@@ -134,4 +143,13 @@ public void setColors(String colors) {
     public String getColors() {
         return this.colors.toString();
     }
+
+    @Override
+    public boolean isCallerCalculationRequired() {
+        return callerCalculationRequired;
+    }
+
+    private static boolean containsCallerPattern(final String pattern) {
+        return CALLER_CHECK_PATTERN.matcher(pattern).matches();
+    }
 }

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:jperkins@redhat.com">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;
+        }
+    }
+}