Fwd: Re: Solaris specific bug in GC log rotation (original) (raw)

Fwd: Re: Solaris specific bug in GC log rotation - extremely long pause

Erik Helin erik.helin at oracle.com
Wed Nov 11 08:49:01 UTC 2015

Hi Rainer,

thanks for the detailed bug report. I'm adding hotspot-runtime-dev, since this seeems like a runtime issue.

Thanks, Erik

----- Forwarded message from Rainer Jung <rainer.jung at kippdata.de> -----

From: Rainer Jung <rainer.jung at kippdata.de> To: Poonam Bajaj Parhar <poonam.bajaj at oracle.com>, "hotspot-gc-dev at openjdk.java.net" <hotspot-gc-dev at openjdk.java.net> Date: Wed, 11 Nov 2015 08:38:39 +0100 Subject: Re: Solaris specific bug in GC log rotation - extremely long pause

Hi Poonam, Am 11.11.2015 um 00:05 schrieb Poonam Bajaj Parhar: >Hello Rainer, > >Could you please file a bug for this problem here: >http://bugreport.java.com/ I did right now. >Please provide the problem description there and attach the reproducible >program, and let us know the created bug id. The bug ID is: (Review ID: JI-9026481) - One long Safepoint pause directly after each GC log rotation I couldn't attach anything, the bug submission forms do not give the opportunity to attach files. I copied the Java and shell script sources into one of the text boxes, but I couldn't fill in all of the reproduction explanations. Please feel free to attach the tar.gz file I had sent to the list. Thanks for your help and advice! Regards, Rainer >On 11/10/2015 2:15 PM, Rainer Jung wrote: >>In case anyone is interested, I'll attach some reproduction code. >>You can run it as a standalone Java program on Solaris. It is pretty >>small and simple. A README is included. >> >>I hope the list accepts attachments. >> >>Regards, >> >>Rainer >> >>Am 10.11.2015 um 16:45 schrieb Rainer Jung: >>>There's a bug in the Solaris specific HotSpot code which exhibits itself >>>as extremely long pauses directly after GC log rotation. >>> >>>The bug can be seen in 1.7.0 patchlevel 80 and above, 1.8.0 patchlevel >>>20 and above and 1.9.0. It was noticed using >>>-XX:PrintGCApplicationStoppedTime. >>> >>>During GC log rotation the function os::printmemoryinfo() in >>>src/os/solaris/vm/ossolaris.cpp is called, which itself calls >>>checkaddr0(). >>> >>>Now checkaddr0() reads the file /proc/self/pmap, but does this entry by >>>entry. Productive Java processes often have 1000 and more map entries >>>(e.g. each thread stack is one entry, often each jar etc. >>> >>>Reading one entry takes about 35-40ms in a zone on a T4 system. Reading >>>e.g. 1000 entries takes 35-40 seconds during which the JVM is stopped. >>>We experienced even stop times up until 2400 seconds in extreme cases. >>> >>>Note that this doesn't have to do with GC. It only happens directly >>>after GC log file rotation. >>> >>>The bug is reading the file entry by entry instead of using pread() to >>>read it in one go. Look for instance at the source code of the Solaris >>>command "pmap" which uses pread() to read the file at once. >>> >>>It might also be questioned, whether this map file check must happen >>>during a safepoint or could also be done outside, only synchronizing in >>>case a hit was found and a warning actually needs to be written to the >>>log file. >>> >>>The bug was shadowed by another bug until and including 1.7.076 and >>>1.8.011: the close() that closes the map file after reading the entries >>>was erroneously put inside the read loop instead of after the read loop. >>>Thus these versions only read the first entry, then closed the file and >>>erred out when trying to read the next entry. So reading was quick. >>> >>>The responsible change was: >>> >>>Java 8: >>>http://hg.openjdk.java.net/jdk8u/jdk8u/hotspot/diff/7d28f4e15b61/src/os/solaris/vm/ossolaris.cpp >>> >>> >>> >>>Java 7: >>>http://hg.openjdk.java.net/jdk7u/jdk7u/hotspot/diff/e50eb3195734/src/os/solaris/vm/ossolaris.cpp >>> >>> >>> >>>Example code for reading using pread() (going back to OpenSolaris): >>> >>>https://github.com/joyent/illumos-joyent/blob/master/usr/src/cmd/ptools/pmap/pmap.c >>> >>> >>> >>>Look e.g. at function xmappingiter() and there look for pread(). >>> >>>See also the discussion thread starting at >>>http://mail.openjdk.java.net/pipermail/hotspot-gc-use/2015-November/002351.html. >>> >>> >>> >>>The analysis was done using source code review and realtime checks with >>>pstack and truss. It would be nice if you could instruct me how to get >>>this fixed. It is a bit specific because it only happens on Solaris and >>>when GC log rotation is active, but Solaris should be an important >>>platform for Oracle and GC log rotation will be used more and more. >>> >>>I do not have a support contract. >>> >>>Regards, >>> >>>Rainer

----- End forwarded message -----

More information about the hotspot-runtime-dev mailing list