[logback-dev] [JIRA] Commented: (LBCLASSIC-234) CLONE -Excessive synchronization in ReconfigureOnChangeFilter.decide

[Niklas Therning (JIRA)]

    [ http://jira.qos.ch/browse/LBCLASSIC-234?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12334#action_12334 ] 

Niklas Therning commented on LBCLASSIC-234:
-------------------------------------------

Hi,

I think we're experiencing this problem too. Our application constantly monitors thousands of users' POP3 and IMAP mailboxes and removes spam. About every 24 hours we have to restart our application. We've had a look at thread dumps taken just before a restart and we're seeing that most of our worker threads are waiting to obtain a lock in ReconfigureOnChangeFilter (see below for an example).

I'd like to help out with this issue. Should I make a patched version with the suggested 0xFFFF fix and see if there's any difference? Should I patch 0.9.7 or a later version? There seems to have been quite a few changes in 1.0 and latest trunk to ReconfigureOnChangeFilter (though the synchronization is still there).

Also, regarding fixing this problem, nextCheck in ReconfigureOnChangeFilter has been made volatile since 0.9.7. Wouldn't it be safe to just check changeDetected() twice? Once outside the synchronized block and then again inside?

We're running on Debian Squeeze and Debian Lenny.

Example from thread dump:
"Worker-22" prio=10 tid=0x00007f4d88cf6800 nid=0x5c2e waiting for monitor entry [0x00007f4d7dad9000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter.decide(ReconfigureOnChangeFilter.java:99)
	- waiting to lock <0x00000000c078fec8> (a ch.qos.logback.classic.LoggerContext)
	at ch.qos.logback.classic.spi.TurboFilterList.getTurboFilterChainDecision(TurboFilterList.java:47)
	at ch.qos.logback.classic.LoggerContext.getTurboFilterChainDecision_0_3OrMore(LoggerContext.java:251)
	at ch.qos.logback.classic.Logger.callTurboFilters(Logger.java:770)
	at ch.qos.logback.classic.Logger.isDebugEnabled(Logger.java:488)
	at ch.qos.logback.classic.Logger.isDebugEnabled(Logger.java:484)

> CLONE -Excessive synchronization in ReconfigureOnChangeFilter.decide
> --------------------------------------------------------------------
>
>                 Key: LBCLASSIC-234
>                 URL: http://jira.qos.ch/browse/LBCLASSIC-234
>             Project: logback-classic
>          Issue Type: Bug
>    Affects Versions: 0.917
>            Reporter: uri unger
>            Assignee: Ceki Gulcu
>            Priority: Critical
>         Attachments: screenshot-1.jpg
>
>
> The synchronization in ReconfigureOnChangeFilter.decide hurts scalability.
> It seems unnecessary to serialize the code in changeDetected -- it should be possible to use atomic updates of nextCheck and lastModified and only serialize the actual reconfiguration.

-- 
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