carterkozak commented on a change in pull request #452: URL: https://github.com/apache/logging-log4j2/pull/452#discussion_r554001403
########## File path: log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppenderEventForwarder.java ########## @@ -0,0 +1,147 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.AppenderControl; +import org.apache.logging.log4j.core.util.Log4jThread; +import org.apache.logging.log4j.status.StatusLogger; + +import java.util.List; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.atomic.AtomicLong; + +class AsyncAppenderEventForwarder extends Log4jThread { + + private static final AtomicLong THREAD_COUNTER = new AtomicLong(0); + + private static final Logger LOGGER = StatusLogger.getLogger(); + + private final AppenderControl errorAppender; + + private final List<AppenderControl> appenders; + + private final BlockingQueue<LogEvent> queue; + + private volatile boolean stopped; + + AsyncAppenderEventForwarder( + final String name, + final AppenderControl errorAppender, + final List<AppenderControl> appenders, + final BlockingQueue<LogEvent> queue) { + super("AsyncAppenderEventForwarder-" + THREAD_COUNTER.incrementAndGet() + "-" + name); + this.errorAppender = errorAppender; + this.appenders = appenders; + this.queue = queue; + this.stopped = false; + } + + @Override + public void run() { + LOGGER.trace("{} has started.", getName()); + forwardAll(); + forwardRemaining(); + } + + private void forwardAll() { + while (!stopped) { + LogEvent event; + try { + event = queue.take(); + } catch (final InterruptedException ignored) { + // Restore the interrupted flag cleared when the exception is caught. + interrupt(); + break; + } + event.setEndOfBatch(queue.isEmpty()); + forwardOne(event); + } + LOGGER.trace("{} has stopped.", getName()); + } + + private void forwardRemaining() { + int eventCount = 0; + while (true) { + // Note the non-blocking Queue#poll() method! + final LogEvent event = queue.poll(); + if (event == null) { + break; + } + event.setEndOfBatch(queue.isEmpty()); + forwardOne(event); + eventCount++; + } + LOGGER.trace( + "{} has processed the last {} remaining event(s).", + getName(), eventCount); + } + + void forwardOne(final LogEvent event) { + + // Forward the event to all registered appenders. + boolean succeeded = false; + // noinspection ForLoopReplaceableByForEach (avoid iterator instantion) + for (int appenderIndex = 0; appenderIndex < appenders.size(); appenderIndex++) { + final AppenderControl control = appenders.get(appenderIndex); + try { + control.callAppender(event); + succeeded = true; + } catch (final Throwable ignored) { + // If no appender is successful, the error appender will get it. + } + } + + // Fallback to the error appender if none has succeeded so far. + if (!succeeded && errorAppender != null) { + try { + errorAppender.callAppender(event); + } catch (final Throwable ignored) { + // If the error appender also fails, there is nothing further + // we can do about it. + } + } + + } + + void stop(final long timeoutMillis) throws InterruptedException { + + // Mark the completion, if necessary. + synchronized (this) { + if (!stopped) { + stopped = true; + LOGGER.trace("{} is signaled to stop.", getName()); + } + } + + // There is a slight chance that the thread is not started yet, wait for + // it to run. Otherwise, interrupt+join might block. + // noinspection StatementWithEmptyBody + while (Thread.State.NEW.equals(getState())); Review comment: I'll take another read through this change today -- happy to defer changes on this part to a separate PR. ########## File path: log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppenderEventDispatcher.java ########## @@ -0,0 +1,172 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.AppenderControl; +import org.apache.logging.log4j.core.impl.Log4jLogEvent; +import org.apache.logging.log4j.core.util.Log4jThread; +import org.apache.logging.log4j.status.StatusLogger; + +import java.util.List; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; + +class AsyncAppenderEventDispatcher extends Log4jThread { + + private static final LogEvent STOP_EVENT = new Log4jLogEvent(); + + private static final AtomicLong THREAD_COUNTER = new AtomicLong(0); + + private static final Logger LOGGER = StatusLogger.getLogger(); + + private final AppenderControl errorAppender; + + private final List<AppenderControl> appenders; + + private final BlockingQueue<LogEvent> queue; + + private final AtomicBoolean stoppedRef; + + AsyncAppenderEventDispatcher( + final String name, + final AppenderControl errorAppender, + final List<AppenderControl> appenders, + final BlockingQueue<LogEvent> queue) { + super("AsyncAppenderEventDispatcher-" + THREAD_COUNTER.incrementAndGet() + "-" + name); + this.errorAppender = errorAppender; + this.appenders = appenders; + this.queue = queue; + this.stoppedRef = new AtomicBoolean(false); + } + + @Override + public void run() { + LOGGER.trace("{} has started.", getName()); + dispatchAll(); + dispatchRemaining(); + } + + private void dispatchAll() { + while (!stoppedRef.get()) { + LogEvent event; + try { + event = queue.take(); + } catch (final InterruptedException ignored) { + // Restore the interrupted flag cleared when the exception is caught. + interrupt(); + break; + } + if (event == STOP_EVENT) { + break; + } + event.setEndOfBatch(queue.isEmpty()); + dispatch(event); + } + LOGGER.trace("{} has stopped.", getName()); + } + + private void dispatchRemaining() { + int eventCount = 0; + while (true) { + // Note the non-blocking Queue#poll() method! + final LogEvent event = queue.poll(); + if (event == null || event == STOP_EVENT) { + break; + } + event.setEndOfBatch(queue.isEmpty()); + dispatch(event); + eventCount++; + } + LOGGER.trace( + "{} has processed the last {} remaining event(s).", + getName(), eventCount); + } + + void dispatch(final LogEvent event) { + + // Dispatch the event to all registered appenders. + boolean succeeded = false; + // noinspection ForLoopReplaceableByForEach (avoid iterator instantion) + for (int appenderIndex = 0; appenderIndex < appenders.size(); appenderIndex++) { + final AppenderControl control = appenders.get(appenderIndex); + try { + control.callAppender(event); + succeeded = true; + } catch (final Throwable error) { + // If no appender is successful, the error appender will get it. + // It is okay to simply log it here. + if (LOGGER.isTraceEnabled()) { + final String message = String.format( + "%s has failed to call appender %s", + getName(), control.getAppenderName()); + LOGGER.trace(message, error); Review comment: nit: I think we can use interpolation curly braces instead of String.format. Same on line 132. ########## File path: log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppenderEventDispatcher.java ########## @@ -0,0 +1,172 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.AppenderControl; +import org.apache.logging.log4j.core.impl.Log4jLogEvent; +import org.apache.logging.log4j.core.util.Log4jThread; +import org.apache.logging.log4j.status.StatusLogger; + +import java.util.List; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; + +class AsyncAppenderEventDispatcher extends Log4jThread { + + private static final LogEvent STOP_EVENT = new Log4jLogEvent(); + + private static final AtomicLong THREAD_COUNTER = new AtomicLong(0); + + private static final Logger LOGGER = StatusLogger.getLogger(); + + private final AppenderControl errorAppender; + + private final List<AppenderControl> appenders; + + private final BlockingQueue<LogEvent> queue; + + private final AtomicBoolean stoppedRef; + + AsyncAppenderEventDispatcher( + final String name, + final AppenderControl errorAppender, + final List<AppenderControl> appenders, + final BlockingQueue<LogEvent> queue) { + super("AsyncAppenderEventDispatcher-" + THREAD_COUNTER.incrementAndGet() + "-" + name); + this.errorAppender = errorAppender; + this.appenders = appenders; + this.queue = queue; + this.stoppedRef = new AtomicBoolean(false); + } + + @Override + public void run() { + LOGGER.trace("{} has started.", getName()); + dispatchAll(); + dispatchRemaining(); + } + + private void dispatchAll() { + while (!stoppedRef.get()) { + LogEvent event; + try { + event = queue.take(); + } catch (final InterruptedException ignored) { + // Restore the interrupted flag cleared when the exception is caught. + interrupt(); + break; + } + if (event == STOP_EVENT) { + break; + } + event.setEndOfBatch(queue.isEmpty()); + dispatch(event); + } + LOGGER.trace("{} has stopped.", getName()); + } + + private void dispatchRemaining() { + int eventCount = 0; + while (true) { + // Note the non-blocking Queue#poll() method! + final LogEvent event = queue.poll(); + if (event == null || event == STOP_EVENT) { Review comment: The previous implementation would allow events that managed to be submitted after the sentinel, but before inputs resulted in a throw to be processed. I think we want a `continue` on `event == STOP_EVENT` rather than `break`. It's not clear that this will make a difference in practice. Continuing to poll after STOP_EVENT doesn't guarantee we record all such events, only if they're already visible in the queue. ########## File path: log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppenderEventDispatcher.java ########## @@ -0,0 +1,172 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.AppenderControl; +import org.apache.logging.log4j.core.impl.Log4jLogEvent; +import org.apache.logging.log4j.core.util.Log4jThread; +import org.apache.logging.log4j.status.StatusLogger; + +import java.util.List; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; + +class AsyncAppenderEventDispatcher extends Log4jThread { + + private static final LogEvent STOP_EVENT = new Log4jLogEvent(); + + private static final AtomicLong THREAD_COUNTER = new AtomicLong(0); + + private static final Logger LOGGER = StatusLogger.getLogger(); + + private final AppenderControl errorAppender; + + private final List<AppenderControl> appenders; + + private final BlockingQueue<LogEvent> queue; + + private final AtomicBoolean stoppedRef; + + AsyncAppenderEventDispatcher( + final String name, + final AppenderControl errorAppender, + final List<AppenderControl> appenders, + final BlockingQueue<LogEvent> queue) { + super("AsyncAppenderEventDispatcher-" + THREAD_COUNTER.incrementAndGet() + "-" + name); + this.errorAppender = errorAppender; + this.appenders = appenders; + this.queue = queue; + this.stoppedRef = new AtomicBoolean(false); + } + + @Override + public void run() { + LOGGER.trace("{} has started.", getName()); + dispatchAll(); + dispatchRemaining(); + } + + private void dispatchAll() { + while (!stoppedRef.get()) { + LogEvent event; + try { + event = queue.take(); + } catch (final InterruptedException ignored) { + // Restore the interrupted flag cleared when the exception is caught. + interrupt(); + break; + } + if (event == STOP_EVENT) { + break; + } + event.setEndOfBatch(queue.isEmpty()); + dispatch(event); + } + LOGGER.trace("{} has stopped.", getName()); + } + + private void dispatchRemaining() { + int eventCount = 0; + while (true) { + // Note the non-blocking Queue#poll() method! + final LogEvent event = queue.poll(); + if (event == null || event == STOP_EVENT) { + break; + } + event.setEndOfBatch(queue.isEmpty()); + dispatch(event); + eventCount++; + } + LOGGER.trace( + "{} has processed the last {} remaining event(s).", + getName(), eventCount); + } + + void dispatch(final LogEvent event) { + + // Dispatch the event to all registered appenders. + boolean succeeded = false; + // noinspection ForLoopReplaceableByForEach (avoid iterator instantion) + for (int appenderIndex = 0; appenderIndex < appenders.size(); appenderIndex++) { + final AppenderControl control = appenders.get(appenderIndex); + try { + control.callAppender(event); + succeeded = true; + } catch (final Throwable error) { + // If no appender is successful, the error appender will get it. + // It is okay to simply log it here. + if (LOGGER.isTraceEnabled()) { + final String message = String.format( + "%s has failed to call appender %s", + getName(), control.getAppenderName()); + LOGGER.trace(message, error); Review comment: I believe as long as there are fewer curly braces than args, and the last arg is a Throwable, it works. (worth a quick validation running locally though). ########## File path: log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppenderEventDispatcher.java ########## @@ -0,0 +1,172 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.AppenderControl; +import org.apache.logging.log4j.core.impl.Log4jLogEvent; +import org.apache.logging.log4j.core.util.Log4jThread; +import org.apache.logging.log4j.status.StatusLogger; + +import java.util.List; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; + +class AsyncAppenderEventDispatcher extends Log4jThread { + + private static final LogEvent STOP_EVENT = new Log4jLogEvent(); + + private static final AtomicLong THREAD_COUNTER = new AtomicLong(0); + + private static final Logger LOGGER = StatusLogger.getLogger(); + + private final AppenderControl errorAppender; + + private final List<AppenderControl> appenders; + + private final BlockingQueue<LogEvent> queue; + + private final AtomicBoolean stoppedRef; + + AsyncAppenderEventDispatcher( + final String name, + final AppenderControl errorAppender, + final List<AppenderControl> appenders, + final BlockingQueue<LogEvent> queue) { + super("AsyncAppenderEventDispatcher-" + THREAD_COUNTER.incrementAndGet() + "-" + name); + this.errorAppender = errorAppender; + this.appenders = appenders; + this.queue = queue; + this.stoppedRef = new AtomicBoolean(false); + } + + @Override + public void run() { + LOGGER.trace("{} has started.", getName()); + dispatchAll(); + dispatchRemaining(); + } + + private void dispatchAll() { + while (!stoppedRef.get()) { + LogEvent event; + try { + event = queue.take(); + } catch (final InterruptedException ignored) { + // Restore the interrupted flag cleared when the exception is caught. + interrupt(); + break; + } + if (event == STOP_EVENT) { + break; + } + event.setEndOfBatch(queue.isEmpty()); + dispatch(event); + } + LOGGER.trace("{} has stopped.", getName()); + } + + private void dispatchRemaining() { + int eventCount = 0; + while (true) { + // Note the non-blocking Queue#poll() method! + final LogEvent event = queue.poll(); + if (event == null || event == STOP_EVENT) { Review comment: > Shouldn't we simply discard anything that is sent after the stop() signal? I think this depends how we define "after" and the "stop signal" ;-) Consider: Thread T1 calls asyncAppender.append with event E T1 checks if the appender is running, this succeeds Thread T2 calls asyncAppender.stop() T2 sets stopped = true T2 submits the STOP_EVENT Thread T1 submits event E to the queue An event is submitted prior to stop, but the STOP_EVENT is received first. Ideally if the event is ignored, we would provide a status message describing that the event was not recorded because the appender was stopped -- events shouldn't disappear, and ideally we don't leave objects (with references to potentially large user-provided parameters) sitting in the queue on heap. That said, continuing to read from the queue after STOP_EVENT doesn't guarantee that we solve the problem (offer may not have been invoked yet!), only makes it less likely that we encounter the race. ########## File path: log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppenderEventDispatcher.java ########## @@ -0,0 +1,172 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache license, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the license for the specific language governing permissions and + * limitations under the license. + */ +package org.apache.logging.log4j.core.appender; + +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.AppenderControl; +import org.apache.logging.log4j.core.impl.Log4jLogEvent; +import org.apache.logging.log4j.core.util.Log4jThread; +import org.apache.logging.log4j.status.StatusLogger; + +import java.util.List; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; + +class AsyncAppenderEventDispatcher extends Log4jThread { + + private static final LogEvent STOP_EVENT = new Log4jLogEvent(); + + private static final AtomicLong THREAD_COUNTER = new AtomicLong(0); + + private static final Logger LOGGER = StatusLogger.getLogger(); + + private final AppenderControl errorAppender; + + private final List<AppenderControl> appenders; + + private final BlockingQueue<LogEvent> queue; + + private final AtomicBoolean stoppedRef; + + AsyncAppenderEventDispatcher( + final String name, + final AppenderControl errorAppender, + final List<AppenderControl> appenders, + final BlockingQueue<LogEvent> queue) { + super("AsyncAppenderEventDispatcher-" + THREAD_COUNTER.incrementAndGet() + "-" + name); + this.errorAppender = errorAppender; + this.appenders = appenders; + this.queue = queue; + this.stoppedRef = new AtomicBoolean(false); + } + + @Override + public void run() { + LOGGER.trace("{} has started.", getName()); + dispatchAll(); + dispatchRemaining(); + } + + private void dispatchAll() { + while (!stoppedRef.get()) { + LogEvent event; + try { + event = queue.take(); + } catch (final InterruptedException ignored) { + // Restore the interrupted flag cleared when the exception is caught. + interrupt(); + break; + } + if (event == STOP_EVENT) { + break; + } + event.setEndOfBatch(queue.isEmpty()); + dispatch(event); + } + LOGGER.trace("{} has stopped.", getName()); + } + + private void dispatchRemaining() { + int eventCount = 0; + while (true) { + // Note the non-blocking Queue#poll() method! + final LogEvent event = queue.poll(); + if (event == null || event == STOP_EVENT) { Review comment: I defer to your judgement whether or not to make a change here, this was meant to elaborate upon the comment and complexities of the scenario. We can make changes separately from this PR even if we decide the behavior should be different :-) ---------------------------------------------------------------- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: [email protected]
