only one shutdown hooks allowed, locks during LoggerContext.stop operation, fixes LOGBACK-1551

Signed-off-by: Ceki Gulcu <ceki@qos.ch>

Author: ceki

logback-classic/src/main/java/ch/qos/logback/classic/LoggerContext.java

@@ -1,13 +1,13 @@
 /**
  * Logback: the reliable, generic, fast and flexible logging framework.
  * Copyright (C) 1999-2015, QOS.ch. All rights reserved.
- *
+ * <p>
  * This program and the accompanying materials are dual-licensed under
  * either the terms of the Eclipse Public License v1.0 as published by
  * the Eclipse Foundation
- *
- *   or (per the licensee's choosing)
- *
+ * <p>
+ * or (per the licensee's choosing)
+ * <p>
  * under the terms of the GNU Lesser General Public License version 2.1
  * as published by the Free Software Foundation.
  */
@@ -23,6 +23,7 @@
 import java.util.Map;
 import java.util.concurrent.ConcurrentHashMap;
 import java.util.concurrent.ScheduledFuture;
+import java.util.concurrent.locks.ReentrantLock;
 
 import ch.qos.logback.classic.util.LogbackMDCAdapter;
 import ch.qos.logback.core.status.ErrorStatus;
@@ -57,7 +58,9 @@
  */
 public class LoggerContext extends ContextBase implements ILoggerFactory, LifeCycle {
 
-    /** Default setting of packaging data in stack traces */
+    /**
+     * Default setting of packaging data in stack traces
+     */
     public static final boolean DEFAULT_PACKAGING_DATA = false;
 
     final Logger root;
@@ -74,7 +77,6 @@ public class LoggerContext extends ContextBase implements ILoggerFactory, LifeCy
 
     MDCAdapter mdcAdapter;
 
-
     private int maxCallerDataDepth = ClassicConstants.DEFAULT_MAX_CALLEDER_DATA_DEPTH;
 
     int resetCount = 0;
@@ -91,6 +93,10 @@ public LoggerContext() {
         initEvaluatorMap();
         size = 1;
         this.frameworkPackages = new ArrayList<String>();
+        // In 1.5.7, the stop() method assumes that at some point the context has been started
+        // since earlier versions of logback did not mandate calling the start method
+        // we need to call in the constructor
+        this.start();
     }
 
     void initEvaluatorMap() {
@@ -117,8 +123,6 @@ public void setName(String name) {
         updateLoggerContextVO();
     }
 
-
-
     public final Logger getLogger(final Class<?> clazz) {
         return getLogger(clazz.getName());
     }
@@ -194,9 +198,7 @@ public Logger exists(String name) {
 
     final void noAppenderDefinedWarning(final Logger logger) {
         if (noAppenderWarning++ == 0) {
-            getStatusManager().add(new WarnStatus(
-                    "No appenders present in context [" + getName() + "] for logger [" + logger.getName() + "].",
-                    logger));
+            getStatusManager().add(new WarnStatus("No appenders present in context [" + getName() + "] for logger [" + logger.getName() + "].", logger));
         }
     }
 
@@ -219,17 +221,24 @@ public boolean isPackagingDataEnabled() {
         return packagingDataEnabled;
     }
 
-    private void cancelScheduledTasks() {
-        for (ScheduledFuture<?> sf : scheduledFutures) {
-            sf.cancel(false);
+    void cancelScheduledTasks() {
+
+        try {
+            configurationLock.lock();
+
+            for (ScheduledFuture<?> sf : scheduledFutures) {
+                sf.cancel(false);
+            }
+            scheduledFutures.clear();
+        } finally {
+            configurationLock.unlock();
         }
-        scheduledFutures.clear();
     }
 
     private void resetStatusListenersExceptResetResistant() {
         StatusManager sm = getStatusManager();
         for (StatusListener sl : sm.getCopyOfStatusListenerList()) {
-            if(!sl.isResetResistant()) {
+            if (!sl.isResetResistant()) {
                 sm.remove(sl);
             }
         }
@@ -254,29 +263,28 @@ public void resetTurboFilterList() {
         turboFilterList.clear();
     }
 
-    final FilterReply getTurboFilterChainDecision_0_3OrMore(final Marker marker, final Logger logger, final Level level,
-            final String format, final Object[] params, final Throwable t) {
+    final FilterReply getTurboFilterChainDecision_0_3OrMore(final Marker marker, final Logger logger, final Level level, final String format,
+                    final Object[] params, final Throwable t) {
         if (turboFilterList.size() == 0) {
             return FilterReply.NEUTRAL;
         }
         return turboFilterList.getTurboFilterChainDecision(marker, logger, level, format, params, t);
     }
 
-    final FilterReply getTurboFilterChainDecision_1(final Marker marker, final Logger logger, final Level level,
-            final String format, final Object param, final Throwable t) {
+    final FilterReply getTurboFilterChainDecision_1(final Marker marker, final Logger logger, final Level level, final String format, final Object param,
+                    final Throwable t) {
         if (turboFilterList.size() == 0) {
             return FilterReply.NEUTRAL;
         }
         return turboFilterList.getTurboFilterChainDecision(marker, logger, level, format, new Object[] { param }, t);
     }
 
-    final FilterReply getTurboFilterChainDecision_2(final Marker marker, final Logger logger, final Level level,
-            final String format, final Object param1, final Object param2, final Throwable t) {
+    final FilterReply getTurboFilterChainDecision_2(final Marker marker, final Logger logger, final Level level, final String format, final Object param1,
+                    final Object param2, final Throwable t) {
         if (turboFilterList.size() == 0) {
             return FilterReply.NEUTRAL;
         }
-        return turboFilterList.getTurboFilterChainDecision(marker, logger, level, format,
-                new Object[] { param1, param2 }, t);
+        return turboFilterList.getTurboFilterChainDecision(marker, logger, level, format, new Object[] { param1, param2 }, t);
     }
 
     // === start listeners ==============================================
@@ -340,10 +348,21 @@ public void start() {
     }
 
     public void stop() {
-        reset();
-        fireOnStop();
-        resetAllListeners();
-        super.stop();
+        if (!isStarted())
+            return;
+
+        try {
+            configurationLock.lock();
+            if (!isStarted())
+                return;
+
+            reset();
+            fireOnStop();
+            resetAllListeners();
+            super.stop();
+        } finally {
+            configurationLock.unlock();
+        }
     }
 
     /**
@@ -395,7 +414,6 @@ public List<String> getFrameworkPackages() {
         return frameworkPackages;
     }
 
-
     @Override
     public void setSequenceNumberGenerator(SequenceNumberGenerator sng) {
         this.sequenceNumberGenerator = sng;
@@ -411,7 +429,7 @@ public MDCAdapter getMDCAdapter() {
     }
 
     public void setMDCAdapter(MDCAdapter anAdapter) {
-        if(this.mdcAdapter !=  null) {
+        if (this.mdcAdapter != null) {
             StatusManager sm = getStatusManager();
             sm.add(new WarnStatus("mdcAdapter being reset a second time", this));
         }

logback-classic/src/main/java/ch/qos/logback/classic/joran/ReconfigureOnChangeTask.java

@@ -30,7 +30,7 @@
 import ch.qos.logback.core.status.StatusUtil;
 
 import static ch.qos.logback.core.spi.ConfigurationEvent.newConfigurationChangeDetectorRunningEvent;
-import static ch.qos.logback.core.spi.ConfigurationEvent.newConfigurationEndedEvent;
+import static ch.qos.logback.core.spi.ConfigurationEvent.newConfigurationEndedSuccessfullyEvent;
 
 public class ReconfigureOnChangeTask extends ContextAwareBase implements Runnable {
 
@@ -92,6 +92,7 @@ private void performXMLConfiguration(LoggerContext lc, URL mainConfigurationURL)
         StatusUtil statusUtil = new StatusUtil(context);
         Model failsafeTop = jc.recallSafeConfiguration();
         URL mainURL = ConfigurationWatchListUtil.getMainWatchURL(context);
+        addInfo("Resetting loggerContext ["+lc.getName()+"]");
         lc.reset();
         long threshold = System.currentTimeMillis();
         try {
@@ -129,8 +130,7 @@ private void fallbackConfiguration(LoggerContext lc, Model failsafeTop, URL main
                 joranConfigurator.processModel(failsafeTop);
                 addInfo(RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);
                 joranConfigurator.registerSafeConfiguration(failsafeTop);
-                context.fireConfigurationEvent(newConfigurationEndedEvent(this));
-                addInfo("after registerSafeConfiguration");
+                context.fireConfigurationEvent(newConfigurationEndedSuccessfullyEvent(this));
             } catch (Exception e) {
                 addError("Unexpected exception thrown by a configuration considered safe.", e);
             }

logback-classic/src/main/java/ch/qos/logback/classic/joran/SerializedModelConfigurator.java

@@ -37,6 +37,7 @@
 import java.io.InputStream;
 import java.net.MalformedURLException;
 import java.net.URL;
+import java.util.concurrent.locks.ReentrantLock;
 
 import static ch.qos.logback.core.CoreConstants.MODEL_CONFIG_FILE_EXTENSION;
 
@@ -81,8 +82,12 @@ private void configureByResource(URL url) {
             mc2mhl.link(defaultProcessor);
 
             // disallow simultaneous configurations of the same context
-            synchronized (context.getConfigurationLock()) {
+            ReentrantLock configurationLock   = context.getConfigurationLock();
+            try {
+                configurationLock.lock();
                 defaultProcessor.process(model);
+            } finally {
+                configurationLock.unlock();
             }
         } else {
             throw new LogbackException(

logback-classic/src/test/java/ch/qos/logback/classic/Logback1551.java

@@ -0,0 +1,81 @@
+/*
+ * Logback: the reliable, generic, fast and flexible logging framework.
+ * Copyright (C) 1999-2024, QOS.ch. All rights reserved.
+ *
+ * This program and the accompanying materials are dual-licensed under
+ * either the terms of the Eclipse Public License v1.0 as published by
+ * the Eclipse Foundation
+ *
+ *   or (per the licensee's choosing)
+ *
+ * under the terms of the GNU Lesser General Public License version 2.1
+ * as published by the Free Software Foundation.
+ */
+
+package ch.qos.logback.classic;
+
+import ch.qos.logback.core.util.Duration;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+
+import java.util.Arrays;
+import java.util.concurrent.ScheduledExecutorService;
+import java.util.concurrent.ScheduledFuture;
+import java.util.concurrent.TimeUnit;
+
+public class Logback1551 {
+    LoggerContext lc;
+
+    @BeforeEach
+    public void setUp() throws Exception {
+        lc = new LoggerContext();
+        lc.setName("x");
+    }
+    @Test
+    public void testConcurrentModificationScheduledTasks() {
+        ScheduledExecutorService scheduledExecutorService = lc.getScheduledExecutorService();
+        Duration duration = Duration.buildByMilliseconds(10);
+
+        Runnable runnable = new Runnable() {
+            public void run() {
+                try {
+                    Thread.sleep(100);
+                } catch (InterruptedException e) {
+                    throw new RuntimeException(e);
+                }
+            }
+        };
+        ScheduledFuture<?> scheduledFuture = scheduledExecutorService.scheduleAtFixedRate(runnable,
+                duration.getMilliseconds(), duration.getMilliseconds(), TimeUnit.MILLISECONDS);
+
+        lc.addScheduledFuture(scheduledFuture);
+        int THREAD_COUNT = 20;
+        Thread[] threads = new Thread[THREAD_COUNT];
+
+        for (int i = 0; i < THREAD_COUNT; i++) {
+            threads[i] = new Thread(new CancelRunnable(lc));
+            threads[i].start();
+        }
+
+        Arrays.stream(threads).forEach(t-> {
+            try {
+                t.join();
+            } catch (InterruptedException e) {
+                throw new RuntimeException(e);
+            }
+        });
+
+    }
+
+    private class CancelRunnable implements Runnable {
+        LoggerContext lc;
+        public CancelRunnable(LoggerContext lc) {
+            this.lc = lc;
+        }
+
+        @Override
+        public void run() {
+            lc.cancelScheduledTasks();
+        }
+    }
+}

logback-classic/src/test/java/ch/qos/logback/classic/LoggerContextTest.java

@@ -1,36 +1,30 @@
 /**
  * Logback: the reliable, generic, fast and flexible logging framework.
  * Copyright (C) 1999-2015, QOS.ch. All rights reserved.
- *
+ * <p>
  * This program and the accompanying materials are dual-licensed under
  * either the terms of the Eclipse Public License v1.0 as published by
  * the Eclipse Foundation
- *
- *   or (per the licensee's choosing)
- *
+ * <p>
+ * or (per the licensee's choosing)
+ * <p>
  * under the terms of the GNU Lesser General Public License version 2.1
  * as published by the Free Software Foundation.
  */
 package ch.qos.logback.classic;
 
-import static ch.qos.logback.core.CoreConstants.FA_FILENAME_COLLISION_MAP;
-import static org.junit.jupiter.api.Assertions.assertEquals;
-import static org.junit.jupiter.api.Assertions.assertFalse;
-import static org.junit.jupiter.api.Assertions.assertNotNull;
-import static org.junit.jupiter.api.Assertions.assertNull;
-import static org.junit.jupiter.api.Assertions.assertTrue;
-import static org.junit.jupiter.api.Assertions.fail;
-
-import java.util.Map;
-
-import org.junit.jupiter.api.BeforeEach;
-
 import ch.qos.logback.classic.turbo.NOPTurboFilter;
 import ch.qos.logback.core.CoreConstants;
 import ch.qos.logback.core.rolling.helper.FileNamePattern;
 import ch.qos.logback.core.status.StatusManager;
+import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
 
+import java.util.Map;
+
+import static ch.qos.logback.core.CoreConstants.FA_FILENAME_COLLISION_MAP;
+import static org.junit.jupiter.api.Assertions.*;
+
 public class LoggerContextTest {
     LoggerContext lc;
 
@@ -251,8 +245,8 @@ public void collisionMapsPostReset() {
         assertNotNull(fileCollisions);
         assertTrue(fileCollisions.isEmpty());
 
-        Map<String, FileNamePattern> filenamePatternCollisionMap = (Map<String, FileNamePattern>) lc
-                .getObject(CoreConstants.RFA_FILENAME_PATTERN_COLLISION_MAP);
+        Map<String, FileNamePattern> filenamePatternCollisionMap = (Map<String, FileNamePattern>) lc.getObject(
+                        CoreConstants.RFA_FILENAME_PATTERN_COLLISION_MAP);
         assertNotNull(filenamePatternCollisionMap);
         assertTrue(filenamePatternCollisionMap.isEmpty());
     }

logback-classic/src/test/java/ch/qos/logback/classic/joran/ChangeDetectedListener.java

@@ -33,7 +33,7 @@ class ChangeDetectedListener  implements ConfigurationEventListener {
     public void listen(ConfigurationEvent configurationEvent) {
         switch (configurationEvent.getEventType()) {
         case CHANGE_DETECTED:
-            System.out.println(this.toString() + "#listen Change detected" + " count="+countDownLatch.getCount());
+            System.out.println(this.toString() + "#listen Change detected " + configurationEvent +" count="+countDownLatch.getCount());
 
             countDownLatch.countDown();
             Object data = configurationEvent.getData();