RFR: 8325613: CTW: Stale method cleanup requires GC after Sweeper removal

[Christian Hagedorn]

On Tue, 12 Mar 2024 19:11:42 GMT, Aleksey Shipilev <shade at openjdk.org> wrote:

> See more details in the bug. There is a double-whammy from two issues: a) Sweeper was removed, and now the cleanup work is done during GC, which does not really happen as CTW barely allocates anything; b) CTW calls for explicit deoptimization often, at which point CTW threads get mostly busy at spin-waiting-yielding for deopt epoch to move (that is why you see lots of `sys%`). (a) leads to stale methods buildup, which makes (b) progressively worse.
> 
> This PR adds explicit GC calls to CTW runner. Since CTW allocates and retains a little, those GCs are quite fast. I chose the threshold by running some CTW tests on my machines. I think we are pretty flat in 25..100 region, so I chose the higher threshold for additional safety.
> 
> This patch improves both CPU and wall times for CTW testing dramatically, as you can see from the logs below. It still does not recuperate completely to JDK 17 levels, but it least it is not regressing as badly.
> 
> 
> --- x86_64 EC2, applications/ctw/modules CTW
> 
> jdk17u-dev:            4511.54s user  169.43s system 1209% cpu  6:27.07 total
> current mainline:     11678.13s user 8687.06s system 2299% cpu 14:45.62 total
> 
> GC every 25 methods:   5050.83s user  670.38s system 1629% cpu  5:51.04 total
> GC every 50 methods:   4965.41s user  709.64s system 1670% cpu  5:39.77 total
> GC every 100 methods:  4997.34s user  782.12s system 1680% cpu  5:43.99 total
> GC every 200 methods:  5237.76s user  943.51s system 1788% cpu  5:45.59 total
> GC every 400 methods:  5851.24s user 1443.16s system 1914% cpu  6:20.99 total
> GC every 800 methods:  7010.06s user 2649.35s system 2079% cpu  7:44.48 total
> GC every 1600 methods: 9361.12s user 5616.84s system 2409% cpu 10:21.68 total
> 
> --- Mac M1, applications/ctw/modules/java.base CTW
> 
> jdk17u-dev:             171.93s user   25.33s system  157% cpu  2:05.34 total
> current mainline:      1128.69s user  349.46s system  249% cpu  9:52.51 total
> 
> GC every 25 methods:    252.31s user   29.98s system  172% cpu  2:43.68 total 
> GC every 50 methods:    232.53s user   28.49s system  170% cpu  2:32.69 total
> GC every 100 methods:   237.38s user   34.53s system  169% cpu  2:40.54 total 
> GC every 200 methods:   251.70s user   39.60s system  172% cpu  2:48.40 total
> GC every 400 methods:   271.50s user   42.55s system  185% cpu  2:49.66 total
> GC every 800 methods:   389.51s user   69.41s system  204% cpu  3:44.01 total
> GC every 1600 methods:  660.98s user  169.97s system  229% cpu  6:01.78 total

Looks reasonable to me, too.

-------------

Marked as reviewed by chagedorn (Reviewer).

PR Review: https://git.openjdk.org/jdk/pull/18249#pullrequestreview-1936183471