fix race condition reported in LOGBACK-1362

Signed-off-by: Ceki Gulcu <[email protected]>

Author: ceki

logback-core/src/main/java/ch/qos/logback/core/AppenderBase.java

@@ -22,7 +22,9 @@
 import ch.qos.logback.core.status.WarnStatus;
 
 /**
- * Sets a skeleton implementation for appenders.
+ * <p>Sets a skeleton implementation for appenders.</p>
+ *
+ * <p>It is coarsely synchronized in its {@link #doAppend(E)} method.</p>
  * 
  * <p>
  * For more information about this appender, please refer to the online manual

logback-core/src/main/java/ch/qos/logback/core/OutputStreamAppender.java

@@ -77,9 +77,17 @@ public void start() {
             addStatus(new ErrorStatus("No output stream set for the appender named \"" + name + "\".", this));
             errors++;
         }
+
+        if (encoder == null) {
+            addWarn("Encoder has not been set. Cannot invoke its init method.");
+            errors++;
+        }
+
+
         // only error free appenders should be activated
         if (errors == 0) {
             super.start();
+            encoderInit();
         }
     }
 
@@ -164,12 +172,7 @@ public void setOutputStream(OutputStream outputStream) {
             // close any previously opened output stream
             closeOutputStream();
             this.outputStream = outputStream;
-            if (encoder == null) {
-                addWarn("Encoder has not been set. Cannot invoke its init method.");
-                return;
-            }
 
-            encoderInit();
         } finally {
             streamWriteLock.unlock();
         }
@@ -198,8 +201,11 @@ private void writeBytes(byte[] byteArray) throws IOException {
             return;
 
         streamWriteLock.lock();
+
         try {
-            writeByteArrayToOutputStreamWithPossibleFlush(byteArray);
+            if(isStarted()) {
+                writeByteArrayToOutputStreamWithPossibleFlush(byteArray);
+            }
         } finally {
             streamWriteLock.unlock();
         }

logback-core/src/main/java/ch/qos/logback/core/UnsynchronizedAppenderBase.java

@@ -22,15 +22,15 @@
 import ch.qos.logback.core.status.WarnStatus;
 
 /**
- * Similar to AppenderBase except that derived appenders need to handle thread
+ * Similar to {@link AppenderBase} except that derived appenders need to handle thread
  * synchronization on their own.
  * 
  * @author Ceki Gülcü
  * @author Ralph Goers
  */
 abstract public class UnsynchronizedAppenderBase<E> extends ContextAwareBase implements Appender<E> {
 
-    protected boolean started = false;
+    protected volatile boolean started = false;
 
     // using a ThreadLocal instead of a boolean add 75 nanoseconds per
     // doAppend invocation. This is tolerable as doAppend takes at least a few

logback-core/src/test/java/ch/qos/logback/core/OutputStreamAppenderTest.java

@@ -82,8 +82,8 @@ public void nullFileFooter() {
 
     public void headerFooterCheck(String fileHeader, String presentationHeader, String presentationFooter,
             String fileFooter) {
-        OutputStreamAppender<Object> wa = new OutputStreamAppender<Object>();
-        wa.setContext(context);
+        OutputStreamAppender<Object> osa = new OutputStreamAppender<Object>();
+        osa.setContext(context);
         ByteArrayOutputStream baos = new ByteArrayOutputStream();
 
         SamplePatternLayout<Object> spl = new SamplePatternLayout<Object>();
@@ -99,16 +99,17 @@ public void headerFooterCheck(String fileHeader, String presentationHeader, Stri
         encoder.setLayout(spl);
         encoder.setContext(context);
 
-        wa.setEncoder(encoder);
-        wa.setOutputStream(baos);
-        wa.start();
+        osa.setEncoder(encoder);
+        osa.setOutputStream(baos);
+        osa.start();
 
-        wa.stop();
+        osa.stop();
         String result = baos.toString();
 
         String expectedHeader = emtptyIfNull(fileHeader) + emtptyIfNull(presentationHeader);
 
         System.out.println(result);
+
         Assertions.assertTrue(result.startsWith(expectedHeader), result);
 
         String expectedFooter = emtptyIfNull(presentationFooter) + emtptyIfNull(fileFooter);

logback-core/src/test/java/ch/qos/logback/core/issue/lbcore258/Logback1362.java

@@ -0,0 +1,105 @@
+/*
+ * 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.core.issue.lbcore258;
+
+
+import java.io.IOException;
+import java.io.OutputStream;
+
+
+import ch.qos.logback.core.OutputStreamAppender;
+import ch.qos.logback.core.encoder.EncoderBase;
+import org.junit.jupiter.api.Test;
+
+/**
+ * Provided by Alexander Kudrevatykh in LOGBACK-1362
+ */
+public class Logback1362 {
+
+    long startNanos = System.nanoTime();
+    long DELAY = 20;
+    long getNanos() {
+        return (System.nanoTime() - startNanos);
+    }
+
+    @Test
+    public void testAppender() throws InterruptedException {
+
+        OutputStreamAppender<Object> appender = new OutputStreamAppender<Object>() {
+            @Override
+            public void addError(String msg, Throwable ex) {
+                throw new RuntimeException(getNanos()+"  "+msg, ex);
+            }
+        };
+
+        appender.setEncoder(new EncoderBase<Object>() {
+
+            @Override
+            public byte[] headerBytes() {
+                return null;
+            }
+
+            @Override
+            public byte[] encode(Object event) {
+                delay(DELAY*2);
+                return new byte[]{'A'};
+            }
+
+            @Override
+            public byte[] footerBytes() {
+                // TODO Auto-generated method stub
+                return null;
+            }
+        });
+        appender.setOutputStream(new OutputStream() {
+
+            @Override
+            public void write(int b) throws IOException {
+                throw new RuntimeException("not closed appender");
+            }
+        });
+
+        System.out.println(getNanos() + " About to call appender.start()");
+        appender.start();
+        System.out.println(getNanos() + " After call to appender.start()");
+
+        Thread t = new Thread(new Runnable() {
+            @Override
+            public void run() {
+                delay(DELAY);
+                System.out.println(getNanos() + " About to call appender.stop()");
+                appender.stop();
+                System.out.println(getNanos() + " After call to appender.stop()");
+            }
+        });
+        t.start();
+        System.out.println(getNanos() + " Calling appender.doAppend(new Object());");
+        appender.doAppend(new Object());
+        System.out.println("xxxxxxxxxxxxxxxxxxxxxx");
+        System.out.println(getNanos()+ " After call to appender.doAppender(new Object())");
+        t.join();
+    }
+
+    private void delay(long delayInMillis) {
+        try {
+            Thread.sleep(delayInMillis);
+        } catch (InterruptedException e) {
+            // TODO Auto-generated catch block
+            e.printStackTrace();
+        }
+    }
+
+}
+