Shenandoah experimental flags

Roman Kennke rkennke at redhat.com
Thu Apr 30 09:05:09 UTC 2020


I kinda suspect it's running into degen GC, and lowering buffer size
slows it down enough to avoid this. Need to see GC logs to confirm it.

Roman

> Hi Cristian,
> 
> On 4/29/20 12:42 AM, Cristian Velazquez wrote:
>> Hi everyone:
>>
>> I'm testing out shenandoah on https://github.com/gaul/java-httpbin. I'm
>> using wrk to send a huge amount of traffic: wrk -d 300 -t 1 -c 32
>> http://127.0.0.1:8080/gzip. I'm using the default flags with 2G heap. 
> 
> Does not seem to reproduce on current head. What build/version are you using?
> 
>> I'm getting pause times from 100-300ms due to the time spent on finish queues.
> 
> Please show the part of GC log where you see this?
> 
>> I tried the following (I used as reference this
>> https://mail.openjdk.java.net/pipermail/shenandoah-dev/2018-July/006630.html
>> ):
>> - Reduce ShenandoahSATBBufferFlushInterval to 1 ms. This didn't make any
>> difference.
>> - Reduce ShenandoahSATBBufferSize to 32. This fixed the issue and now see
>> better pause times.
> 
> Really! That is odd. The periodic SATB buffer is supposed to flush anything leftover before you hit
> this problem.
> 
>> I have run it for quite a while and I haven't seen any issue with this
>> configuration. Although, I would like to know what is the recommendation in
>> this scenario? is it safe to decrease the buffer size? what is the impact
>> of doing so?
> 
> Mostly throughput performance. SATB buffer is the thing that accumulates the old field values before
> each store to maintain marking invariants. Without this buffer, every reference store would need to
> call into VM, which would be costly. So the buffer is deliberately quite large to keep application
> from calling into VM too often, and do that only for buffer flushes.
> 
> But, that matters only when marking is running. In my quick tests, your workload seems to be almost
> fully young:
> 
> [93.298s][info][gc] Trigger: Free (204M) is below minimum threshold (204M)
> [93.298s][info][gc] GC(12) Concurrent reset 0.218ms
> [93.299s][info][gc] GC(12) Pause Init Mark (unload classes) 0.191ms
> [93.301s][info][gc] GC(12) Concurrent marking (unload classes) 1.918ms
> [93.301s][info][gc] GC(12) Pause Final Mark (unload classes) 0.221ms
> [93.301s][info][gc] GC(12) Concurrent weak roots 0.362ms
> [93.302s][info][gc] GC(12) Concurrent cleanup 1766M->102M(2021M) 0.269ms
> [93.303s][info][gc] GC(12) Concurrent class unloading 1.403ms
> 
> ...so marking is way too short for you to notice this.
> 
> What I suspect is happening in your case is that marking is *so short* that buffer flush never
> happens until Final Mark, where we discover some work to do. But it is puzzling why that work is
>> 100ms, when the workload does not have a lot of live data.
> 
> Need more info...
> 



More information about the shenandoah-dev mailing list