From b9dd97588e211c9c1511ccca7efaf0abf7ffcc68 Mon Sep 17 00:00:00 2001 From: James Perkins Date: Fri, 28 Jul 2017 09:48:12 -0700 Subject: [PATCH] [LOGMGR-161] Make best attempt to only calculate caller information if the formatter being used requires it. --- .../org/jboss/logmanager/ExtFormatter.java | 15 ++ .../java/org/jboss/logmanager/ExtHandler.java | 39 +++++ .../logmanager/formatters/FormatStep.java | 9 ++ .../logmanager/formatters/Formatters.java | 25 +++ .../formatters/MultistepFormatter.java | 11 ++ .../formatters/StructuredFormatter.java | 5 + .../logmanager/handlers/AsyncHandler.java | 14 +- .../logmanager/handlers/QueueHandler.java | 13 +- .../logmanager/handlers/ExtHandlerTests.java | 153 ++++++++++++++++++ .../logmanager/handlers/HandlerTest.java | 83 ---------- 10 files changed, 281 insertions(+), 86 deletions(-) create mode 100644 src/test/java/org/jboss/logmanager/handlers/ExtHandlerTests.java delete mode 100644 src/test/java/org/jboss/logmanager/handlers/HandlerTest.java diff --git a/src/main/java/org/jboss/logmanager/ExtFormatter.java b/src/main/java/org/jboss/logmanager/ExtFormatter.java index 174e5144..5b052f07 100644 --- a/src/main/java/org/jboss/logmanager/ExtFormatter.java +++ b/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; + } } diff --git a/src/main/java/org/jboss/logmanager/ExtHandler.java b/src/main/java/org/jboss/logmanager/ExtHandler.java index 7ee53634..ed564489 100644 --- a/src/main/java/org/jboss/logmanager/ExtHandler.java +++ b/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. + *

+ * 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. + *

+ * + * @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()); + } } diff --git a/src/main/java/org/jboss/logmanager/formatters/FormatStep.java b/src/main/java/org/jboss/logmanager/formatters/FormatStep.java index 456d2bc9..7c610da0 100644 --- a/src/main/java/org/jboss/logmanager/formatters/FormatStep.java +++ b/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; + } } diff --git a/src/main/java/org/jboss/logmanager/formatters/Formatters.java b/src/main/java/org/jboss/logmanager/formatters/Formatters.java index b21083de..56926254 100644 --- a/src/main/java/org/jboss/logmanager/formatters/Formatters.java +++ b/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; + } }; } diff --git a/src/main/java/org/jboss/logmanager/formatters/MultistepFormatter.java b/src/main/java/org/jboss/logmanager/formatters/MultistepFormatter.java index 57d93130..3475672f 100644 --- a/src/main/java/org/jboss/logmanager/formatters/MultistepFormatter.java +++ b/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; + } } diff --git a/src/main/java/org/jboss/logmanager/formatters/StructuredFormatter.java b/src/main/java/org/jboss/logmanager/formatters/StructuredFormatter.java index 9190e7a7..1ffb1462 100644 --- a/src/main/java/org/jboss/logmanager/formatters/StructuredFormatter.java +++ b/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. diff --git a/src/main/java/org/jboss/logmanager/handlers/AsyncHandler.java b/src/main/java/org/jboss/logmanager/handlers/AsyncHandler.java index 25fe27e6..6139be64 100644 --- a/src/main/java/org/jboss/logmanager/handlers/AsyncHandler.java +++ b/src/main/java/org/jboss/logmanager/handlers/AsyncHandler.java @@ -136,8 +136,18 @@ protected void doPublish(final ExtLogRecord record) { } } final BlockingQueue 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 { diff --git a/src/main/java/org/jboss/logmanager/handlers/QueueHandler.java b/src/main/java/org/jboss/logmanager/handlers/QueueHandler.java index 286d31c9..3011da0d 100644 --- a/src/main/java/org/jboss/logmanager/handlers/QueueHandler.java +++ b/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); } diff --git a/src/test/java/org/jboss/logmanager/handlers/ExtHandlerTests.java b/src/test/java/org/jboss/logmanager/handlers/ExtHandlerTests.java new file mode 100644 index 00000000..4cfdb724 --- /dev/null +++ b/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 James R. Perkins + */ +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; + } + } +} diff --git a/src/test/java/org/jboss/logmanager/handlers/HandlerTest.java b/src/test/java/org/jboss/logmanager/handlers/HandlerTest.java deleted file mode 100644 index 45f49be6..00000000 --- a/src/test/java/org/jboss/logmanager/handlers/HandlerTest.java +++ /dev/null @@ -1,83 +0,0 @@ -/* - * 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 org.jboss.logmanager.ExtHandler; -import org.junit.Assert; -import org.junit.Test; - -/** - * @author James R. Perkins - */ -public class HandlerTest { - - @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); - - } - - static class CloseHandler extends ExtHandler { - private boolean closed = false; - - @Override - public void close() { - closed = true; - super.close(); - } - - void reset() { - closed = false; - } - } -}