MDC values no longer inherited. This fixes LOGBACK-422 and LOGBACK-624

Author: ceki

logback-classic/src/main/java/ch/qos/logback/classic/util/LogbackMDCAdapter.java

@@ -13,12 +13,11 @@
  */
 package ch.qos.logback.classic.util;
 
+import java.util.Collections;
 import java.util.HashMap;
 import java.util.Map;
-import java.util.Collections;
 import java.util.Set;
 
-
 import org.slf4j.spi.MDCAdapter;
 
 /**
@@ -53,7 +52,7 @@ public class LogbackMDCAdapter implements MDCAdapter {
   // Initially the contents of the thread local in parent and child threads
   // reference the same map. However, as soon as a thread invokes the put()
   // method, the maps diverge as they should.
-  final InheritableThreadLocal<Map<String, String>> copyOnInheritThreadLocal = new InheritableThreadLocal<Map<String, String>>();
+  final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal<Map<String, String>>();
 
   private static final int WRITE_OPERATION = 1;
   private static final int MAP_COPY_OPERATION = 2;
@@ -81,7 +80,7 @@ private Map<String, String> duplicateAndInsertNewMap(Map<String, String> oldMap)
         }
     }
 
-    copyOnInheritThreadLocal.set(newMap);
+    copyOnThreadLocal.set(newMap);
     return newMap;
   }
 
@@ -101,7 +100,7 @@ public void put(String key, String val) throws IllegalArgumentException {
       throw new IllegalArgumentException("key cannot be null");
     }
 
-    Map<String, String> oldMap = copyOnInheritThreadLocal.get();
+    Map<String, String> oldMap = copyOnThreadLocal.get();
     Integer lastOp = getAndSetLastOperation(WRITE_OPERATION);
 
     if (wasLastOpReadOrNull(lastOp) || oldMap == null) {
@@ -120,7 +119,7 @@ public void remove(String key) {
     if (key == null) {
       return;
     }
-    Map<String, String> oldMap = copyOnInheritThreadLocal.get();
+    Map<String, String> oldMap = copyOnThreadLocal.get();
     if (oldMap == null) return;
 
     Integer lastOp = getAndSetLastOperation(WRITE_OPERATION);
@@ -139,15 +138,15 @@ public void remove(String key) {
    */
   public void clear() {
     lastOperation.set(WRITE_OPERATION);
-    copyOnInheritThreadLocal.remove();
+    copyOnThreadLocal.remove();
   }
 
   /**
    * Get the context identified by the <code>key</code> parameter.
    * <p/>
    */
   public String get(String key) {
-    final Map<String, String> map = copyOnInheritThreadLocal.get();
+    final Map<String, String> map = copyOnThreadLocal.get();
     if ((map != null) && (key != null)) {
          return map.get(key);
     } else {
@@ -161,7 +160,7 @@ public String get(String key) {
    */
   public Map<String, String> getPropertyMap() {
     lastOperation.set(MAP_COPY_OPERATION);
-    return copyOnInheritThreadLocal.get();
+    return copyOnThreadLocal.get();
   }
 
   /**
@@ -183,7 +182,7 @@ public Set<String> getKeys() {
    * null.
    */
   public Map<String, String> getCopyOfContextMap() {
-    Map<String, String> hashMap = copyOnInheritThreadLocal.get();
+    Map<String, String> hashMap = copyOnThreadLocal.get();
     if (hashMap == null) {
       return null;
     } else {
@@ -198,6 +197,6 @@ public void setContextMap(Map<String, String> contextMap) {
     newMap.putAll(contextMap);
 
     // the newMap replaces the old one for serialisation's sake
-    copyOnInheritThreadLocal.set(newMap);
+    copyOnThreadLocal.set(newMap);
   }
 }

logback-classic/src/test/java/ch/qos/logback/classic/util/LogbackMDCAdapterTest.java

@@ -35,7 +35,6 @@ public class LogbackMDCAdapterTest {
 
   private final LogbackMDCAdapter mdcAdapter = new LogbackMDCAdapter();
 
-
   /**
    * Test that CopyOnInheritThreadLocal does not barf when the
    * MDC hashmap is null
@@ -67,12 +66,12 @@ public void removeInexistentKey() {
   @Test
   public void sequenceWithGet() {
     mdcAdapter.put("k0", "v0");
-    Map<String, String> map0 = mdcAdapter.copyOnInheritThreadLocal.get();
+    Map<String, String> map0 = mdcAdapter.copyOnThreadLocal.get();
     mdcAdapter.get("k0");  
     mdcAdapter.put("k1", "v1"); // no map copy required
 
     // verify that map0 is the same instance and that value was updated
-    assertSame(map0, mdcAdapter.copyOnInheritThreadLocal.get());
+    assertSame(map0, mdcAdapter.copyOnThreadLocal.get());
   }
 
 
@@ -88,25 +87,25 @@ public void sequenceWithGetPropertyMap() {
   @Test
   public void sequenceWithCopyContextMap() {
     mdcAdapter.put("k0", "v0");
-    Map<String, String> map0 = mdcAdapter.copyOnInheritThreadLocal.get();
+    Map<String, String> map0 = mdcAdapter.copyOnThreadLocal.get();
     mdcAdapter.getCopyOfContextMap();  
     mdcAdapter.put("k1", "v1"); // no map copy required
 
     // verify that map0 is the same instance and that value was updated
-    assertSame(map0, mdcAdapter.copyOnInheritThreadLocal.get());
+    assertSame(map0, mdcAdapter.copyOnThreadLocal.get());
   }
 
 
   // =================================================
 
   /**
-   * Test that LogbackMDCAdapter copies its hashmap when a child
+   * Test that LogbackMDCAdapter does not copy its hashmap when a child
    * thread inherits it.
    *
    * @throws InterruptedException
    */
   @Test
-  public void copyOnInheritenceTest() throws InterruptedException {
+  public void noCopyOnInheritenceTest() throws InterruptedException {
     CountDownLatch countDownLatch = new CountDownLatch(1);
     String firstKey = "x" + diff;
     String secondKey = "o" + diff;
@@ -129,7 +128,6 @@ public void copyOnInheritenceTest() throws InterruptedException {
     assertEquals(parentHMWitness, parentHM);
 
     HashMap<String, String> childHMWitness = new HashMap<String, String>();
-    childHMWitness.put(firstKey, firstKey + A_SUFFIX);
     childHMWitness.put(secondKey, secondKey + A_SUFFIX);
     assertEquals(childHMWitness, childThread.childHM);
 
@@ -195,8 +193,8 @@ public void run() {
 
 
   Map<String, String> getMapFromMDCAdapter(LogbackMDCAdapter lma) {
-    InheritableThreadLocal<Map<String, String>> copyOnInheritThreadLocal = lma.copyOnInheritThreadLocal;
-    return copyOnInheritThreadLocal.get();
+    ThreadLocal<Map<String, String>> copyOnThreadLocal = lma.copyOnThreadLocal;
+    return copyOnThreadLocal.get();
   }
 
   // ==========================    various thread classes
@@ -247,10 +245,11 @@ class ChildThread extends Thread {
     @Override
     public void run() {
       logbackMDCAdapter.put(secondKey, secondKey + A_SUFFIX);
-      assertNotNull(logbackMDCAdapter.get(firstKey));
-      assertEquals(firstKey + A_SUFFIX, logbackMDCAdapter.get(firstKey));
+      assertNull(logbackMDCAdapter.get(firstKey));
       if (countDownLatch != null) countDownLatch.countDown();
+      assertNotNull(logbackMDCAdapter.get(secondKey));
       assertEquals(secondKey + A_SUFFIX, logbackMDCAdapter.get(secondKey));
+      
       successful = true;
       childHM = getMapFromMDCAdapter(logbackMDCAdapter);
     }

logback-site/src/site/pages/news.html

@@ -32,6 +32,33 @@ <h2>Logback News</h2>
     <h3>2016, Release of version 1.1.5</h3>
 
 
+    <div class="breaking">
+      <h4>MDC values are no longer inherited by child threads.</h4>
+    </div>
+
+    <p>Child threads no longer inherit MDC values. In previous
+    versions of logback as well as log4j 1.x, MDC values were
+    inherited by child threads. Several users have argued convincingly
+    that MDC inheritance by child threads was unhelpful and even
+    dangerous. This change fixes <a
+    href="http://jira.qos.ch/browse/LOGBACK-422">LOGBACK-422</a> and <a
+    href="http://jira.qos.ch/browse/LOGBACK-624">LOGBACK-624</a>
+    </p>
+
+    <p>When the <code>FileNamePattern</code> string for
+    <code>RollingFileAppender/SizeAndTimeBasedFNATP</code> lacks a %i
+    token, then compression for the second archive in the same period
+    cannot occur as the target file already exists. Under those
+    circumstances, logback leaves behind .tmp files as reported in <a
+    href="http://jira.qos.ch/browse/LOGBACK-992">LOGBACK-992</a>, <a
+    href="http://jira.qos.ch/browse/LOGBACK-173">LOGBACK-173</a> and
+    <a
+    href="http://jira.qos.ch/browse/LOGBACK-920">LOGBACK-920</a>. In
+    this release, this particular condition is detected by
+    <code>RollingFileAppender</code> which will not start but alert
+    the user instead.
+    </p>
+
     <p>AsyncAppender is now configurable to never block. This feature
     was requested by Jeff Wartes in <a
     href="http://jira.qos.ch/browse/LOGBACK-898">LOGBACK-898</a> with