Logging > The current TurboFilterList implementation of logback-classic which calls the TurboFilters is a CopyOnWriteArrayList. This means every time any logger method is called the array of TurboFilters is copied. As we are using the logger extensively this small copy is visible in the flamegraph. A call to isXLevelEnabled check does not avoid this path.

Author: A-Imal

src/main/java/com/hivemq/bootstrap/LoggingBootstrap.java

@@ -25,9 +25,10 @@
 import ch.qos.logback.core.read.ListAppender;
 import ch.qos.logback.core.util.StatusPrinter;
 import com.hivemq.extension.sdk.api.annotations.NotNull;
-import com.hivemq.logging.NettyLogLevelModifier;
-import com.hivemq.logging.XodusEnvironmentImplLogLevelModificator;
-import com.hivemq.logging.XodusFileDataWriterLogLevelModificator;
+import com.hivemq.logging.LogLevelModifierTurboFilter;
+import com.hivemq.logging.modifier.NettyLogLevelModifier;
+import com.hivemq.logging.modifier.XodusEnvironmentImplLogLevelModifier;
+import com.hivemq.logging.modifier.XodusFileDataWriterLogLevelModifier;
 import org.apache.commons.lang3.SystemUtils;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
@@ -42,22 +43,15 @@
  * This class is responsible for all logging bootstrapping. This is only
  * needed at the very beginning of HiveMQs lifecycle and before bootstrapping other
  * resources
- *
- * @author Dominik Obermaier
  */
 public class LoggingBootstrap {
 
-    private static @NotNull ListAppender<ILoggingEvent> listAppender = new ListAppender<>();
-
     private static final Logger log = LoggerFactory.getLogger(LoggingBootstrap.class);
 
-    private static final XodusFileDataWriterLogLevelModificator xodusFileDataWriterLogLevelModificator =
-            new XodusFileDataWriterLogLevelModificator();
-    private static final NettyLogLevelModifier nettyLogLevelModifier = new NettyLogLevelModifier();
-    private static final XodusEnvironmentImplLogLevelModificator xodusEnvironmentImplLogLevelModificator =
-            new XodusEnvironmentImplLogLevelModificator();
-
+    private static @NotNull ListAppender<ILoggingEvent> listAppender = new ListAppender<>();
     private static final List<Appender<ILoggingEvent>> defaultAppenders = new LinkedList<>();
+    private static final @NotNull LogLevelModifierTurboFilter logLevelModifierTurboFilter =
+            new LogLevelModifierTurboFilter();
 
     /**
      * Prepares the logging. This method must be called before any logging occurs
@@ -90,9 +84,8 @@ public static void prepareLogging() {
     public static void initLogging(final @NotNull File configFolder) {
 
         final LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
-        final ch.qos.logback.classic.Logger logger = getRootLogger();
 
-        context.addListener(new LogbackChangeListener(logger));
+        context.addListener(new LogbackChangeListener());
 
         final boolean overridden = overrideLogbackXml(configFolder);
 
@@ -104,13 +97,15 @@ public static void initLogging(final @NotNull File configFolder) {
 
         reset();
 
+        context.addTurboFilter(logLevelModifierTurboFilter);
+
         // must be added here, as addLoglevelModifiers() is much to late
         if (SystemUtils.IS_OS_WINDOWS) {
-            context.addTurboFilter(xodusFileDataWriterLogLevelModificator);
+            logLevelModifierTurboFilter.registerLogLevelModifier(new XodusFileDataWriterLogLevelModifier());
             log.trace("Added Xodus log level modifier for FileDataWriter.class");
         }
 
-        context.addTurboFilter(nettyLogLevelModifier);
+        logLevelModifierTurboFilter.registerLogLevelModifier(new NettyLogLevelModifier());
         log.trace("Added Netty log level modifier");
     }
 
@@ -194,9 +189,7 @@ private static boolean overrideLogbackXml(final @NotNull File configFolder) {
     }
 
     public static void addLoglevelModifiers() {
-        final LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
-
-        context.addTurboFilter(xodusEnvironmentImplLogLevelModificator);
+        logLevelModifierTurboFilter.registerLogLevelModifier(new XodusEnvironmentImplLogLevelModifier());
         log.trace("Added Xodus log level modifier for EnvironmentImpl.class");
     }
 
@@ -208,14 +201,7 @@ private static void reset() {
         listAppender.list.clear();
     }
 
-    private static class LogbackChangeListener implements LoggerContextListener {
-
-        private final @NotNull ch.qos.logback.classic.Logger logger;
-
-        private LogbackChangeListener(
-                final @NotNull ch.qos.logback.classic.Logger logger) {
-            this.logger = logger;
-        }
+    private static final class LogbackChangeListener implements LoggerContextListener {
 
         @Override
         public boolean isResetResistant() {
@@ -237,7 +223,7 @@ public void onStart(final @NotNull LoggerContext context) {
         @Override
         public void onReset(final @NotNull LoggerContext context) {
             log.trace("logback.xml was changed");
-            addTurboFilters(context);
+            context.addTurboFilter(logLevelModifierTurboFilter);
         }
 
         @Override
@@ -249,12 +235,5 @@ public void onStop(final @NotNull LoggerContext context) {
         public void onLevelChange(final @NotNull ch.qos.logback.classic.Logger logger, final @NotNull Level level) {
             //noop
         }
-
-        private void addTurboFilters(final @NotNull LoggerContext context) {
-
-            context.addTurboFilter(xodusFileDataWriterLogLevelModificator);
-            context.addTurboFilter(nettyLogLevelModifier);
-            context.addTurboFilter(xodusEnvironmentImplLogLevelModificator);
-        }
     }
 }

src/main/java/com/hivemq/logging/LogLevelModifierTurboFilter.java

@@ -0,0 +1,64 @@
+/*
+ * Copyright 2019-present HiveMQ GmbH
+ *
+ * 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 com.hivemq.logging;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.turbo.TurboFilter;
+import ch.qos.logback.core.spi.FilterReply;
+import com.hivemq.extension.sdk.api.annotations.NotNull;
+import com.hivemq.extension.sdk.api.annotations.Nullable;
+import com.hivemq.logging.modifier.LogLevelModifier;
+import org.slf4j.Marker;
+
+import java.util.ArrayList;
+import java.util.List;
+
+public class LogLevelModifierTurboFilter extends TurboFilter {
+
+    private @NotNull List<LogLevelModifier> logLevelModifiers = new ArrayList<>();
+
+    @Override
+    public @NotNull FilterReply decide(
+            final @Nullable Marker marker,
+            final @NotNull Logger logger,
+            final @NotNull Level level,
+            final @Nullable String format,
+            final @Nullable Object @Nullable [] params,
+            final @Nullable Throwable t) {
+
+        FilterReply filterReply = FilterReply.NEUTRAL;
+
+        if (format == null || level == Level.OFF) {
+            // format is the log message
+            return filterReply;
+        }
+
+        for (final LogLevelModifier logLevelModifier : logLevelModifiers) {
+            filterReply = logLevelModifier.decide(marker, logger, level, format, params, t);
+            if (filterReply != FilterReply.NEUTRAL) {
+                return filterReply;
+            }
+        }
+        return filterReply;
+    }
+
+    public void registerLogLevelModifier(final @NotNull LogLevelModifier logLevelModifier) {
+        final List<LogLevelModifier> tmp = new ArrayList<>(logLevelModifiers);
+        tmp.add(logLevelModifier);
+        logLevelModifiers = tmp;
+    }
+}