[
http://jira.qos.ch/browse/LBCORE-97?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=11152#action_11152
]
Ceki Gulcu commented on LBCORE-97:
----------------------------------
> As I said before, this does happen with just a simple
> RollingFileAppender in place, too. This may be caused by some huge
> debug messages but this shouldn't be able to render the whole
> application unusable.
Writing a very large log message will obviously take time. Since
RollingAppender writes only one message at a time, it is natural for other
threads wishing to access RollingAppender to queue, regardless of the fairness
policy.
> Starvation on AppenderBase.doAppend
> -----------------------------------
>
> Key: LBCORE-97
> URL: http://jira.qos.ch/browse/LBCORE-97
> Project: logback-core
> Issue Type: Bug
> Components: Appender
> Affects Versions: 0.9.15
> Reporter: Joern Huxhorn
> Assignee: Logback dev list
> Priority: Critical
> Attachments: AppenderBaseLock2.patch,
> Suggested_change_of_documentation.patch, SynchronizedVsFairLock.java
>
>
> The problem we are facing here is that several threads are trying to obtain
> the object monitor of the exact same resource, namely the Appender.
> The assumption that multiple threads waiting for ownership of a monitor would
> receive the monitor in the order that they tried to acquire it is simply
> incorrect. This is documented behavior.
> See the last paragraph of [1]:
> "Likewise, no assumptions should be made about the order in which threads are
> granted ownership of a monitor or the order in which threads wake in response
> to the notify or notifyAll method. An excellent reference for these topics is
> Chapter 9, "Threads," in Joshua Bloch's book Effective Java Programming
> Language Guide. "
> The documentation of Object.notifyAll() [2] states the following:
> "[..] The awakened threads will compete in the usual manner with any other
> threads that might be actively competing to synchronize on this object; for
> example, the awakened threads enjoy no reliable privilege or disadvantage in
> being the next thread to lock this object."
> The documentation in [5] also lists the following as a weak-spot of Built-in
> Synchronization in J2SE 1.4.x:
> "No way to alter the semantics of a lock, for example, with respect to
> reentrancy, read versus write protection, or fairness."
> In LBCORE-96 Ceki stated the following:
> "Logback is using the standard synchronization mechanism found in the JDK.
> You are saying that that mechanism is unsuitable which, truth be told, sounds
> quite suspicious."
> Yes, it's unsuitable in this situation because obtaining the object monitor
> is not guaranteed to be fair. It's not working in a "first come, first serve"
> manner. I assumed that, too, but it isn't the case. I had the exact same
> problem in Lilith some time ago because I made exactly this very same wrong
> assumption.
> Fairness of object monitor lock acquisition seems to be logical and a "good
> thing" but it's not specified that way, and for good reasons.
> Without fairness in place, the VM can optimize the execution of an
> application much better. A context switch is a costly operation for a CPU so
> performance is increased significantly if such a switch can be omitted.
> Concerning a test-case, this would be pretty hardcore to implement since it's
> 100% implementation dependent. One implementation *may* handle the locking of
> object monitors fairly while others don't.
> Therefore I'll try the following first:
> I assume I could convince you that object monitor acquisition (OMA) is not
> fair.
> If we take that for granted the following scenario should show my point:
> There are 4 Threads (e.g. 4 Threads handling concurrent webapp-requests) that
> have one single chokepoint, the appender.
> Since OMA isn't fair, it's possible that only some of those threads can work
> at all (see [3]). Exactly that is happening right now in our webapp running
> on a 4-core Solaris on JDK6.
> My next assumption is that we both agree that this isn't acceptable behavior.
> Logging should be handled "first come, first served" so that if Thread A is
> waiting to append an event and Thread B is waiting to append an event
> subsequently, the actual appending order should be A, then B.
> This is currently not the case. It *may* be the case but there is no
> guarantee of it.
> One could even argue that the logging system is working incorrectly (aside
> from the starvation problem) because events are appended in a different order
> than the actual execution of the logger call.
> The only way to prevent this is the introduction of fairness into the locking
> process. The way to do this is to use ReentrantLock [4].
> From the ReentrantLock javadoc:
> "The constructor for this class accepts an optional fairness parameter. When
> set true, under contention, locks favor granting access to the
> longest-waiting thread. Otherwise this lock does not guarantee any particular
> access order. Programs using fair locks accessed by many threads may display
> lower overall throughput (i.e., are slower; often much slower) than those
> using the default setting, but have smaller variances in times to obtain
> locks and guarantee lack of starvation."
> This is exactly what is absolutely necessary for a logging framework.
> Logging must *NOT* be able to introduce a starvation problem into a
> multi-threaded application! And it does exactly that right now.
> I doubt that the performance will decrease in a significant manner due to the
> use of a fair ReentrantLock but even if this would be the case it would be
> necessary anyway.
> Otherwise, appending simply isn't working correctly.
> [1] http://java.sun.com/j2se/1.5.0/docs/guide/vm/thread-priorities.html
> [2] http://java.sun.com/javase/6/docs/api/java/lang/Object.html#notifyAll()
> [3] http://en.wikipedia.org/wiki/Starvation_(computing)
> [4]
> http://java.sun.com/javase/6/docs/api/java/util/concurrent/locks/ReentrantLock.html
> [5] http://java.sun.com/developer/technicalArticles/J2SE/concurrency/
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://jira.qos.ch/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
_______________________________________________
logback-dev mailing list
[email protected]
http://qos.ch/mailman/listinfo/logback-dev
