[logback-dev] synchronization style?

[Joern Huxhorn]

Ceki Gulcu wrote:
>
>
> Joern Huxhorn wrote:
>
>> Nope, a discussion like that is really necessary because this whole
>> issue is pretty crucial and will essentially decide how well Logback
>> will perform in environments with >1 CPU-cores.
>> This will become more and more important with more cores added in every
>> new CPU generation. The more cores are present, the more relevant the
>> issue of unfairness will become, since waiting threads will  mean idling
>> CPUs.
>
> While open to further investigation and new data, evidence collected
> indicates that threads in Sun's JDK on multi-core CPU
> on Linux as well as other platforms can make other threads
> starve but that is *not* a logback issue. Moreover, it would be unfair to
> penalize *all* logback users using fair locking which is much slower
> than synchronization or unfair locks.
>
I copied your results over from your test for the sake of discussion:
java.runtime.version = 1.6.0_11-b03
java.vendor          = Sun Microsystems Inc.
java.version         = 1.6.0_11
os.name              = Linux
os.version           = 2.6.25-gentoo-r6
Sync:   139698775, or 35 nanos per cycle
Unfair: 87028802, or 57 nanos per cycle
Fair:   4106449, or 1217 nanos per cycle

java.runtime.version = jvmxa6460-20081105_25433
java.vendor          = IBM Corporation
java.version         = 1.6.0
os.name              = Linux
os.version           = 2.6.25-gentoo-r6
Sync:   356946629, or 14 nanos per cycle
Unfair: 91892449, or 54 nanos per cycle
Fair:   7380308, or 677 nanos per cycle

So yes, the locking itself is significantly slower.

The following numbers are the max amount of wasted time of my example app:
2959018000 synchronized
2078606000 unfair lock
27691000 fair lock
The maximum wasted time of all threads is ~100 times smaller in case of
the fair lock!! This means that the overall system is running *waaay*
smoother... regardless of the additional nanos spent for the fair lock.
The main problem is that *every* CPU has to access the appender,
degrading multi-core-systems to semi-single-core.
Minimizing the amount of time a thread (and therefore one of the other
cores) has to wait is crucial.
> As a side note, and if my memory serves me well, you gather caller
> data for every log call which can have significant impact on
> performance. Are you collecting caller data?
Yes, I do, but performance was absolutely sufficient on a single-core
system - which is quite ironic. Let's just forget about my appender for
the moment. The behavior is similar but less dramatic in case of
FileAppender.

Regards,
Joern.