RFR: JDK-6823527: java.util.logging.Handler has thread safety issues

[David Holmes]

Ship it! :)

Thanks,
David

On 30/08/2013 9:50 PM, Daniel Fuchs wrote:
> Hi,
>
> Please find below an updated patch for solution (c)
>
> <http://cr.openjdk.java.net/~dfuchs/webrev_6823527/webrev.02/>
>
> best regards,
>
> -- daniel
>
>  >>> It seems we have 5 choices:
>  >>>
>  >>> a. Not fixing
>  >>> b. Using regular 'synchronized' pattern [1]
>  >>> c. Using volatiles, synchronize setters only [2]
>  >>> d. Using volatiles, only synchronize setters when obviously necessary
>  >>> e. other? (like introducing new private locks - but I don't think
>  >>> anybody would want that)
>  >>>
>  >>> [1] <http://cr.openjdk.java.net/~dfuchs/webrev_6823527/webrev.00/>
>  >>> [2] <http://cr.openjdk.java.net/~dfuchs/webrev_6823527/webrev.01/>
>  >>>
>  >>> My own preference would lean to either b) or c).
>
>
>
> On 8/30/13 10:38 AM, Daniel Fuchs wrote:
>> On 8/30/13 9:21 AM, David Holmes wrote:
>>> Hi Daniel,
>>>
>>> I'm fine with the approach in (c), just wanted to highlight the
>>> performance considerations (volatile and synchronized need not be
>>> equivalent in the uncontended case - biased-locking can mean there are
>>> no barriers emitted.)
>>>
>>> A few specific comments on [2]:
>>>
>>> Handler.java:
>>>
>>> reportError doesn't need changing now that the field is volatile and you
>>> aren't doing sync.
>>
>> right. I will revert to original code.
>>
>>> MemoryHandler.java:
>>>
>>> pushLevel should/could be volatile and the sync removed from
>>> getPushLevel.
>>
>> right. thanks - I missed that.
>>
>>> In setPushLevel this seems to be unused code:
>>>
>>>   262         LogManager manager = LogManager.getLogManager();
>>>
>>> unless there is some obscure side-effect in calling getLogManager ??
>>
>> Well - yes it triggers the initialization of the logging system.
>> However the super class will already have called getLogManager() -
>> so this call should have no effect.  I will remove it.
>>
>>> setPushLevel might as well also be synchronized at the method level. All
>>> the Handler methods already include checkPermission inside the
>>> sync-block. Though I'm actually more inclined to change all the existing
>>> code to use sync-blocks so that checkPermission is done outside the lock
>>> region. But a consistent approach either way would be preferable.
>>
>> Agreed. Once I have removed the call to LogManager then the method can
>> be synchronized at method level.
>>
>>> StreamHandler.java
>>>
>>> writer doesn't need to be volatile - AFAICS it is only accessed within
>>> synchronized methods.
>>
>> Ah - no - it's called in isLoggable() actually. The whole point of using
>> volatiles instead of regular synchronization was to allow isLoggable()
>> to be called concurrently with e.g. publish() - so I would think
>> it's better to make writer volatile too.
>>
>> Thanks for the valuable comments! I will update the webrev and send out
>> a new revision...
>>
>> best regards,
>>
>> -- daniel
>>
>>>
>>> Thanks,
>>> David
>>>
>>> On 30/08/2013 4:45 PM, Daniel Fuchs wrote:
>>>> On 8/30/13 3:27 AM, David Holmes wrote:
>>>>> Hi Daniel,
>>>>>
>>>>> As usual with these kinds of changes we start by trying to complete an
>>>>> incomplete/incorrect synchronization pattern and get diverted into
>>>>> changing the synchronization pattern. :) The latter of course has more
>>>>> risk than the former.
>>>>>
>>>>> Making everything synchronized has the benefit that we don't need to
>>>>> analyse the "real" methods to check what would happen if one of these
>>>>> data values changed mid-method. Might be harmless, might not.
>>>>> Atomicity makes things easy to reason about.
>>>> Agreed. We can analyze the 'real methods' of Handler classes in the
>>>> JDK.
>>>> But I'm sure there are plenty of
>>>> subclasses of handlers in applications out there that we don't know
>>>> about. So we can't really be sure
>>>> what the effect of changing synchronization might have on those
>>>> subclasses.
>>>>
>>>>> Making the fields volatile and un-sync'ing the getters is a potential
>>>>> optimization for readers. But are these fields that are read
>>>>> frequently by multiple threads?
>>>>
>>>> At least three of them are accessed by isLoggable() which I believe is
>>>> called very frequently by
>>>> multiple threads (level, filter, and writer).
>>>>
>>>>> The downside of doing so is a negative performance impact inside the
>>>>> "real" methods where every volatile field access requires
>>>>> (platform-dependent) memory barriers.
>>>> That - I think - should not be such an issue since the fields are
>>>> private.
>>>> I mean - we can see whether there are methods that do multiple
>>>> access to
>>>> the fields in the
>>>> classes that define these fields - and fix that if necessary.
>>>> For subclasses, they will have to call the getter, which will require
>>>> synchronization anyway.
>>>> I mean - for subclasses - isn't the fact that the getter accesses a
>>>> volatile field or the fact that the
>>>> getter is synchronized equivalent in terms of performance?
>>>>
>>>> JDK 8 is a major version of the JDK - so I think if we want to fix this
>>>> bug it's
>>>> probably better to do it now rather than in a minor update.
>>>>
>>>> It seems we have 5 choices:
>>>>
>>>> a. Not fixing
>>>> b. Using regular 'synchronized' pattern [1]
>>>> c. Using volatiles, synchronize setters only [2]
>>>> d. Using volatiles, only synchronize setters when obviously necessary
>>>> e. other? (like introducing new private locks - but I don't think
>>>> anybody would want that)
>>>>
>>>> [1] <http://cr.openjdk.java.net/~dfuchs/webrev_6823527/webrev.00/>
>>>> [2] <http://cr.openjdk.java.net/~dfuchs/webrev_6823527/webrev.01/>
>>>>
>>>> My own preference would lean to either b) or c).
>>>>
>>>> -- daniel
>>>>
>>>>
>>>>>
>>>>> David
>>>>>
>>>>> On 30/08/2013 5:54 AM, Daniel Fuchs wrote:
>>>>>> On 8/29/13 9:45 PM, Mandy Chung wrote:
>>>>>>> On 8/29/13 11:04 AM, Daniel Fuchs wrote:
>>>>>>>> On 8/29/13 7:58 PM, Mandy Chung wrote:
>>>>>>>>> On 8/29/13 9:46 AM, Daniel Fuchs wrote:
>>>>>>>>>> Here is the new webrev implementing Jason's suggestion.
>>>>>>>>>> Compared to previous webrev only Handler.java &
>>>>>>>>>> StreamHandler.java
>>>>>>>>>> have changed.
>>>>>>>>>>
>>>>>>>>>> <http://cr.openjdk.java.net/~dfuchs/webrev_6823527/webrev.01/>
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Looks good.  I also agree that making those fields to be volatile
>>>>>>>>> is a
>>>>>>>>> good suggestion and only requires writer to acquire the lock.
>>>>>>>>>
>>>>>>>>> A minor comment:  The setter methods in Handler class are
>>>>>>>>> synchronized
>>>>>>>>> at the method entry whereas StreamHandler.setPushLevel
>>>>>>>>> synchronizes
>>>>>>>>> after checkPermission() is called.  checkPermission doesn't need
>>>>>>>>> to be
>>>>>>>>> synchronized.  Either way is fine with me and it'd be good to
>>>>>>>>> do it
>>>>>>>>> consistently.
>>>>>>>>
>>>>>>>> Hi Mandy,
>>>>>>>>
>>>>>>>> Are you suggesting I should put checkPermission() within
>>>>>>>> the synchronized block? It might be more consistent with
>>>>>>>> what the other setters do. Although as you state it does
>>>>>>>> not matter much.
>>>>>>>
>>>>>>> Having a second thought - do the setters really need to be
>>>>>>> synchronized?   My guess is that StreamHandler.publish is
>>>>>>> synchronized
>>>>>>> so as to ensure that the log messages are sequential and not
>>>>>>> interpersed
>>>>>>> when multiple threads are publishing.  The spec is unclear.
>>>>>>> Perhaps it
>>>>>>> worths looking into this further?
>>>>>>
>>>>>> I believe at least setEncodings() needs synchronization.
>>>>>> setLevel() had it - so are we going to cause subtle race conditions
>>>>>> if we remove it?
>>>>>>
>>>>>> My own feeling is that keeping setters synchronized might be better.
>>>>>>
>>>>>> We could of course say that a subclass which needs to prevent
>>>>>> e.g. setFormatter() from being called concurrently with publish()
>>>>>> should override setFormatter just for the purpose of synchronizing
>>>>>> it...
>>>>>>
>>>>>>> One more minor note: MemoryHandler.pushLevel can also be made
>>>>>>> volatile.
>>>>>>> L262: look like the log manager is not needed in the existing code.
>>>>>>
>>>>>> hmmm. Right. It's already called once in the super class so removing
>>>>>> this call should have no effect. I will remove it.
>>>>>>
>>>>>> -- daniel
>>>>>>
>>>>>>>
>>>>>>> Mandy
>>>>>>>
>>>>>>
>>>>
>>
>