<html><head><meta http-equiv="content-type" content="text/html; charset=utf-8"></head><body dir="auto"><div>Very interesting. </div><div><br></div><div>This link in the page gives a 404: <a href="http://laforge49.github.io/JActor2/tutorials/core/gettingStarted.html">http://laforge49.github.io/JActor2/tutorials/core/gettingStarted.html</a><br><br>David</div><div><br>On 7 Mar 2014, at 06:42, champion <<a href="mailto:champion@163.com">champion@163.com</a>> wrote:<br><br></div><blockquote type="cite"><div>
<meta content="text/html; charset=utf-8" http-equiv="Content-Type">
<style>
BLOCKQUOTE {
MARGIN-TOP: 0px; MARGIN-BOTTOM: 0px; MARGIN-LEFT: 2em
}
OL {
MARGIN-TOP: 0px; MARGIN-BOTTOM: 0px
}
UL {
MARGIN-TOP: 0px; MARGIN-BOTTOM: 0px
}
DIV.FoxDiv20140307144001643047 {
COLOR: #000000
}
P {
MARGIN-TOP: 0px; MARGIN-BOTTOM: 0px
}
BODY {
LINE-HEIGHT: 1.5; FONT-FAMILY: 微软雅黑; COLOR: #000000; FONT-SIZE: 10.5pt
}
</style>
<meta name="GENERATOR" content="MSHTML 9.00.8112.16533">
<div>I've writen a faster AsyncAppender which use disruptor,and run
stable in my project for years.the source is at <a href="https://github.com/cp149/jactor-logger">https://github.com/cp149/jactor-logger</a>,
Maybe it can give you some help.</div>
<div> </div>
<hr style="WIDTH: 210px; HEIGHT: 1px" align="left" color="#b5c4df" size="1">
<div><span>champion</span></div>
<div> </div>
<div style="BORDER-BOTTOM: medium none; BORDER-LEFT: medium none; PADDING-BOTTOM: 0cm; PADDING-LEFT: 0cm; PADDING-RIGHT: 0cm; BORDER-TOP: #b5c4df 1pt solid; BORDER-RIGHT: medium none; PADDING-TOP: 3pt">
<div style="PADDING-BOTTOM: 8px; PADDING-LEFT: 8px; PADDING-RIGHT: 8px; FONT-FAMILY: tahoma; BACKGROUND: #efefef; COLOR: #000000; FONT-SIZE: 12px; PADDING-TOP: 8px">
<div><b>From:</b> <a href="mailto:mike@coursescheduler.io">Michael
Reinhold</a></div>
<div><b>Date:</b> 2014-03-07 02:48</div>
<div><b>To:</b> <a href="mailto:logback-user@qos.ch">logback users
list</a></div>
<div><b>Subject:</b> Re: [logback-user] AsyncAppenderBase not flushing
queue during JVM shutdown</div></div></div>
<div>
<div style="BACKGROUND-COLOR: white" class="FoxDiv20140307144001643047">
<div dir="ltr">Hi David, Chris,
<div><br></div>
<div>Thanks for the feedback. In the test case that I ran with the
AsyncAppender, LoggerContext.stop did not wait for the async appender to finish
flushing before exiting - the stop method returned immediately. I just retested
this scenario to be sure. My test should generate exactly 135 log events (also
going to a local file appender, so I can confirm that entries are present or
missing). Without the async appender I get all of the expected events (at much
lower throughput); with the async appender (using the call to LoggerContext.stop
prior to exiting) I get a variable number (generally less than 20 events). It's
possible that the lower latency of flushing to local files results in the async
appender being able to flush completely to disk before the JVM exits, whereas
the latency to Loggly is just too high. Queue size probably also has an impact -
I allow for a fairly large queue because the penalty of falling back to
synchronous logging for Loggly is large and my logging tends to come in
bursts.</div>
<div><br></div>
<div>If stop() did wait for async appenders to flush, that would improve the
situation. Although the use-case that involves shutdown hooks that want to log
would still need to be addressed. The only way that I can see that does address
allowing shutdown hooks to log is via a queue flushing shutdown hook (requiring
a call to LoggerContext.stop won't help for shutdown hooks or applications that
use JVM implicit shutdowns). My opinion is that a shutdown hook can satisfy both
needs with minimal impact to other classes or semantics on how
LoggerContext.stop functions. One hook per async appender would be simple to
implement and would also allow for parallel flushing of async appender
queues.<br></div>
<div><br></div>
<div>A default shutdown timeout as you described makes sense to me and fits with
what I was thinking for implementation of a shutdown hook.</div>
<div><br></div>
<div>I could probably throw together a quick and dirty implementation tonight as
a proof of concept. Thoughts?</div>
<div><br></div>
<div>Regards,</div>
<div><br></div>
<div>Mike Reinhold</div>
<div><br></div></div>
<div class="gmail_extra"><br><br>
<div class="gmail_quote">On Thu, Mar 6, 2014 at 1:01 PM, Chris Pratt <span dir="ltr"><<a href="mailto:thechrispratt@gmail.com" target="_blank">thechrispratt@gmail.com</a>></span> wrote:<br>
<blockquote style="BORDER-LEFT: #ccc 1px solid; MARGIN: 0px 0px 0px 0.8ex; PADDING-LEFT: 1ex" class="gmail_quote">
<div dir="ltr">Another option might be to require calling the LoggerContext.stop
when using AsyncAppender's. The stop method could signal to the
AsyncAppenders that they should drain their queue's and exit, which would
allow the application to shut down naturally (if the AsyncAppenders aren't
started as demon's)<span class="HOEnZb"><font color="#888888">
<div> (*Chris*)</div></font></span></div>
<div class="HOEnZb">
<div class="h5">
<div class="gmail_extra"><br><br>
<div class="gmail_quote">On Thu, Mar 6, 2014 at 9:55 AM, David Roussel <span dir="ltr"><<a href="mailto:nabble@diroussel.xsmail.com" target="_blank">nabble@diroussel.xsmail.com</a>></span> wrote:<br>
<blockquote style="BORDER-LEFT: #ccc 1px solid; MARGIN: 0px 0px 0px 0.8ex; PADDING-LEFT: 1ex" class="gmail_quote">
<div>
<div>Mike,</div>
<div><br></div>
<div>I would expect the shutdown of logback to wait for async appenders to
drain their queues before we can consider the shutdown down. </div>
<div><br></div>
<div>I have used async appenders to provide faster logging when writing to
local files. And that's what I expected happens. </div>
<div><br></div>
<div>Of course there is the problem of waiting for too long. How about an
async appender has a default shutdown timeout which can be overridden by
config. So it can wait 2 seconds by default, but can be overridden to 30
seconds for the loggly usecase. </div>
<div><br></div>
<div>The simple solution is to put this all in AsyncAppender(Base), but if
we want to allow multiple async appenders to shutdown in parallel, then the
fix might involve more changes. <span><font color="#888888"><br><br>David</font></span></div>
<div>
<div>
<div><br>On 6 Mar 2014, at 12:51, Michael Reinhold <<a href="mailto:mike@coursescheduler.io" target="_blank">mike@coursescheduler.io</a>> wrote:<br><br></div>
<blockquote type="cite">
<div>
<div dir="ltr">Hi David,
<div><br></div>
<div>I forgot to mention this in my original note and it is a good
thought, but yes I have tried to cleanly shutdown Logback. Even when the
LogbackContext stop method is invoked prior to JVM exit, the async queue
is not flushed completely. When Logback is stopped cleanly, the async
worker thread exits the "waiting for events in the queue" while loop and
moves on to the "flush remaining elements from the queue" for loop
(confirmed by the info message when debug is enabled and via breakpoint).
Ultimately, because the thread is a daemon thread - this process is still
interrupted by JVM shutdown. There is no guarantee that the async worker
will get enough time to process all events.</div>
<div><br></div>
<div>From a theoretical standpoint, stopping Logback properly does not
solve flushing issues with the AsycAppender in a number of cases (it may
be fair to argue that it should not attempt to cover all of these
cases):</div>
<div>
<ul>
<li>Queue is relatively full or wrapped appender latency is high - the
async worker may not be able to finish processing the queued items
between when the LogbackContext.stop method is invoked and when the JVM
actually exits
</li><li>Implicit JVM exit upon end of last user thread - some applications
don't explicitly call System.exit but rather rely on implicit JVM exit.
In that case, where would you cleanly shutdown Logback? It can probably
be done, but would require an application redesign to avoid reliance on
implicit exit or some form of thread tracking thread.
</li><li>Shutdown hooks are used to clean up resources - some applications
have components or modules that need to clean up after themselves when
the JVM shuts down. Typically, shutdown hooks are used for this purpose,
however the AsyncAppender's worker thread is unable to process queued
events after shutdown has been initiated (while the shutdown hooks are
running). This also prevents shutdown hooks from being able to log
events
</li><li>Signal handling on *nix systems - signals can be sent to the
application for a number of reasons, most often to request graceful
shutdown or to terminate something that is non-responsive. If the signal
corresponds to something that generally means "graceful shutdown" on the
host system, normal cleanup routines should execute in the application
(typically implemented as shutdown hooks, so maybe this is the same as
the previous one). </li></ul>
<div>From a practical standpoint, I am running into the first and the
third scenarios. Even shutting down cleanly, the latency and queue depth
can cause elements to be missed; additionally, I have shutdown hooks that
clean up resources and expect the ability to log events and
errors.</div></div>
<div><br></div>
<div>My thought is that a modified AsyncAppenderBase implementation could
(optionally) install a shutdown hook that continues watching the queue for
new events. A configurable "queue idle time" could be used to tell the
shutdown hook that it has probably caught all events and can safely
shutdown (not foolproof, I'm still thinking about other ways of handling
it). Additionally, the hook could have a configurable "max processing
time" so that it doesn't keep the JVM alive for an undesirable amount of
time (thinking in the context of automation software where shutdown
requests typically have a max execution time before they are considered as
"failed online").</div>
<div><br></div>
<div>I hope this helps clarify the scenario I am considering and a
proposed solution!</div>
<div><br></div>
<div>Regards,</div>
<div><br></div>
<div>Mike Reinhold</div></div>
<div class="gmail_extra"><br><br>
<div class="gmail_quote">On Wed, Mar 5, 2014 at 5:30 PM, David Roussel <span dir="ltr"><<a href="mailto:nabble@diroussel.xsmail.com" target="_blank">nabble@diroussel.xsmail.com</a>></span> wrote:<br>
<blockquote style="BORDER-LEFT: #ccc 1px solid; MARGIN: 0px 0px 0px 0.8ex; PADDING-LEFT: 1ex" class="gmail_quote">
<div>
<div>Did you try shutting down logback cleanly. Like this <a href="http://stackoverflow.com/questions/3678755/do-i-need-to-flush-events-when-shutting-down-using-logback" target="_blank">http://stackoverflow.com/questions/3678755/do-i-need-to-flush-events-when-shutting-down-using-logback</a><br><br>David</div>
<div>
<div>
<div><br>On 5 Mar 2014, at 20:44, Michael Reinhold <<a href="mailto:mike@coursescheduler.io" target="_blank">mike@coursescheduler.io</a>> wrote:<br><br></div>
<blockquote type="cite">
<div>
<div dir="ltr">
<div dir="ltr">
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">Hi
Ceki, </div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">I am
currently using the AsyncAppender in combination with the
LogglyAppender from the Logback extensions project. While working on a
number of aspects of my application, I found that I was not
consistently getting all of the log messages that I expected. In
particular, when the application shuts down immediately (or very
shortly) after a burst of logging activity, the tail of those log
events is often not present in Loggly. From a number of tests, this
issue is not restricted to use with the LogglyAppender, but is simply
more evident because of the latency involved.</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">Looking
through the source code for the AsyncAppenderBase, I saw the
following:</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">You create
the Async sender thread as a Daemon thread</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">addInfo("Setting
discardingThreshold to " + discardingThreshold);</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
worker.setDaemon(true);</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
worker.setName("AsyncAppender-Worker-" +
worker.getName());</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
// make sure this instance is marked as "started" before
staring the worker Thread</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
super.start();</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
worker.start();</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">In the
sender thread, if you determine that the parent thread has stopped or
the async sender thread has been interrupted, you allow the worker
thread to flush remaining log events in the queue.</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">while
(parent.isStarted()) {</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
try {</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
E e = parent.blockingQueue.take();</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
aai.appendLoopOnAppenders(e);</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
} catch (InterruptedException ie) {</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
break;</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
}</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
}</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
addInfo("Worker thread will flush remaining events
before exiting. ");</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
for (E e : parent.blockingQueue) {</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
aai.appendLoopOnAppenders(e);</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
}</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">
aai.detachAndStopAllAppenders();</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">From what
I can tell, during JVM shutdown (for a standalone SE instance, the
same is probably not true for EE instances with application servers)
daemon threads may be terminated without allowing the the
AsyncAppenderBase to escape the while loop and proceed onto the queue
flush for loop. </div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">From Brian
Goetz in Java Concurrency in Practice:</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">"When a
thread exits, the JVM performs an inventory of running threads, and if
the only threads that are left are daemon threads, it initiates an
orderly shutdown. When the JVM halts, any remaining daemon threads are
abandoned finally blocks are not executed, stacks are not unwound the
JVM just exits. Daemon threads should be used sparingly few processing
activities can be safely abandoned at any time with no cleanup. In
particular, it is dangerous to use daemon threads for tasks that might
perform any sort of I/O. Daemon threads are best saved for
"housekeeping" tasks, such as a background thread that periodically
removes expired entries from an in-memory cache."</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">To test
this, I inserted a break point in the AsyncAppenderBase at the call to
addInfo and ran a variety of different scenarios. At no point in time
was I able to get the breakpoint to stop at the addInfo
line. </div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">I don't
think there are any clear cut solutions to this. Making the worker
thread a user thread instead of daemon thread has its own
implications, particularly that if all other user threads have exited
the async threads would keep the JVM instance alive (unless
System.exit has been called, in which case I believe that you will
still have lost log events even if the async processing thread is not
a daemon). It might be possible to create a shutdown hook that does
the queue flushing for the async worker - though you may need to
consider the possibility of other shutdown hooks wanting to log events
as well.</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">I'm
currently mocking up a version of the AsyncAppenderBase and
AsyncAppender that installs a shutdown hook as described previously. I
think a "queue idle time" configuration might be the best way to
handle other shutdown hooks adding log events (aka - after processing
whatever was in the queue, if no new events are added
within <i><b>x</b></i> ms then the shutdown hook can assume
nothing else will be adding log events and can exit). An
alternative might be to have the shutdown hook query the ThreadMXBean
API to determine if other shutdown hooks are still executing and
possibly adding log events (though the threads that are expected to be
running during shutdown may be not only application specific but also
JVM implementation specific... I'm not sure).</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">Let me
know what you think. I'll let you know if I feel that my mockup may be
viable...</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">Regards,</div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px"><br></div>
<div style="FONT-FAMILY: arial,sans-serif; FONT-SIZE: 13px">Mike
Reinhold</div>
<div><br></div></div></div></div></blockquote></div></div>
<blockquote type="cite">
<div><span>_______________________________________________</span><br><span>Logback-user
mailing list</span><br><span><a href="mailto:Logback-user@qos.ch" target="_blank">Logback-user@qos.ch</a></span><br><span><a href="http://mailman.qos.ch/mailman/listinfo/logback-user" target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a></span></div></blockquote></div><br>_______________________________________________<br>Logback-user
mailing list<br><a href="mailto:Logback-user@qos.ch" target="_blank">Logback-user@qos.ch</a><br><a href="http://mailman.qos.ch/mailman/listinfo/logback-user" target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a><br></blockquote></div><br></div></div></blockquote>
<blockquote type="cite">
<div><span>_______________________________________________</span><br><span>Logback-user
mailing list</span><br><span><a href="mailto:Logback-user@qos.ch" target="_blank">Logback-user@qos.ch</a></span><br><span><a href="http://mailman.qos.ch/mailman/listinfo/logback-user" target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a></span></div></blockquote></div></div></div><br>_______________________________________________<br>Logback-user
mailing list<br><a href="mailto:Logback-user@qos.ch" target="_blank">Logback-user@qos.ch</a><br><a href="http://mailman.qos.ch/mailman/listinfo/logback-user" target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a><br></blockquote></div><br></div></div></div><br>_______________________________________________<br>Logback-user
mailing list<br><a href="mailto:Logback-user@qos.ch">Logback-user@qos.ch</a><br><a href="http://mailman.qos.ch/mailman/listinfo/logback-user" target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a><br></blockquote></div><br></div></div></div>
</div></blockquote><blockquote type="cite"><div><span>_______________________________________________</span><br><span>Logback-user mailing list</span><br><span><a href="mailto:Logback-user@qos.ch">Logback-user@qos.ch</a></span><br><span><a href="http://mailman.qos.ch/mailman/listinfo/logback-user">http://mailman.qos.ch/mailman/listinfo/logback-user</a></span></div></blockquote></body></html>