[jira] [Commented] (LOG4J2-1049) AsyncAppender eats my Interrupt

["Robert Schaft (JIRA)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/LOG4J2-1049?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14580539#comment-14580539 ] 

Robert Schaft commented on LOG4J2-1049:
---------------------------------------

A similar problem was tackled by LOG4J2-830. But the fix was apparently incomplete and just made the problem harder to see.

> AsyncAppender eats my Interrupt
> -------------------------------
>
>                 Key: LOG4J2-1049
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1049
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 2.2, 2.3
>         Environment: Java 7, Windows
>            Reporter: Robert Schaft
>              Labels: Async
>   Original Estimate: 48h
>  Remaining Estimate: 48h
>
> I wrote a LoggingThread that will be stopped by sending loggingThread.interrupt() from another Thread.
> {code:title=LoggingThread.java}
> class LoggingThread extends Thread {
>   private final static Logger LOGGER = LoggerFactory.getLogger(LoggingThread .class);
>   public void run() {
>     while (!Thread.currentThread().isInterrupted()) {
>       LOGGER.debug("{} is logging {}", this, "nothing");
>     }
>   }
> }
> {code}
> Unfortunately, loggingThread.interrupt() is sometimes set before AsyncAppender.append() or at the beginning of that.
> {code:title=AsyncAppender#append() line 153}
> try {
>   // wait for free slots in the queue
>   queue.put(Log4jLogEvent.serialize(coreEvent, includeLocation));
>   appendSuccessful = true;
> } catch (final InterruptedException e) {
>   LOGGER.warn("Interrupted while waiting for a free slot in the AsyncAppender LogEvent-queue {}",
>   getName());
> }
> {code}
> This will make queue.put throw an InterruptedException and remove the interrupted flag of the current flag.
> I suggest a simple bugfix: Call Thread by Thread.currentThread().interrupt() in the catch clause. This will reset the interrupted flag of the current Thread.
> A more complex bugfix which doesn't loose a message:
> {code:title=AsyncAppender#append() line 153}
> Serializable serialized = Log4jLogEvent.serialize(coreEvent, includeLocation);
> try {
>   // wait for free slots in the queue
>   queue.put(serialized);
>   appendSuccessful = true;
> } catch (final InterruptedException e) {
>   try {
>     // The interrupt is catched and the interrupted flag is unset.
>     // Therefore offer() won't return with an InterruptedException
>     // unless another Thread sends again an interrupt.
>     // Use a timeout to handle the case where the Interrupt e
>     // was really meant for a hanging put() and not just 
>     // coincidently sent at the same time.
>     // If the put() was really hanging,
>     // offer() would return with false after 10ms and no second
>     // external interrupt() is required
>     appendSuccessful = queue.offer(serialized, 10L, TimeUnit.MILLISECONDS);
>   } catch (final InterruptedException e2) {
>     // queue.put is really hanging and someone 
>   }
>   if (!appendSuccessful) {
>     LOGGER.warn("Interrupted while waiting for a free slot in the AsyncAppender LogEvent-queue {}",
>     getName());
>   }
>   // set the interrupted flag again.
>   Thread.currentThread().interrupt();
> }
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org