qos-ch / reload4j

reload4j is a drop-in replacement for log4j 1.2.17
Apache License 2.0
148 stars 22 forks source link

Performance improvement in Category callAppenders() #51

Open lauredogit opened 2 years ago

lauredogit commented 2 years ago

Hi,

We just got a bottleneck in production with 2000+ threads blocked waiting on the lock in the synchronized block of callAppenders() in Category.

This never happend before to us, including in stress tests.

However, I seem to think a small performance improvement could be made with a simple open call (if I'm reading the code correctly).

    public void callAppenders(LoggingEvent event) {
    int writes = 0;

    for (Category c = this; c != null; c = c.parent) {
        // Protected against simultaneous call to addAppender, removeAppender,...
        // open call, read the values under lock:
        AppenderAttachableImpl aai;
        boolean additive;
        synchronized (c) {
            aai = c.aai;
            additive = c.additive;
        }
        // open call
        if (aai != null) {
            writes += aai.appendLoopOnAppenders(event);
        }
        if (!additive) {
            break;
        }
    }

Since aai is final and is a thread-safe data structure, we only want correct visibility of the aai and additive fields and we don't need to block the whole category object while calling appendLoopOnAppenders.

What do you think?

Best regards, Dominique

ceki commented 2 years ago

@lauredogit Which version of reload4j are you using?

lauredogit commented 2 years ago

Production was using in 1.2.20.

lauredogit commented 2 years ago

It appears the threads were piling up due to slowness induced by a remote diagnostic agent running at the time (RDA).

It is strange that it materialized by showing a bottleneck in the synchronized block of Category#callAppenders().

Nonetheless, it might be a performance improvement to use an open call to invoke the appendLoopOnAppenders(...) method instead of doing it while holding the lock.