RFR (M) 8186042: Optimize OopMapCache lookup

[coleen.phillimore at oracle.com]

On 8/14/17 8:45 AM, coleen.phillimore at oracle.com wrote:
>
>
> On 8/14/17 8:29 AM, David Holmes wrote:
>> On 14/08/2017 10:17 PM, coleen.phillimore at oracle.com wrote:
>>> On 8/13/17 8:29 PM, David Holmes wrote:
>>>> Hi Coleen,
>>>>
>>>> This looks good to me - Reviewed. A couple of minor comments below.
>>>>
>>>> On 12/08/2017 1:46 AM, coleen.phillimore at oracle.com wrote:
>>>>> Summary: Use lock free access to oopMapCache
>>>>> Contributed-by: frederic.parain at oracle.com, 
>>>>> coleen.phillimore at oracle.com
>>>>>
>>>>> The OopMapCache::lookup() function took out a mutex to protect 
>>>>> access between the GC threads that are running concurrently. See 
>>>>> bug for more info.   The function lookup() is run by multiple GC 
>>>>> threads concurrently.  If there's a collision in the hashtable, 
>>>>> this uses atomic cmpxchg to add the entry to a list to be cleaned 
>>>>> up after the safepoint is over.   GC isn't doing lookup at that 
>>>>> point.
>>>>>
>>>>> This change is contributed by Frederic Parain, with some cleanup 
>>>>> and logging from me.
>>>>>
>>>>> open webrev at http://cr.openjdk.java.net/~coleenp/8186042.01/webrev
>>>>> bug link https://bugs.openjdk.java.net/browse/JDK-8186042
>>>>
>>>> src/share/vm/interpreter/oopMapCache.cpp
>>>>
>>>> The logging here doesn't follow our usual pattern of only making 
>>>> the logging calls if the appropriate logging level is enabled. ??
>>>
>>> I'm not sure what you're talking about.
>>>
>>> I think this is the new pattern of doing logging:
>>>
>>>    Log(interpreter, oopmap) logv;
>>>    LogStream st(logv.trace());
>>
>> I'm not familiar with that form. I wonder how the subsequent 
>> unconditional st.print is handled? ie how much work do we do before 
>> determining logging is not enabled?
>
> I wish I knew how to get generated .s file with the new build. The 
> printing code in the function OopMapCacheEntry::verify_mask isn't 
> doing anything interesting (like getting as_C_string() etc).  The 
> implied check for log_is_enabled before all of the st.print()s can't 
> be worse than the existing global checks for TraceOopMapGeneration && 
> Verbose.  It's a ton cleaner and the performance is a wash.

The function verify_maks is called under an assert, so the log trace 
queries won't affect product performance.
Coleen

>>
>>> Otherwise
>>>
>>>       log_debug(interpreter, oopmap)("*** collision in oopmap cache 
>>> - flushing item ***");
>>>
>>> checks for whether debug level logging is on. 
>>
>> Yes.
>>
>>> You only need this:
>>>    if (log_is_enabled(Debug, interpreter, oopmap)) {
>>>      static int count = 0;
>>>      ResourceMark rm;
>>>      log_debug(interpreter, oopmap)
>>>            ("%d - Computing oopmap at bci %d for %s at hash %d", 
>>> ++count, bci,
>>>             method()->name_and_sig_as_C_string(), probe);
>>>    }
>>>
>>> If you're creating a ResourceMark.
>>
>> I don't associate it only with use of ResourceMarks, but any time you 
>> have to do a bit of work to gather all the information that will be 
>> passed to the actual logging statement. The aim being not to do any 
>> of that if logging is not enabled.
>>
>>> Unless logging changed (which I think it did).
>>
>> Perhaps. In which case I'd like to understand how this new form 
>> minimises the wasted effort when logging is disabled.
>>
>>>>
>>>> src/share/vm/interpreter/oopMapCache.hpp
>>>>
>>>> Nit: OopMapCacheEntry* volatile* _array;
>>>>
>>>> Space after volatile please as it refers to the OMCE* not the *_array.
>>>
>>> Like this?
>>>
>>>    OopMapCacheEntry* volatile * _array;
>>
>> Yes.
>>
>>> Per coding standard, we don't put the '*' without * in front of the 
>>> name of the variable, only the type, like
>>>     OopMapCacheEntry* blah;
>>> vs
>>>     OopMapCacheEntry *blah;
>>
>> Okay I see where this comes from. Personally I find it odd to have 
>> the "volatile*". Anyway minor issue.
>>
>>>>
>>>>> Tested with RBT equivalent of nightly on linux x64.  Also ran 
>>>>> dacapo with -Xint -Xlog:interpreter+oopmap=debug to verify.  This 
>>>>> change also 
>>>>
>>>> Do you have some performance improvement numbers for this 
>>>> optimization? Or is this a pre-emptive strike against a potential 
>>>> locking bottleneck?
>>>
>>> Erik Osterlund ran benchmarks but I don't have access to them and he 
>>> is on vacation.   Heresay is that the bottleneck observed for this 
>>> lock is gone.
>>
>> Okay we can get the gory details added to the bug later.
>
> Yes, RedHat will see the improvements also.
>
> Thanks,
> Coleen
>
>>
>> Thanks,
>> David
>>
>>>>
>>>>> removes -XX:+TraceOopMapGeneration (not 
>>>>> -XX:+TraceNewOopMapGeneration however) in favor of new logging. A 
>>>>> linked CSR request is pending.
>>>>
>>>> Ok.
>>>
>>> Thanks for commenting on the CSR and the review.
>>>
>>> Coleen
>>>>
>>>>
>>>> Thanks,
>>>> David
>>>>
>>>>> Thanks,
>>>>> Coleen
>>>>>
>>>
>