1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17 package org.apache.logging.log4j.core.async;
18
19 import java.util.concurrent.ExecutorService;
20 import java.util.concurrent.Executors;
21 import java.util.concurrent.ThreadFactory;
22
23 import org.apache.logging.log4j.Level;
24 import org.apache.logging.log4j.Logger;
25 import org.apache.logging.log4j.core.LogEvent;
26 import org.apache.logging.log4j.core.impl.Log4jLogEvent;
27 import org.apache.logging.log4j.core.impl.LogEventFactory;
28 import org.apache.logging.log4j.core.impl.MutableLogEvent;
29 import org.apache.logging.log4j.core.impl.ReusableLogEventFactory;
30 import org.apache.logging.log4j.core.jmx.RingBufferAdmin;
31 import org.apache.logging.log4j.message.ReusableMessage;
32 import org.apache.logging.log4j.status.StatusLogger;
33
34 import com.lmax.disruptor.EventFactory;
35 import com.lmax.disruptor.EventTranslatorTwoArg;
36 import com.lmax.disruptor.ExceptionHandler;
37 import com.lmax.disruptor.RingBuffer;
38 import com.lmax.disruptor.Sequence;
39 import com.lmax.disruptor.SequenceReportingEventHandler;
40 import com.lmax.disruptor.WaitStrategy;
41 import com.lmax.disruptor.dsl.Disruptor;
42 import com.lmax.disruptor.dsl.ProducerType;
43
44
45
46
47
48
49
50
51
52
53
54
55
56 public class AsyncLoggerConfigDisruptor implements AsyncLoggerConfigDelegate {
57
58 private static final int MAX_DRAIN_ATTEMPTS_BEFORE_SHUTDOWN = 200;
59 private static final int SLEEP_MILLIS_BETWEEN_DRAIN_ATTEMPTS = 50;
60 private static final Logger LOGGER = StatusLogger.getLogger();
61
62
63
64
65 public static class Log4jEventWrapper {
66 public Log4jEventWrapper() {
67 }
68
69 public Log4jEventWrapper(final MutableLogEvent mutableLogEvent) {
70 event = mutableLogEvent;
71 }
72
73 private AsyncLoggerConfig loggerConfig;
74 private LogEvent event;
75
76
77
78
79 public void clear() {
80 loggerConfig = null;
81 if (event instanceof MutableLogEvent) {
82 ((MutableLogEvent) event).clear();
83 } else {
84 event = null;
85 }
86 }
87
88 @Override
89 public String toString() {
90 return String.valueOf(event);
91 }
92 }
93
94
95
96
97 private static class Log4jEventWrapperHandler implements SequenceReportingEventHandler<Log4jEventWrapper> {
98 private static final int NOTIFY_PROGRESS_THRESHOLD = 50;
99 private Sequence sequenceCallback;
100 private int counter;
101
102 @Override
103 public void setSequenceCallback(final Sequence sequenceCallback) {
104 this.sequenceCallback = sequenceCallback;
105 }
106
107 @Override
108 public void onEvent(final Log4jEventWrapper event, final long sequence, final boolean endOfBatch)
109 throws Exception {
110 event.event.setEndOfBatch(endOfBatch);
111 event.loggerConfig.asyncCallAppenders(event.event);
112 event.clear();
113
114 notifyIntermediateProgress(sequence);
115 }
116
117
118
119
120
121 private void notifyIntermediateProgress(final long sequence) {
122 if (++counter > NOTIFY_PROGRESS_THRESHOLD) {
123 sequenceCallback.set(sequence);
124 counter = 0;
125 }
126 }
127 }
128
129
130
131
132
133 private static final EventFactory<Log4jEventWrapper> FACTORY = new EventFactory<Log4jEventWrapper>() {
134 @Override
135 public Log4jEventWrapper newInstance() {
136 return new Log4jEventWrapper();
137 }
138 };
139
140
141
142
143
144 private static final EventFactory<Log4jEventWrapper> MUTABLE_FACTORY = new EventFactory<Log4jEventWrapper>() {
145 @Override
146 public Log4jEventWrapper newInstance() {
147 return new Log4jEventWrapper(new MutableLogEvent());
148 }
149 };
150
151
152
153
154 private static final EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> TRANSLATOR =
155 new EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig>() {
156
157 @Override
158 public void translateTo(final Log4jEventWrapper ringBufferElement, final long sequence,
159 final LogEvent logEvent, final AsyncLoggerConfig loggerConfig) {
160 ringBufferElement.event = logEvent;
161 ringBufferElement.loggerConfig = loggerConfig;
162 }
163 };
164
165
166
167
168 private static final EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> MUTABLE_TRANSLATOR =
169 new EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig>() {
170
171 @Override
172 public void translateTo(final Log4jEventWrapper ringBufferElement, final long sequence,
173 final LogEvent logEvent, final AsyncLoggerConfig loggerConfig) {
174 ((MutableLogEvent) ringBufferElement.event).initFrom(logEvent);
175 ringBufferElement.loggerConfig = loggerConfig;
176 }
177 };
178
179 private static final ThreadFactory THREAD_FACTORY = new DaemonThreadFactory("AsyncLoggerConfig-");
180
181 private int ringBufferSize;
182 private AsyncQueueFullPolicy asyncQueueFullPolicy;
183 private Boolean mutable = Boolean.FALSE;
184
185 private volatile Disruptor<Log4jEventWrapper> disruptor;
186 private ExecutorService executor;
187 private long backgroundThreadId;
188 private EventFactory<Log4jEventWrapper> factory;
189 private EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> translator;
190
191 public AsyncLoggerConfigDisruptor() {
192 }
193
194
195 @Override
196 public void setLogEventFactory(final LogEventFactory logEventFactory) {
197
198
199 this.mutable = mutable || (logEventFactory instanceof ReusableLogEventFactory);
200 }
201
202
203
204
205
206
207
208 public synchronized void start() {
209 if (disruptor != null) {
210 LOGGER.trace("AsyncLoggerConfigDisruptor not starting new disruptor for this configuration, "
211 + "using existing object.");
212 return;
213 }
214 LOGGER.trace("AsyncLoggerConfigDisruptor creating new disruptor for this configuration.");
215 ringBufferSize = DisruptorUtil.calculateRingBufferSize("AsyncLoggerConfig.RingBufferSize");
216 final WaitStrategy waitStrategy = DisruptorUtil.createWaitStrategy("AsyncLoggerConfig.WaitStrategy");
217 executor = Executors.newSingleThreadExecutor(THREAD_FACTORY);
218 backgroundThreadId = DisruptorUtil.getExecutorThreadId(executor);
219 asyncQueueFullPolicy = AsyncQueueFullPolicyFactory.create();
220
221 translator = mutable ? MUTABLE_TRANSLATOR : TRANSLATOR;
222 factory = mutable ? MUTABLE_FACTORY : FACTORY;
223 disruptor = new Disruptor<>(factory, ringBufferSize, executor, ProducerType.MULTI, waitStrategy);
224
225 final ExceptionHandler<Log4jEventWrapper> errorHandler = DisruptorUtil.getAsyncLoggerConfigExceptionHandler();
226 disruptor.handleExceptionsWith(errorHandler);
227
228 final Log4jEventWrapperHandler[] handlers = {new Log4jEventWrapperHandler()};
229 disruptor.handleEventsWith(handlers);
230
231 LOGGER.debug("Starting AsyncLoggerConfig disruptor for this configuration with ringbufferSize={}, "
232 + "waitStrategy={}, exceptionHandler={}...", disruptor.getRingBuffer().getBufferSize(), waitStrategy
233 .getClass().getSimpleName(), errorHandler);
234 disruptor.start();
235 }
236
237
238
239
240
241 public synchronized void stop() {
242 final Disruptor<Log4jEventWrapper> temp = disruptor;
243 if (temp == null) {
244 LOGGER.trace("AsyncLoggerConfigDisruptor: disruptor for this configuration already shut down.");
245 return;
246 }
247 LOGGER.trace("AsyncLoggerConfigDisruptor: shutting down disruptor for this configuration.");
248
249
250 disruptor = null;
251
252
253
254
255 for (int i = 0; hasBacklog(temp) && i < MAX_DRAIN_ATTEMPTS_BEFORE_SHUTDOWN; i++) {
256 try {
257 Thread.sleep(SLEEP_MILLIS_BETWEEN_DRAIN_ATTEMPTS);
258 } catch (final InterruptedException e) {
259 }
260 }
261 temp.shutdown();
262
263 LOGGER.trace("AsyncLoggerConfigDisruptor: shutting down disruptor executor for this configuration.");
264 executor.shutdown();
265 executor = null;
266
267 if (DiscardingAsyncQueueFullPolicy.getDiscardCount(asyncQueueFullPolicy) > 0) {
268 LOGGER.trace("AsyncLoggerConfigDisruptor: {} discarded {} events.", asyncQueueFullPolicy,
269 DiscardingAsyncQueueFullPolicy.getDiscardCount(asyncQueueFullPolicy));
270 }
271 }
272
273
274
275
276 private static boolean hasBacklog(final Disruptor<?> theDisruptor) {
277 final RingBuffer<?> ringBuffer = theDisruptor.getRingBuffer();
278 return !ringBuffer.hasAvailableCapacity(ringBuffer.getBufferSize());
279 }
280
281 @Override
282 public EventRoute getEventRoute(final Level logLevel) {
283 final int remainingCapacity = remainingDisruptorCapacity();
284 if (remainingCapacity < 0) {
285 return EventRoute.DISCARD;
286 }
287 return asyncQueueFullPolicy.getRoute(backgroundThreadId, logLevel);
288 }
289
290 private int remainingDisruptorCapacity() {
291 final Disruptor<Log4jEventWrapper> temp = disruptor;
292 if (hasLog4jBeenShutDown(temp)) {
293 return -1;
294 }
295 return (int) temp.getRingBuffer().remainingCapacity();
296 }
297
298
299
300
301 private boolean hasLog4jBeenShutDown(final Disruptor<Log4jEventWrapper> aDisruptor) {
302 if (aDisruptor == null) {
303 LOGGER.warn("Ignoring log event after log4j was shut down");
304 return true;
305 }
306 return false;
307 }
308
309 @Override
310 public void enqueueEvent(final LogEvent event, final AsyncLoggerConfig asyncLoggerConfig) {
311
312 try {
313 final LogEvent logEvent = prepareEvent(event);
314 enqueue(logEvent, asyncLoggerConfig);
315 } catch (final NullPointerException npe) {
316
317
318 LOGGER.warn("Ignoring log event after log4j was shut down.");
319 }
320 }
321
322 private LogEvent prepareEvent(final LogEvent event) {
323 final LogEvent logEvent = ensureImmutable(event);
324 if (logEvent instanceof Log4jLogEvent && logEvent.getMessage() instanceof ReusableMessage) {
325 ((Log4jLogEvent) logEvent).makeMessageImmutable();
326 }
327 return logEvent;
328 }
329
330 private void enqueue(final LogEvent logEvent, final AsyncLoggerConfig asyncLoggerConfig) {
331 disruptor.getRingBuffer().publishEvent(translator, logEvent, asyncLoggerConfig);
332 }
333
334 @Override
335 public boolean tryEnqueue(final LogEvent event, final AsyncLoggerConfig asyncLoggerConfig) {
336 final LogEvent logEvent = prepareEvent(event);
337 return disruptor.getRingBuffer().tryPublishEvent(translator, logEvent, asyncLoggerConfig);
338 }
339
340 private LogEvent ensureImmutable(final LogEvent event) {
341 LogEvent result = event;
342 if (event instanceof RingBufferLogEvent) {
343
344
345
346
347
348
349 result = ((RingBufferLogEvent) event).createMemento();
350 }
351 return result;
352 }
353
354
355
356
357
358
359
360 @Override
361 public RingBufferAdmin createRingBufferAdmin(final String contextName, final String loggerConfigName) {
362 return RingBufferAdmin.forAsyncLoggerConfig(disruptor.getRingBuffer(), contextName, loggerConfigName);
363 }
364 }