ShenandoahStrDedupTable::lookup_or_add uses a lot of CPU time

[Omar Kilani]

Hi,

This is more of a 'is this how it should be?' rather than a bug report
or defect.

Our apps running on the JVM basically read things from a database, do
X, and emit JSON. So... pretty string heavy.

Running 'perf top' shows ShenandoahStrDedupTable::lookup_or_add using
something like 25% of all CPU time on a 24 phsyical / 48 HT Intel(R)
Xeon(R) Gold 6126 CPU @ 2.60GHz.

I'm sort of wondering if something changed recently as we moved from
shipilev openjdk-shenandoah-jdk10 b246 to b251 and I don't remember
this sort of behavior. Our pause times with StringDedup enabled look
like this:

[97116.240s][info][gc,start     ] GC(821) Pause Init Mark
[97116.366s][info][gc           ] GC(821) Pause Init Mark 126.301ms
[97116.524s][info][gc,start     ] GC(821) Pause Final Mark
[97116.525s][info][gc           ] GC(821) Pause Final Mark 1.311ms
[97116.534s][info][gc,start     ] GC(821) Pause Init Update Refs
[97116.534s][info][gc           ] GC(821) Pause Init Update Refs 0.142ms
[97116.566s][info][gc,start     ] GC(821) Pause Final Update Refs
[97116.655s][info][gc           ] GC(821) Pause Final Update Refs 88.653ms

And our pause times without StringDup look like this:

[4109.086s][info][gc,start     ] GC(41) Pause Init Mark
[4109.095s][info][gc           ] GC(41) Pause Init Mark 8.566ms
[4109.119s][info][gc,start     ] GC(41) Pause Final Mark
[4109.120s][info][gc           ] GC(41) Pause Final Mark 1.478ms
[4109.126s][info][gc,start     ] GC(41) Pause Init Update Refs
[4109.126s][info][gc           ] GC(41) Pause Init Update Refs 0.134ms
[4109.136s][info][gc,start     ] GC(41) Pause Final Update Refs
[4109.141s][info][gc           ] GC(41) Pause Final Update Refs 5.518ms

The only difference here is the -XX:+UseStringDeduplication option.

I'd really appreciate any insights or hunches. :)

Regards,
Omar