RFR(M): 8231460: Performance issue (CodeHeap) with large free blocks

[Andrew Dinn]

Hi Lutz,

I'll summarize my thoughts here rather than answer point by point.

The patch successfully addresses the worst case performance but it seems
to me extremely unlikely that we will see anything that approaches that
case in real applications. So, that doesn't argue for pushing the patch.

The patch does not seem to make a significant difference to the stress
test. This test is also not necessarily 'representative' of real cases
but it is much more likely to be so than the worst case test. That
suggests to me that the current patch is perhaps not worth pursuing (it
ain't really broke so ...).  Especially so given that it is not possible
to distinguish any benefit when running the Spec benchmark apps. One
could argue that the patch looks like it will do no harm and may do good
in pathological  cases but that's not really good enough reason to make
a change. We really need evidence that this is worth doing.

The free list 'search bottleneck' certainly looks like a more promising
problem to tackle than the 'merge problem'. However, once again this
'problem' may just be an artefact of running this specific test rather
than anything that might happen in real life.

I think the only way to find out for sure whether the current patch or a
patch that addresses the 'search bottleneck' is going to be beneficial
is to instrument the JVM to record traces for code-cache use from real
apps and then replay allocations/frees based on those traces to see what
difference a patch makes and how much this might help the overall
execution time.

regards,


Andrew Dinn
-----------

On 31/10/2019 16:55, Schmidt, Lutz wrote:
> Hi Andrew, (and hi to the interested crowd),
> 
> Please accept my apologies for taking so long to get back.
> 
> These tests (OverflowCodeCacheTest and StressCodeCacheTest) were causing me quite some headaches. Some layer between me and the test prevents the vm (in particular: the VMThread) from terminating normally. The final output from my time measurements is therefore not generated or thrown away. Adding to that were some test machine unavailabilities and a bug in my measurement code, causing crashes. 
> 
> Anyway, I added some on-the-fly output, printing the timer values after 10k measurement intervals. This reveals some interesting, additional facts about the tests and the CodeHeap management methods. For detailed numbers, refer to the files attached to the bug (https://bugs.openjdk.java.net/browse/JDK-8231460). For even more detail, I can provide the jtr files on request. 
> 
> 
> OverflowCodeCacheTest
> =====================
> This test runs (in my setup) with a 1GB CodeCache.
> 
> For this test, CodeHeap::mark_segmap_as_used() is THE performance hog. 40% of all calls have to mark more than 16k segment map entries (in the not optimized case). Basically all of these calls convert to len=1 calls with the optimization turned on. Note that during FreeBlock joining, the segment count is forced to 1(one). No wonder the time spent in CodeHeap::mark_segmap_as_used() collapses from >80sec (half of the test runtime) to <100msec. 
> 
> CodeHeap::add_to_freelist() on the other hand, is almost not observable. Average free list length is at two elements, making even linear search really quick. 
> 
> 
> StressCodeCacheTest
> ===================
> With a 1GB CodeCache, this test runs into a 12 min timeout, set by our internal test environment. Scaling back to 300MB prevents the test from timing out.
> 
> For this test, CodeHeap::mark_segmap_as_used() is not a factor. From 200,000 calls, only a few (less than 3%) had to process a block consisting of more than 16 segments. Note that during FreeBlock joining, the segment count is forced to 1(one). 
> 
> Another method is popping up as performance hog instead: CodeHeap::add_to_freelist(). More than 8 out of 40 seconds of test runtime (before optimization) are spent in this method, for just 160,000 calls. The test seems to create a long list of non-contiguous free blocks (around 5,500 on average). This list is linearly scanned to find the insert point for the free block at hand.
> 
> Suffering as well from the long free block list is CodeHeap::search_freelist(). It uses another 2.7 seconds for 270,000 calls.  
> 
> 
> SPEVjvm2008 suite
> =================
> With respect to the task at hand, this is a well-behaved test suite. Timing shows some before/after difference, but nothing spectacular. The measurements due not provide evidence of a performance bottleneck. 
> 
> 
> There were some minor adjustments to the code. Unused code blocks have been removed as well. I have therefore created a new webrev. You can find it here:
>    http://cr.openjdk.java.net/~lucy/webrevs/8231460.01/ 
> 
> Thanks for investing your time!
> Lutz
> 
> 
> On 21.10.19, 15:06, "Andrew Dinn" <adinn at redhat.com> wrote:
> 
>     Hi Lutz,
>     
>     On 21/10/2019 13:37, Schmidt, Lutz wrote:
>     > I understand what you are interested in. And I was hoping to be able
>     > to provide some (first) numbers by today. Unfortunately, the
>     > measurement code I activated last Friday was buggy and blew most of
>     > the tests I had hoped to run over the weekend.
>     > 
>     > I will take your modified test and run it with and without my
>     > optimization. In parallel, I will try to generate some (non-random)
>     > numbers for other tests.
>     > 
>     > I'll be back as soon as I have results.
>     
>     Thanks for trying the test and also for deriving some call stats from a
>     real example. I'm keen to see how much your patch improves things.
>     
>     regards,
>     
>     
>     Andrew Dinn
>     -----------
>     Senior Principal Software Engineer
>     Red Hat UK Ltd
>     Registered in England and Wales under Company Registration No. 03798903
>     Directors: Michael Cunningham, Michael ("Mike") O'Neill
>     
>     
> 
>