AW: ridiculous ParNew pause times

[Per Liden]

Hi,

As someone already mentioned, writes to the GC log file are synchronous. 
They are buffered fwrite()s on a stdio FILE stream. But there's no 
fsync()-ing going on.

There's work ongoing to improve/redesign the whole logging framework in 
the VM (JEP 158, http://openjdk.java.net/jeps/158). I briefly talked to 
the guys involved in that and passed on the feedback that some kind of 
support for async logging might be worth considering.

If you want to get involved or follow that effort I'd suggest you hang 
out on serviceability-dev at openjdk.java.net.

cheers,
/Per

On 04/10/2014 11:07 AM, Cornelius Riemenschneider wrote:
> Yes, these settings are currently set to the default values.
> I'll investigate changing them as well, but for now I'll move the gc log to a ramdisk -
> waiting for the log to be written is a very stupid reason to delay something awful as a garbage collection.
>
> Regards,
> Cornelius Riemenschneider
> --
> ITscope GmbH
> Ludwig-Erhard-Allee 20
> 76131 Karlsruhe
> Email: cornelius.riemenschneider at itscope.de
> https://www.itscope.com
> Handelsregister: AG Mannheim, HRB 232782
> Sitz der Gesellschaft: Karlsruhe
> Geschäftsführer: Alexander Münkel, Benjamin Mund, Stefan Reger
>
>
> -----Ursprüngliche Nachricht-----
> Von: hotspot-gc-use [mailto:hotspot-gc-use-bounces at openjdk.java.net] Im Auftrag von Holger Hoffstätte
> Gesendet: Mittwoch, 9. April 2014 19:42
> An: hotspot-gc-use
> Betreff: Re: ridiculous ParNew pause times
>
> On 04/09/14 18:40, Cornelius Riemenschneider wrote:
>> Bingo! First, i tried to get a tool which shows me which process
>> writes to which file and how long that takes, but I was unable to find
>> one I could master to use. Based on your suggestion I moved the log.gc
>> file to a ramdisk and performed extensive load testing - now my
>> biggest outlier is 2014-04-09T18:29:13.873+0200: 383.372:
>> [GC2014-04-09T18:29:13.874+0200: 383.372: [ParNew:
>> 431041K->208698K(3145728K), 1.8312460 secs]
>> 11055599K->11203421K(21495808K), 1.8315130 secs] [Times: user=2.61
>> sys=0.03, real=1.83 secs] which is okay.
>
> Another idea: are your vm.dirty_(expire|writeback)_centisecs and especially vm.dirty_(background)_ratio sysctl settings default, aka ridiculously high? This can result in writeback storms of a huge number of accumulated dirty buffers and is a common reason for periodic stalls, which can take forever when another process issues fsync() at inappropriate moments.
>
> Just a guess.
>
> -h
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>