Return-Path: 
 <commits-return-3277-apmail-logging-commits-archive=logging.apache.org@logging.apache.org>
X-Original-To: apmail-logging-commits-archive@minotaur.apache.org
Delivered-To: apmail-logging-commits-archive@minotaur.apache.org
Received: from mail.apache.org (hermes.apache.org [140.211.11.3])
	by minotaur.apache.org (Postfix) with SMTP id 687FF10983
	for <apmail-logging-commits-archive@minotaur.apache.org>;
 Sun,  5 Jan 2014 08:10:37 +0000 (UTC)
Received: (qmail 87225 invoked by uid 500); 5 Jan 2014 08:10:35 -0000
Delivered-To: apmail-logging-commits-archive@logging.apache.org
Received: (qmail 87204 invoked by uid 500); 5 Jan 2014 08:10:31 -0000
Mailing-List: contact commits-help@logging.apache.org; run by ezmlm
Precedence: bulk
List-Help: <mailto:commits-help@logging.apache.org>
List-Unsubscribe: <mailto:commits-unsubscribe@logging.apache.org>
List-Post: <mailto:commits@logging.apache.org>
List-Id: <commits.logging.apache.org>
Reply-To: dev@logging.apache.org
Delivered-To: mailing list commits@logging.apache.org
Received: (qmail 87197 invoked by uid 99); 5 Jan 2014 08:10:28 -0000
Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136)
    by apache.org (qpsmtpd/0.29) with ESMTP; Sun, 05 Jan 2014 08:10:27 +0000
X-ASF-Spam-Status: No, hits=-2000.0 required=5.0
	tests=ALL_TRUSTED
X-Spam-Check-By: apache.org
Received: from [140.211.11.4] (HELO eris.apache.org) (140.211.11.4)
    by apache.org (qpsmtpd/0.29) with ESMTP; Sun, 05 Jan 2014 08:10:26 +0000
Received: from eris.apache.org (localhost [127.0.0.1])
	by eris.apache.org (Postfix) with ESMTP id 5BBAC23888E2;
	Sun,  5 Jan 2014 08:10:06 +0000 (UTC)
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Subject: svn commit: r1555468 - in /logging/log4j/log4j2/trunk:
 log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
 src/changes/changes.xml
Date: Sun, 05 Jan 2014 08:10:06 -0000
To: commits@logging.apache.org
From: rpopma@apache.org
X-Mailer: svnmailer-1.0.9
Message-Id: <20140105081006.5BBAC23888E2@eris.apache.org>
X-Virus-Checked: Checked by ClamAV on apache.org

Author: rpopma
Date: Sun Jan  5 08:10:05 2014
New Revision: 1555468

URL: http://svn.apache.org/r1555468
Log:
LOG4J2-485: Fixed issue where toString methods that perform logging could deadlock AsyncAppender

Modified:
    logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
    logging/log4j/log4j2/trunk/src/changes/changes.xml

Modified: logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java?rev=1555468&r1=1555467&r2=1555468&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java (original)
+++ logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java Sun Jan  5 08:10:05 2014
@@ -62,6 +62,7 @@ public final class AsyncAppender extends
     private AppenderControl errorAppender;
     private AsyncThread thread;
     private static final AtomicLong threadSequence = new AtomicLong(1);
+    private static ThreadLocal<Boolean> isAppenderThread = new ThreadLocal<Boolean>();
 
 
     private AsyncAppender(final String name, final Filter filter, final AppenderRef[] appenderRefs,
@@ -122,34 +123,43 @@ public final class AsyncAppender extends
     /**
      * Actual writing occurs here.
      * <p/>
-     * @param event The LogEvent.
+     * @param evt The LogEvent.
      */
     @Override
-    public void append(final LogEvent event) {
+    public void append(final LogEvent evt) {
         if (!isStarted()) {
             throw new IllegalStateException("AsyncAppender " + getName() + " is not active");
         }
-        if (event instanceof Log4jLogEvent) {
-            boolean appendSuccessful = false;
-            if (blocking) {
+        if (!(evt instanceof Log4jLogEvent)) {
+            return; // only know how to Serialize Log4jLogEvents
+        }
+        Log4jLogEvent event = (Log4jLogEvent) evt;
+        boolean appendSuccessful = false;
+        if (blocking) {
+            if (isAppenderThread.get() == Boolean.TRUE && queue.remainingCapacity() == 0) {
+                // LOG4J2-485: avoid deadlock that would result from trying
+                // to add to a full queue from appender thread
+                event.setEndOfBatch(false); // queue is definitely not empty!
+                appendSuccessful = thread.callAppenders(event);
+            } else {
                 try {
                     // wait for free slots in the queue
-                    queue.put(Log4jLogEvent.serialize((Log4jLogEvent) event, includeLocation));
+                    queue.put(Log4jLogEvent.serialize(event, includeLocation));
                     appendSuccessful = true;
                 } catch (final InterruptedException e) {
                     LOGGER.warn("Interrupted while waiting for a free slot in the AsyncAppender LogEvent-queue {}",
                             getName());
                 }
-            } else {
-                appendSuccessful = queue.offer(Log4jLogEvent.serialize((Log4jLogEvent) event, includeLocation));
-                if (!appendSuccessful) {
-                    error("Appender " + getName() + " is unable to write primary appenders. queue is full");
-                }
             }
-            if ((!appendSuccessful) && (errorAppender != null)) {
-                errorAppender.callAppender(event);
+        } else {
+            appendSuccessful = queue.offer(Log4jLogEvent.serialize(event, includeLocation));
+            if (!appendSuccessful) {
+                error("Appender " + getName() + " is unable to write primary appenders. queue is full");
             }
         }
+        if ((!appendSuccessful) && (errorAppender != null)) {
+            errorAppender.callAppender(event);
+        }
     }
 
     /**
@@ -211,6 +221,7 @@ public final class AsyncAppender extends
 
         @Override
         public void run() {
+            isAppenderThread.set(Boolean.TRUE); // LOG4J2-485
             while (!shutdown) {
                 Serializable s;
                 try {
@@ -225,15 +236,7 @@ public final class AsyncAppender extends
                 }
                 final Log4jLogEvent event = Log4jLogEvent.deserialize(s);
                 event.setEndOfBatch(queue.isEmpty());
-                boolean success = false;
-                for (final AppenderControl control : appenders) {
-                    try {
-                        control.callAppender(event);
-                        success = true;
-                    } catch (final Exception ex) {
-                        // If no appender is successful the error appender will get it.
-                    }
-                }
+                boolean success = callAppenders(event);
                 if (!success && errorAppender != null) {
                     try {
                         errorAppender.callAppender(event);
@@ -249,9 +252,7 @@ public final class AsyncAppender extends
                     if (s instanceof Log4jLogEvent) {
                         final Log4jLogEvent event = Log4jLogEvent.deserialize(s);
                         event.setEndOfBatch(queue.isEmpty());
-                        for (final AppenderControl control : appenders) {
-                            control.callAppender(event);
-                        }
+                        callAppenders(event);
                     }
                 } catch (final InterruptedException ex) {
                     // May have been interrupted to shut down.
@@ -259,6 +260,28 @@ public final class AsyncAppender extends
             }
         }
 
+        /**
+         * Calls {@link AppenderControl#callAppender(LogEvent) callAppender} on
+         * all registered {@code AppenderControl} objects, and returns {@code true}
+         * if at least one appender call was successful, {@code false} otherwise.
+         * Any exceptions are silently ignored.
+         * 
+         * @param event the event to forward to the registered appenders
+         * @return {@code true} if at least one appender call succeeded, {@code false} otherwise
+         */
+        boolean callAppenders(final Log4jLogEvent event) {
+            boolean success = false;
+            for (final AppenderControl control : appenders) {
+                try {
+                    control.callAppender(event);
+                    success = true;
+                } catch (final Exception ex) {
+                    // If no appender is successful the error appender will get it.
+                }
+            }
+            return success;
+        }
+
         public void shutdown() {
             shutdown = true;
             if (queue.isEmpty()) {

Modified: logging/log4j/log4j2/trunk/src/changes/changes.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/changes/changes.xml?rev=1555468&r1=1555467&r2=1555468&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/changes/changes.xml (original)
+++ logging/log4j/log4j2/trunk/src/changes/changes.xml Sun Jan  5 08:10:05 2014
@@ -21,6 +21,9 @@
   </properties>
   <body>
     <release version="2.0-RC1" date="2013-MM-DD" description="Bug fixes and enhancements">
+      <action issue="LOG4J2-485" dev="rpopma" type="fix">
+        Fixed issue where toString methods that perform logging could deadlock AsyncAppender.
+      </action>
       <action issue="LOG4J2-445" dev="rpopma" type="fix" due-to="Anthony Baldocchi">
         ResolverUtil cannot find packages in file URLs which include the '+' character.
       </action>