You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by Remko Popma <re...@gmail.com> on 2015/09/12 20:19:24 UTC
LoggerConfig improvement
I want to run this by you:
LoggerConfig currently always takes a lock after logging a log event.
Within this lock it checks if the shutdown flag has been set.
Can we do it the other way around? First check if the shutdown flag has
been set and then take the lock (to notify the other thread)?
I think it is safe to do this:
public void log(final LogEvent event) {
counter.incrementAndGet();
try {
if (!isFiltered(event)) {
processLogEvent(event);
}
} finally {
// FIRST update counter, THEN check shutdown flag;
// these are atomic and will not get re-ordered.
// So we don't need the lock to check the shutdown flag.
if (counter.decrementAndGet() == 0 && shutdown.get()) {
// ONLY take the lock if the shutdown flag was set
shutdownLock.lock();
try {
noLogEvents.signalAll(); // lock required to call signal()
} finally {
shutdownLock.unlock();
}
}
}
}
// keep this method unchanged
private void waitForCompletion() {
shutdownLock.lock();
try {
// NOTE: FIRST the shutdown flag is set
if (shutdown.compareAndSet(false, true)) {
int retries = 0;
// NOTE: THEN the counter is read
while (counter.get() > 0) {
try {
noLogEvents.await(retries + 1, TimeUnit.SECONDS);
} catch (final InterruptedException ie) {
if (++retries > MAX_RETRIES) {
break;
}
}
}
}
} finally {
shutdownLock.unlock();
}
}
Re: LoggerConfig improvement
Posted by Remko Popma <re...@gmail.com>.
Yes, especially AbstractConfiguration.stop() has changed a few times since
AsyncLoggers were introduced.
LoggerConfig.waitForCompletion() predates those changes; that would explain
it.
On Sun, Sep 13, 2015 at 1:23 PM, Ralph Goers <ra...@dslextreme.com>
wrote:
> I would have to go back and look at the code again. I remember having to
> implement that to shutdown properly but I suppose things could have changed
> since then.
>
> Ralph
>
> On Sep 12, 2015, at 9:12 PM, Remko Popma <re...@gmail.com> wrote:
>
> Looking at this some more, I now wonder why LoggerConfig.clearAppenders()
> even needs to wait for completion:
> LoggerConfig.clearAppenders() is only called from
> AbstractConfiguration.stop(), and is called *after* all appenders have been
> stopped...
>
> Could we do away with the waitForCompletion() method (and associated
> fields) altogether, or am I missing something?
>
> On Sunday, September 13, 2015, Remko Popma <re...@gmail.com> wrote:
>
>> Ralph, yes, pull up the shutdown.get() check into afterLogEvent():
>>
>>
>> Gary, I expect some improvement, although it may not be huge. It should
>> also be visible in a single-threaded case. I hope small changes like this
>> allow us to catch up or exceed Logback in synchronous logging scenarios.
>>
>> On Sunday, September 13, 2015, Gary Gregory <ga...@gmail.com>
>> wrote:
>>
>>> And this will make logging faster because there is less locking in
>>> multi-threaded apps?
>>>
>>> Gary
>>>
>>> On Sat, Sep 12, 2015 at 1:10 PM, Ralph Goers <ralph.goers@dslextreme.com
>>> > wrote:
>>>
>>>> Are you talking about making this change in
>>>> signalCompletionIfShutdown()? If so I am OK with what you are proposing.
>>>>
>>>> Ralph
>>>>
>>>> > On Sep 12, 2015, at 11:19 AM, Remko Popma <re...@gmail.com>
>>>> wrote:
>>>> >
>>>> > I want to run this by you:
>>>> >
>>>> > LoggerConfig currently always takes a lock after logging a log event.
>>>> > Within this lock it checks if the shutdown flag has been set.
>>>> > Can we do it the other way around? First check if the shutdown flag
>>>> has been set and then take the lock (to notify the other thread)?
>>>> >
>>>> > I think it is safe to do this:
>>>> >
>>>> > public void log(final LogEvent event) {
>>>> > counter.incrementAndGet();
>>>> > try {
>>>> > if (!isFiltered(event)) {
>>>> > processLogEvent(event);
>>>> > }
>>>> > } finally {
>>>> > // FIRST update counter, THEN check shutdown flag;
>>>> > // these are atomic and will not get re-ordered.
>>>> > // So we don't need the lock to check the shutdown flag.
>>>> > if (counter.decrementAndGet() == 0 && shutdown.get()) {
>>>> > // ONLY take the lock if the shutdown flag was set
>>>> > shutdownLock.lock();
>>>> > try {
>>>> > noLogEvents.signalAll(); // lock required to call
>>>> signal()
>>>> > } finally {
>>>> > shutdownLock.unlock();
>>>> > }
>>>> > }
>>>> > }
>>>> > }
>>>> >
>>>> > // keep this method unchanged
>>>> > private void waitForCompletion() {
>>>> > shutdownLock.lock();
>>>> > try {
>>>> > // NOTE: FIRST the shutdown flag is set
>>>> > if (shutdown.compareAndSet(false, true)) {
>>>> > int retries = 0;
>>>> > // NOTE: THEN the counter is read
>>>> > while (counter.get() > 0) {
>>>> > try {
>>>> > noLogEvents.await(retries + 1, TimeUnit.SECONDS);
>>>> > } catch (final InterruptedException ie) {
>>>> > if (++retries > MAX_RETRIES) {
>>>> > break;
>>>> > }
>>>> > }
>>>> > }
>>>> > }
>>>> > } finally {
>>>> > shutdownLock.unlock();
>>>> > }
>>>> > }
>>>> >
>>>> >
>>>>
>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>>>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>>>
>>>>
>>>
>>>
>>> --
>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>> Java Persistence with Hibernate, Second Edition
>>> <http://www.manning.com/bauer3/>
>>> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
>>> Spring Batch in Action <http://www.manning.com/templier/>
>>> Blog: http://garygregory.wordpress.com
>>> Home: http://garygregory.com/
>>> Tweet! http://twitter.com/GaryGregory
>>>
>>
>
Re: LoggerConfig improvement
Posted by Ralph Goers <ra...@dslextreme.com>.
I would have to go back and look at the code again. I remember having to implement that to shutdown properly but I suppose things could have changed since then.
Ralph
> On Sep 12, 2015, at 9:12 PM, Remko Popma <re...@gmail.com> wrote:
>
> Looking at this some more, I now wonder why LoggerConfig.clearAppenders() even needs to wait for completion:
> LoggerConfig.clearAppenders() is only called from AbstractConfiguration.stop(), and is called *after* all appenders have been stopped...
>
> Could we do away with the waitForCompletion() method (and associated fields) altogether, or am I missing something?
>
> On Sunday, September 13, 2015, Remko Popma <remko.popma@gmail.com <ma...@gmail.com>> wrote:
> Ralph, yes, pull up the shutdown.get() check into afterLogEvent():
>
>
> Gary, I expect some improvement, although it may not be huge. It should also be visible in a single-threaded case. I hope small changes like this allow us to catch up or exceed Logback in synchronous logging scenarios.
>
> On Sunday, September 13, 2015, Gary Gregory <garydgregory@gmail.com <javascript:_e(%7B%7D,'cvml','garydgregory@gmail.com');>> wrote:
> And this will make logging faster because there is less locking in multi-threaded apps?
>
> Gary
>
> On Sat, Sep 12, 2015 at 1:10 PM, Ralph Goers <ralph.goers@dslextreme.com <>> wrote:
> Are you talking about making this change in signalCompletionIfShutdown()? If so I am OK with what you are proposing.
>
> Ralph
>
> > On Sep 12, 2015, at 11:19 AM, Remko Popma <remko.popma@gmail.com <>> wrote:
> >
> > I want to run this by you:
> >
> > LoggerConfig currently always takes a lock after logging a log event.
> > Within this lock it checks if the shutdown flag has been set.
> > Can we do it the other way around? First check if the shutdown flag has been set and then take the lock (to notify the other thread)?
> >
> > I think it is safe to do this:
> >
> > public void log(final LogEvent event) {
> > counter.incrementAndGet();
> > try {
> > if (!isFiltered(event)) {
> > processLogEvent(event);
> > }
> > } finally {
> > // FIRST update counter, THEN check shutdown flag;
> > // these are atomic and will not get re-ordered.
> > // So we don't need the lock to check the shutdown flag.
> > if (counter.decrementAndGet() == 0 && shutdown.get()) {
> > // ONLY take the lock if the shutdown flag was set
> > shutdownLock.lock();
> > try {
> > noLogEvents.signalAll(); // lock required to call signal()
> > } finally {
> > shutdownLock.unlock();
> > }
> > }
> > }
> > }
> >
> > // keep this method unchanged
> > private void waitForCompletion() {
> > shutdownLock.lock();
> > try {
> > // NOTE: FIRST the shutdown flag is set
> > if (shutdown.compareAndSet(false, true)) {
> > int retries = 0;
> > // NOTE: THEN the counter is read
> > while (counter.get() > 0) {
> > try {
> > noLogEvents.await(retries + 1, TimeUnit.SECONDS);
> > } catch (final InterruptedException ie) {
> > if (++retries > MAX_RETRIES) {
> > break;
> > }
> > }
> > }
> > }
> > } finally {
> > shutdownLock.unlock();
> > }
> > }
> >
> >
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org <>
> For additional commands, e-mail: log4j-dev-help@logging.apache.org <>
>
>
>
>
> --
> E-Mail: garydgregory@gmail.com <> | ggregory@apache.org <>
> Java Persistence with Hibernate, Second Edition <http://www.manning.com/bauer3/>
> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
> Spring Batch in Action <http://www.manning.com/templier/>
> Blog: http://garygregory.wordpress.com <http://garygregory.wordpress.com/>
> Home: http://garygregory.com/ <http://garygregory.com/>
> Tweet! http://twitter.com/GaryGregory <http://twitter.com/GaryGregory>
Re: LoggerConfig improvement
Posted by Remko Popma <re...@gmail.com>.
Looking at this some more, I now wonder why LoggerConfig.clearAppenders()
even needs to wait for completion:
LoggerConfig.clearAppenders() is only called from
AbstractConfiguration.stop(), and is called *after* all appenders have been
stopped...
Could we do away with the waitForCompletion() method (and associated
fields) altogether, or am I missing something?
On Sunday, September 13, 2015, Remko Popma <re...@gmail.com> wrote:
> Ralph, yes, pull up the shutdown.get() check into afterLogEvent():
>
>
> Gary, I expect some improvement, although it may not be huge. It should
> also be visible in a single-threaded case. I hope small changes like this
> allow us to catch up or exceed Logback in synchronous logging scenarios.
>
> On Sunday, September 13, 2015, Gary Gregory <garydgregory@gmail.com
> <javascript:_e(%7B%7D,'cvml','garydgregory@gmail.com');>> wrote:
>
>> And this will make logging faster because there is less locking in
>> multi-threaded apps?
>>
>> Gary
>>
>> On Sat, Sep 12, 2015 at 1:10 PM, Ralph Goers <ra...@dslextreme.com>
>> wrote:
>>
>>> Are you talking about making this change in
>>> signalCompletionIfShutdown()? If so I am OK with what you are proposing.
>>>
>>> Ralph
>>>
>>> > On Sep 12, 2015, at 11:19 AM, Remko Popma <re...@gmail.com>
>>> wrote:
>>> >
>>> > I want to run this by you:
>>> >
>>> > LoggerConfig currently always takes a lock after logging a log event.
>>> > Within this lock it checks if the shutdown flag has been set.
>>> > Can we do it the other way around? First check if the shutdown flag
>>> has been set and then take the lock (to notify the other thread)?
>>> >
>>> > I think it is safe to do this:
>>> >
>>> > public void log(final LogEvent event) {
>>> > counter.incrementAndGet();
>>> > try {
>>> > if (!isFiltered(event)) {
>>> > processLogEvent(event);
>>> > }
>>> > } finally {
>>> > // FIRST update counter, THEN check shutdown flag;
>>> > // these are atomic and will not get re-ordered.
>>> > // So we don't need the lock to check the shutdown flag.
>>> > if (counter.decrementAndGet() == 0 && shutdown.get()) {
>>> > // ONLY take the lock if the shutdown flag was set
>>> > shutdownLock.lock();
>>> > try {
>>> > noLogEvents.signalAll(); // lock required to call
>>> signal()
>>> > } finally {
>>> > shutdownLock.unlock();
>>> > }
>>> > }
>>> > }
>>> > }
>>> >
>>> > // keep this method unchanged
>>> > private void waitForCompletion() {
>>> > shutdownLock.lock();
>>> > try {
>>> > // NOTE: FIRST the shutdown flag is set
>>> > if (shutdown.compareAndSet(false, true)) {
>>> > int retries = 0;
>>> > // NOTE: THEN the counter is read
>>> > while (counter.get() > 0) {
>>> > try {
>>> > noLogEvents.await(retries + 1, TimeUnit.SECONDS);
>>> > } catch (final InterruptedException ie) {
>>> > if (++retries > MAX_RETRIES) {
>>> > break;
>>> > }
>>> > }
>>> > }
>>> > }
>>> > } finally {
>>> > shutdownLock.unlock();
>>> > }
>>> > }
>>> >
>>> >
>>>
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>>
>>>
>>
>>
>> --
>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>> Java Persistence with Hibernate, Second Edition
>> <http://www.manning.com/bauer3/>
>> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
>> Spring Batch in Action <http://www.manning.com/templier/>
>> Blog: http://garygregory.wordpress.com
>> Home: http://garygregory.com/
>> Tweet! http://twitter.com/GaryGregory
>>
>
Re: LoggerConfig improvement
Posted by Remko Popma <re...@gmail.com>.
Ralph, yes, pull up the shutdown.get() check into afterLogEvent():
Gary, I expect some improvement, although it may not be huge. It should
also be visible in a single-threaded case. I hope small changes like this
allow us to catch up or exceed Logback in synchronous logging scenarios.
On Sunday, September 13, 2015, Gary Gregory <ga...@gmail.com> wrote:
> And this will make logging faster because there is less locking in
> multi-threaded apps?
>
> Gary
>
> On Sat, Sep 12, 2015 at 1:10 PM, Ralph Goers <ra...@dslextreme.com>
> wrote:
>
>> Are you talking about making this change in signalCompletionIfShutdown()?
>> If so I am OK with what you are proposing.
>>
>> Ralph
>>
>> > On Sep 12, 2015, at 11:19 AM, Remko Popma <re...@gmail.com>
>> wrote:
>> >
>> > I want to run this by you:
>> >
>> > LoggerConfig currently always takes a lock after logging a log event.
>> > Within this lock it checks if the shutdown flag has been set.
>> > Can we do it the other way around? First check if the shutdown flag has
>> been set and then take the lock (to notify the other thread)?
>> >
>> > I think it is safe to do this:
>> >
>> > public void log(final LogEvent event) {
>> > counter.incrementAndGet();
>> > try {
>> > if (!isFiltered(event)) {
>> > processLogEvent(event);
>> > }
>> > } finally {
>> > // FIRST update counter, THEN check shutdown flag;
>> > // these are atomic and will not get re-ordered.
>> > // So we don't need the lock to check the shutdown flag.
>> > if (counter.decrementAndGet() == 0 && shutdown.get()) {
>> > // ONLY take the lock if the shutdown flag was set
>> > shutdownLock.lock();
>> > try {
>> > noLogEvents.signalAll(); // lock required to call
>> signal()
>> > } finally {
>> > shutdownLock.unlock();
>> > }
>> > }
>> > }
>> > }
>> >
>> > // keep this method unchanged
>> > private void waitForCompletion() {
>> > shutdownLock.lock();
>> > try {
>> > // NOTE: FIRST the shutdown flag is set
>> > if (shutdown.compareAndSet(false, true)) {
>> > int retries = 0;
>> > // NOTE: THEN the counter is read
>> > while (counter.get() > 0) {
>> > try {
>> > noLogEvents.await(retries + 1, TimeUnit.SECONDS);
>> > } catch (final InterruptedException ie) {
>> > if (++retries > MAX_RETRIES) {
>> > break;
>> > }
>> > }
>> > }
>> > }
>> > } finally {
>> > shutdownLock.unlock();
>> > }
>> > }
>> >
>> >
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>
>>
>
>
> --
> E-Mail: garydgregory@gmail.com | ggregory@apache.org
> Java Persistence with Hibernate, Second Edition
> <http://www.manning.com/bauer3/>
> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
> Spring Batch in Action <http://www.manning.com/templier/>
> Blog: http://garygregory.wordpress.com
> Home: http://garygregory.com/
> Tweet! http://twitter.com/GaryGregory
>
Re: LoggerConfig improvement
Posted by Gary Gregory <ga...@gmail.com>.
And this will make logging faster because there is less locking in
multi-threaded apps?
Gary
On Sat, Sep 12, 2015 at 1:10 PM, Ralph Goers <ra...@dslextreme.com>
wrote:
> Are you talking about making this change in signalCompletionIfShutdown()?
> If so I am OK with what you are proposing.
>
> Ralph
>
> > On Sep 12, 2015, at 11:19 AM, Remko Popma <re...@gmail.com> wrote:
> >
> > I want to run this by you:
> >
> > LoggerConfig currently always takes a lock after logging a log event.
> > Within this lock it checks if the shutdown flag has been set.
> > Can we do it the other way around? First check if the shutdown flag has
> been set and then take the lock (to notify the other thread)?
> >
> > I think it is safe to do this:
> >
> > public void log(final LogEvent event) {
> > counter.incrementAndGet();
> > try {
> > if (!isFiltered(event)) {
> > processLogEvent(event);
> > }
> > } finally {
> > // FIRST update counter, THEN check shutdown flag;
> > // these are atomic and will not get re-ordered.
> > // So we don't need the lock to check the shutdown flag.
> > if (counter.decrementAndGet() == 0 && shutdown.get()) {
> > // ONLY take the lock if the shutdown flag was set
> > shutdownLock.lock();
> > try {
> > noLogEvents.signalAll(); // lock required to call
> signal()
> > } finally {
> > shutdownLock.unlock();
> > }
> > }
> > }
> > }
> >
> > // keep this method unchanged
> > private void waitForCompletion() {
> > shutdownLock.lock();
> > try {
> > // NOTE: FIRST the shutdown flag is set
> > if (shutdown.compareAndSet(false, true)) {
> > int retries = 0;
> > // NOTE: THEN the counter is read
> > while (counter.get() > 0) {
> > try {
> > noLogEvents.await(retries + 1, TimeUnit.SECONDS);
> > } catch (final InterruptedException ie) {
> > if (++retries > MAX_RETRIES) {
> > break;
> > }
> > }
> > }
> > }
> > } finally {
> > shutdownLock.unlock();
> > }
> > }
> >
> >
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
>
--
E-Mail: garydgregory@gmail.com | ggregory@apache.org
Java Persistence with Hibernate, Second Edition
<http://www.manning.com/bauer3/>
JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
Spring Batch in Action <http://www.manning.com/templier/>
Blog: http://garygregory.wordpress.com
Home: http://garygregory.com/
Tweet! http://twitter.com/GaryGregory
Re: LoggerConfig improvement
Posted by Ralph Goers <ra...@dslextreme.com>.
Are you talking about making this change in signalCompletionIfShutdown()? If so I am OK with what you are proposing.
Ralph
> On Sep 12, 2015, at 11:19 AM, Remko Popma <re...@gmail.com> wrote:
>
> I want to run this by you:
>
> LoggerConfig currently always takes a lock after logging a log event.
> Within this lock it checks if the shutdown flag has been set.
> Can we do it the other way around? First check if the shutdown flag has been set and then take the lock (to notify the other thread)?
>
> I think it is safe to do this:
>
> public void log(final LogEvent event) {
> counter.incrementAndGet();
> try {
> if (!isFiltered(event)) {
> processLogEvent(event);
> }
> } finally {
> // FIRST update counter, THEN check shutdown flag;
> // these are atomic and will not get re-ordered.
> // So we don't need the lock to check the shutdown flag.
> if (counter.decrementAndGet() == 0 && shutdown.get()) {
> // ONLY take the lock if the shutdown flag was set
> shutdownLock.lock();
> try {
> noLogEvents.signalAll(); // lock required to call signal()
> } finally {
> shutdownLock.unlock();
> }
> }
> }
> }
>
> // keep this method unchanged
> private void waitForCompletion() {
> shutdownLock.lock();
> try {
> // NOTE: FIRST the shutdown flag is set
> if (shutdown.compareAndSet(false, true)) {
> int retries = 0;
> // NOTE: THEN the counter is read
> while (counter.get() > 0) {
> try {
> noLogEvents.await(retries + 1, TimeUnit.SECONDS);
> } catch (final InterruptedException ie) {
> if (++retries > MAX_RETRIES) {
> break;
> }
> }
> }
> }
> } finally {
> shutdownLock.unlock();
> }
> }
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org