loss of cause??

STIRLING, SCOTT ss4766 at att.com
Fri Oct 11 13:59:43 UTC 2013 

I think that's brilliant - regression tests for the GC log formats. Probably non-trivial to do, since each build would have to run and generate some GC logging, but definitely a good idea. As you stated, there are many tools and scripts out there dependent on the JVM GC logs. Not everything is using JMX or JVMTI to obtain GC metrics, by-passing the logs. And there's so much useful information in the logs, they have been critical for us in AT&T e-comm hosting (where we host many "big box" retailers) many times for troubleshooting production issues. Sometimes they are the only available historical trace of an issue's existence. They're indispensable.

Scott Stirling
AT&T, Boston

-----Original Message-----
From: Kirk Pepperdine [mailto:kirk at kodewerk.com] 
Sent: Friday, October 11, 2013 2:32 AM
To: STIRLING, SCOTT
Cc: Mikael Gerdin; hotspot-gc-dev at openjdk.java.net openjdk.java.net
Subject: Re: loss of cause??

Hi Scott,

Indeed I did mention the logging JEP. I was thinking at that time of dedicating some time to adjusting GC logging in the JVM. However I put that on hold when the logging JEP showed up. IMHO, that JEP needs work before it's implemented. But that is a different topic. Over the last couple of days I've been thinking about converting my parsers to a big test and then just test then schedule tests against the most recent checkins of OpenJDK. I will not cover everything but I can focus on the most common/useful settings.

Regards,
Kirk

On 2013-10-11, at 3:32 AM, "STIRLING, SCOTT" <ss4766 at att.com> wrote:

> Hi Kirk - I dug up and checked my notes from JavaOne last year. You referenced the JEP below when I had asked a general question about GC logging format vagaries (which had gotten worse with CMS and are even worse with multiple threads writing interleaving log messages in the GC log ...):
> 
> http://openjdk.java.net/jeps/158 on "Unified JVM Logging"
> 
> I notice it mentions there "It is also outside the scope of the JEP to enforce a logging format, apart from the format of the decorations and the use of human-readable plain text." :-/
> 
> Scott S
> AT&T, Boston
> 
> -----Original Message-----
> From: Kirk Pepperdine [mailto:kirk at kodewerk.com] 
> Sent: Thursday, October 10, 2013 6:37 PM
> To: STIRLING, SCOTT
> Cc: Mikael Gerdin; hotspot-gc-dev at openjdk.java.net openjdk.java.net
> Subject: Re: loss of cause??
> 
> Hi Scott,
> 
> I don't think I've every talked about a standardized log format. I don't see how you could create one. However there are things you could do to make it easier to parse. Moving to XML wouldn't be one of my favourite choices. However you are correct in saying that the loosely structured log format that changes and takes on bugs from one build to the next is a problem. GC logging is the absolute best way to know whats going on and it provides the highest quality information for tuning purposes. It's easy to collect and it provides a whole hosts of values. For example, I can detect poor testing regimes by looking at the data, I've debugged strange memory conditions, found problems with frameworks. You simply cannot do these deeper types of analysis with any of the other sources of info about the collectors.
> 
> I'll take the weak formatting.. I can work with it but this rejiggering of the format for some what arbitrary reasons is a problem. In this case I can see the need to be an alignment for 8. However, I wish the alignment didn't come with this regression and one has to ask, how come the output is different on Window, Linux and OSX for the same build?
> 
> Regards,
> Kirk
> 
> On 2013-10-11, at 12:16 AM, "STIRLING, SCOTT" <ss4766 at att.com> wrote:
> 
>> I thought there was a JSR to standardize on the log format, or had heard that a couple years ago at JavaOne in SFO. Might've been at one of Kirk's presentations, if I recall! I remember asking about it. IBM, for example, at least has an XML format to the JVM GC log so you can write tools around a parseable DOM -- but Sun, for years and years, has had this ad hoc, increasingly difficult to parse, loosely structured log format that changes regularly. It's kind of out of control ...
>> 
>> FWIW,
>> Scott Stirling
>> AT&T, Boston
>> 
>> -----Original Message-----
>> From: hotspot-gc-dev-bounces at openjdk.java.net [mailto:hotspot-gc-dev-bounces at openjdk.java.net] On Behalf Of Kirk Pepperdine
>> Sent: Thursday, October 10, 2013 4:20 PM
>> To: Mikael Gerdin
>> Cc: hotspot-gc-dev at openjdk.java.net openjdk.java.net
>> Subject: Re: loss of cause??
>> 
>> Hi Mikael,
>> 
>> Thanks for the response. I'm aware of the flag. But more importantly I want, and I think I can speak for other, is for the log formats to remain stable. These things are painful enough to parse without having to compensate for variations not only across builds but across different OS'es.
>> 
>> Kind regards,
>> Kirk Pepperdine
>> 
>> On 2013-10-10, at 4:00 PM, Mikael Gerdin <mikael.gerdin at oracle.com> wrote:
>> 
>>> On 10/10/2013 03:46 PM, Pierre Laporte wrote:
>>>> This is also true for Linux :
>>>> http://www.pingtimeout.fr/2013/08/gc-log-format-change.html
>>> 
>>> If you want the GC causes for all gcs in 7u40 please use -XX:+PrintGCCause
>>> 
>>> /Mikael
>>> 
>>>> 
>>>> 
>>>> On Thu, Oct 10, 2013 at 3:30 PM, Kirk Pepperdine <kirk at kodewerk.com
>>>> <mailto:kirk at kodewerk.com>> wrote:
>>>> 
>>>>  Hi all,
>>>> 
>>>>  I've just noticed this in a GC log.
>>>> 
>>>>  642.015: [Full GC [PSYoungGen: 1904K->0K(79360K)] [ParOldGen:
>>>>  337438K->338524K(442368K)] 339342K->338524K(521728K) [PSPermGen:
>>>>  13239K->13239K(21504K)], 4.4455297 secs] [Times: user=7.94 sys=0.02,
>>>>  real=4.44 secs]
>>>> 
>>>> 
>>>>  This collection was triggered by a call to System.gc().
>>>> 
>>>>  More info
>>>>  D:\dev\>"C:\Program Files\Java\jdk1.7.0_40\bin\java" -version
>>>>  java version "1.7.0_40"
>>>>  Java(TM) SE Runtime Environment (build 1.7.0_40-b43)
>>>>  Java HotSpot(TM) 64-Bit Server VM (build 24.0-b56, mixed mode)
>>>> 
>>>>  Flags used -Xloggc:gc.log -XX:+PrintGCDetails
>>>> 
>>>> 
>>>>  Same app running in OSX produces;
>>>> 
>>>>  2.435: [Full GC (System) [PSYoungGen: 32K->0K(24064K)] [ParOldGen:
>>>>  3666K->3666K(54976K)] 3698K->3666K(79040K) [PSPermGen:
>>>>  9620K->9620K(22272K)], 0.0311970 secs] [Times: user=0.06 sys=0.00,
>>>>  real=0.03 secs]
>>>> 
>>>>  Obviously triggered by a full GC
>>>> 
>>>>  flash-2:kirk$ java -version
>>>>  java version "1.7.0_40"
>>>>  Java(TM) SE Runtime Environment (build 1.7.0_40-b43)
>>>>  Java HotSpot(TM) 64-Bit Server VM (build 24.0-b56, mixed mode)
>>>> 
>>>>  Flags used -Xloggc:gc.log -XX:+PrintGCDetails
>>>> 
>>>>  I've not checked for this on Linux yet.
>>>> 
>>>>  So, it looks as though the (System) has been lost on windows?
>>>> 
>>>>  Regards,
>>>>  Kirk
>>>> 
>>>> 
>>>> 
>>>> 
>>>> 
>>>> 
>>>> 
>>>> 
>>>> 
>>>> 
>>>> --
>>>> 
>>>> Pierre Laporte
>>>> @pingtimeout <https://twitter.com/pingtimeout>
>>>> pierre at pingtimeout.fr <mailto:pierre at pingtimeout.fr>
>>>> http://www.pingtimeout.fr/
>>> 
>> 
>

More information about the hotspot-gc-dev mailing list