G1: SoftReference, 0 refs, 31.0027203 secs

[Kim Barrett]

On Jul 20, 2015, at 4:24 PM, charlie hunt <charlie.hunt at oracle.com> wrote:
> 
> Hi Simone,
> 
> Seems very peculiar to see 0 SoftReferences processed and an incredibly high reported time.
> 
> Couple questions popped in my mind as I looked through the logs.
> 
> I’m assuming this is on Linux?  If so, could you confirm THP (transparent huge pages) is disabled?
> 
> And, did you happen to try tuning -XXSoftRefLRUPolicyMSPerMB smaller from the default of 1000 to say something as low as 1 to see if what you’re seeing goes away ?
> 
> Perhaps someone on the GC team has some thoughts as a situation where we would see 0 SoftReferences processed yet a high amount of time spent there.

We’ve seen other reports of long soft reference processing times, despite having none to process.  See, for example, email to this list from Joy Xiong, circa 5/20/2015, subject “Long Reference Processing Time”.

I’ve spent some time looking at the reference processing code, but I don’t see anything in the reference processing code itself that would cause this.

However, there might be a possible mis-attribution of time here.  Soft references are the first references to be processed.  The phase1 reference processing first iterates over the (empty in this case) soft reference list.  It then calls the “complete_gc” closure to process any mark stack entries added by that iteration.  But if there were already mark stack entries when reference processing was started, the time for processing them would be included in the soft reference processing time.

I *think* the mark stack (including the thread queues) ought to be empty when reference processing is started, but I’m not certain of that.  If it isn’t empty but is supposed to be, that would be a bug.  If it isn’t empty and that’s permitted, then the resulting mis-attribution of time is a bug.  And if it is empty but we still get unexpectedly long soft reference processing times then this hypothesis is falsified.

I don’t yet see a way to tell whether the mark stack is empty or to correct the time attribution that doesn’t involve patching the source code and rebuilding.