Jrockit 1.5 support ? about gcviewer

[rupeshr-zz]

A few months ago, I had added JRockit 1.6 support to the latest codebase.
The same JRockit 1.6 reader works for JRockit 1.5 as well, as far as I can
tell (I am able to parse your logs below without issues). I did have to put
in an enhancement to support -Xverbosetimestamp though, before it worked. I
will check that code in and do a pull request.

On Mon, Nov 12, 2012 at 8:35 AM, dramezh [email protected] wrote:

Is GCViewer supports JRockit 1.5's GC logs ? Coz i am not able view GC
logs generated on one of my application running on JRockit 1.5.

-Xverboselog:gc.log
-verbose:memory
-Xverbose:gcpause,gcreport
-Xverbosetimestamp

[memory ][Sat Oct 27 20:01:49 2012][23355] Running with 32 bit heap and
compressed references supporting 32GB heap.
[memory ][Sat Oct 27 20:01:49 2012][23355] GC mode: Garbage collection
optimized for short pausetimes, strategy: Generational Concurrent Mark &
Sweep.
[memory ][Sat Oct 27 20:01:49 2012][23355] Heap size: 25165824KB, maximal
heap size: 25165824KB, nursery size: 4194304KB.
[memory ][Sat Oct 27 20:01:49 2012][23355] -: KB->KB (KB), ms, sum of
pauses ms.
[memory ][Sat Oct 27 20:01:49 2012][23355] - start time of collection
(seconds since jvm start).
[memory ][Sat Oct 27 20:01:49 2012][23355] - OC (old collection) or YC
(young collection).
[memory ][Sat Oct 27 20:01:49 2012][23355] - end time of collection
(seconds since jvm start).
[memory ][Sat Oct 27 20:01:49 2012][23355] - memory used by objects before
collection (KB).
[memory ][Sat Oct 27 20:01:49 2012][23355] - memory used by objects after
collection (KB).
[memory ][Sat Oct 27 20:01:49 2012][23355] - size of heap after collection
(KB).
[memory ][Sat Oct 27 20:01:49 2012][23355] - total time of collection
(milliseconds).
[memory ][Sat Oct 27 20:01:49 2012][23355] - total sum of pauses during
collection (milliseconds).
[memory ][Sat Oct 27 20:01:49 2012][23355] Run with -Xverbose:gcpause to
see individual phases.
[gcpause][Sat Oct 27 20:04:38 2012][23355] [YC#1] [---] 468.690 ms
(168.027000-168.495000) YC
[gcpause][Sat Oct 27 20:04:38 2012][23355] [YC#1] [con] 0.004 ms
(168.027000-168.027000) YC:PreGC
[gcpause][Sat Oct 27 20:04:38 2012][23355] [YC#1] [pau] 468.590 ms
(168.027000-168.495000) YC:Main
[gcpause][Sat Oct 27 20:04:38 2012][23355] [YC#1] [con] 0.010 ms
(168.495000-168.495000) YC:PostGC
[memory ][Sat Oct 27 20:04:38 2012][23355] [YC#1] 168.027-168.495: YC
4263587KB->1265249KB (25165824KB), 0.469 s, sum of pauses 468.590 ms,
longest pause 468.590 ms.
[gcpause][Sat Oct 27 20:04:38 2012][23355] Thread "[ACTIVE] ExecuteThread:
'0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60
tid=23444 was in TLA-fetch 468.827 ms from 168.027 s (1 GCs).
[gcpause][Sat Oct 27 20:06:20 2012][23355] [YC#2] [---] 645.670 ms
(270.685000-271.330000) YC
[gcpause][Sat Oct 27 20:06:20 2012][23355] [YC#2] [con] 0.003 ms
(270.685000-270.685000) YC:PreGC
[gcpause][Sat Oct 27 20:06:20 2012][23355] [YC#2] [pau] 645.545 ms
(270.685000-271.330000) YC:Main
[gcpause][Sat Oct 27 20:06:20 2012][23355] [YC#2] [con] 0.030 ms
(271.330000-271.330000) YC:PostGC
[memory ][Sat Oct 27 20:06:20 2012][23355] [YC#2] 270.685-271.330: YC
4435053KB->1543400KB (25165824KB), 0.646 s, sum of pauses 645.545 ms,
longest pause 645.545 ms.
[gcpause][Sat Oct 27 20:06:20 2012][23355] Thread "[ACTIVE] ExecuteThread:
'0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60
tid=23444 was in TLA-fetch 646.349 ms from 270.684 s (1 GCs).
[gcpause][Sat Oct 27 20:08:25 2012][23355] [YC#3] [---] 612.496 ms
(394.948000-395.561000) YC
[gcpause][Sat Oct 27 20:08:25 2012][23355] [YC#3] [con] 0.003 ms
(394.948000-394.948000) YC:PreGC
[gcpause][Sat Oct 27 20:08:25 2012][23355] [YC#3] [pau] 612.295 ms
(394.949000-395.561000) YC:Main
[gcpause][Sat Oct 27 20:08:25 2012][23355] [YC#3] [con] 0.068 ms
(395.561000-395.561000) YC:PostGC
[memory ][Sat Oct 27 20:08:25 2012][23355] [YC#3] 394.948-395.561: YC
4696729KB->1891349KB (25165824KB), 0.612 s, sum of pauses 612.295 ms,
longest pause 612.295 ms.
[gcpause][Sat Oct 27 20:08:25 2012][23355] Thread "[ACTIVE] ExecuteThread:
'0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60
tid=23444 was in TLA-fetch 612.736 ms from 394.948 s (1 GCs).
[gcpause][Sat Oct 27 20:09:19 2012][23355] [YC#4] [---] 333.239 ms
(449.237000-449.570000) YC
[gcpause][Sat Oct 27 20:09:19 2012][23355] [YC#4] [con] 0.003 ms
(449.237000-449.237000) YC:PreGC
[gcpause][Sat Oct 27 20:09:19 2012][23355] [YC#4] [pau] 333.123 ms
(449.237000-449.570000) YC:Main
[gcpause][Sat Oct 27 20:09:19 2012][23355] [YC#4] [con] 0.038 ms
(449.570000-449.570000) YC:PostGC

Regards,
Ramesh

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/45.

[rdev1991]

thanks rupesh.

Whenever i try to drag drop this content. its showing the following error message

14-Nov-2012 11:03:47 com.tagtraum.perf.gcviewer.imp.DataReaderFactory getDataReader
SEVERE: Failed to recognize file format.

can you let me know which version of GCViewer that you are using?

or

adding Xverbosetimestamp will resolve my problem ?

[rupeshr-zz]

Sorry, not following you. What exactly are you doing when you get this
error? My code is in the master branch (not in latest build). If you get
the latest source from master and build GCViewer, you will have the JRockit
1.6 functionality. You will have to disable -Xverbosetimestamp for your
JRockit logs for now, when you use this version of GCViewer. I'm still in
the process of getting my -Xverbosetimestamp fix from last night merged
into the master.

On Wed, Nov 14, 2012 at 3:08 AM, dramezh [email protected] wrote:

thanks rupesh.

Whenever i try to drag drop this content. its showing the following error
message

14-Nov-2012 11:03:47 com.tagtraum.perf.gcviewer.imp.DataReaderFactory
getDataReader
SEVERE: Failed to recognize file format.

can you let me know which version of GCViewer that you are using?

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/45#issuecomment-10362563.

[rdev1991]

I am running weblogic 9 with JRockit JVM 1.5 version. I have add following parameter to print GC information on GC log

-Xverboselog:gc.log
-verbose:memory
-Xverbose:gcpause,gcreport
-Xverbosetimestamp

1. When i drag drop the generated file i am not able to view any graphs on GCViewer instead i am getting "Failed to recognize" message

2. Do i need add / Remove any parameter that will help me to view Logs in GCViewer?

Thanks,
Ramesh

[rupeshr-zz]

The latest downloadable version of GCViewer does not have this enhancement
yet. You will have to download the latest source code and build
gcviewer.jar yourself to get this feature.

On Thu, Nov 15, 2012 at 1:15 PM, dramezh [email protected] wrote:

I am running weblogic 9 with JRockit JVM 1.5 version. I have add following
parameter to print GC information on GC log

-Xverboselog:gc.log
-verbose:memory
-Xverbose:gcpause,gcreport
-Xverbosetimestamp

1. When i drag drop the generated file i am not able to view any graphs on
   GCViewer instead i am getting "Failed to recognize" message

2. Do i need add / Remove any parameter that will help me to view Logs in
   GCViewer?

Thanks,
Ramesh

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/45#issuecomment-10425736.

[ecki]

I was able to quickly set up a https://www.travis-ci.org build for my fork, and it actually build now on every push. However I dont know yet if and how to configure travis to actually distribute build results. Any ideas? This would allow us to have not only tests on commit but also get snapshot builds.

https://travis-ci.org/ecki/GCViewer

[chewiebug]

@ecki Setting up a build server to build snapshot releases sounds like a very good idea to me. I don't know travis-ci, but maybe I can find out how to get the build results.

@dramezh If we can't fetch snapshot builds from travis-ci soon, I'll publish a manual build of the latest snapshot version here.

@rupeshr Thank you for contributing another fix! I'll merge your pull request soon. I can't find much in your pull request yet. Your last push occurred 3 months ago. Did you really push what you want me to merge?

Regards, Jörg

[chewiebug]

@ecki I have found an article about publishing artifacts inside travis-ci to github. Does it help?

Regards, Jörg

[rupeshr-zz]

I'm still figuring out Git. I've staged and committed the two files I changed, but I don't see the changes on my own repository (forked from yours) when I do web file browse on github. I sent you a pull request and it showed 'two' changed files but looks like that didn't work. I also see a 'push' request option. Should I try that? I suspect the problem is with my code being out of sync with the 'upstream' repository. If all else fails, I will just redo the git client and code from scratch.

• Rupesh

On Nov 16, 2012, at 12:10 AM, chewiebug [email protected] wrote:

@ecki Setting up a build server to build snapshot releases sounds like a very good idea to me. I don't know travis-ci, but maybe I can find out how to get the build results.

@dramezh If we can't fetch snapshot builds from travis-ci soon, I'll publish a manual build of the latest snapshot version here.

@rupeshr Thank you for contributing another fix! I'll merge your pull request soon. I can't find much in your pull request yet. Your last push occurred 3 months ago. Did you really push what you want me to merge?

Regards, Jörg

—
Reply to this email directly or view it on GitHub.

[chewiebug]

Hi Rupesh

"Push" is just what you were looking for. I have sent you a separate
mail message to explain more details using git(hub).

Regards, Jörg

Am 17.11.2012 11:27, schrieb Rupesh Ramachandran:

I'm still figuring out Git. I've staged and committed the two files I
changed, but I don't see the changes on my own repository (forked from
yours) when I do web file browse on github. I sent you a pull request
and it showed 'two' changed files but looks like that didn't work. I
also see a 'push' request option. Should I try that? I suspect the
problem is with my code being out of sync with the 'upstream'
repository. If all else fails, I will just redo the git client and
code from scratch.

• Rupesh

On Nov 16, 2012, at 12:10 AM, chewiebug [email protected] wrote:

@ecki Setting up a build server to build snapshot releases sounds
like a very good idea to me. I don't know travis-ci, but maybe I can
find out how to get the build results.

@dramezh If we can't fetch snapshot builds from travis-ci soon, I'll
publish a manual build of the latest snapshot version here.

@rupeshr Thank you for contributing another fix! I'll merge your
pull request soon. I can't find much in your pull request yet. Your
last push occurred 3 months ago. Did you really push what you want me
to merge?

Regards, Jörg

—
Reply to this email directly or view it on GitHub.

—
Reply to this email directly or view it on GitHub
#45 (comment).

[chewiebug]

@ecki I'll move discussion about travis-ci to the mailing list to leave the issue related discussion here.

@dramezh I have automated build uploads to this projects github downloads section. The latest build there doesn't contain the fix rupesh provides yet. I'll update you here as soon as a download is available.

Regards, Jörg

[chewiebug]

Hi Ramesh,

I have been able to merge Rupesh's pull request. Now your log file should be parsable. Could you please check? I have uploaded the latest build (must show "2012-11-18 19:08" as build date; if it shows yesterdays date, plase wait a few hours and try again - github seems to have caches, which need to be invalidated).

Regards, Jörg

[rdev1991]

Sure Jorg, Let me download the latest build and try.

i am gonna use same settings as follows

-Xverboselog:gc.log
-verbose:memory
-Xverbose:gcpause,gcreport
-Xverbosetimestamp

[rdev1991]

Drag dropped the GC logs and getting "Failed to recognize file format." message

Log file size is 37.0 MB

[memory ][Sat Oct 27 00:43:52 2012][20525] Running with 64 bit heap and uncompressed references.
[memory ][Sat Oct 27 00:43:52 2012][20525] GC mode: Static, strategy: Generational Concurrent Mark & Sweep
[memory ][Sat Oct 27 00:43:52 2012][20525] heap size: 25165824K, maximal heap size: 25165824K, nursery size: 4194304K
[memory ][Sat Oct 27 00:43:52 2012][20525] -: GC K->K (K), ms
[memory ][Sat Oct 27 00:43:52 2012][20525] <s/start> - start time of collection (seconds since jvm start)
[memory ][Sat Oct 27 00:43:52 2012][20525] - end time of collection (seconds since jvm start)
[memory ][Sat Oct 27 00:43:52 2012][20525] - memory used by objects before collection (KB)
[memory ][Sat Oct 27 00:43:52 2012][20525] - memory used by objects after collection (KB)
[memory ][Sat Oct 27 00:43:52 2012][20525] - size of heap after collection (KB)
[memory ][Sat Oct 27 00:43:52 2012][20525] - total sum of pauses during collection (milliseconds)
[memory ][Sat Oct 27 00:43:52 2012][20525] run with -Xverbose:gcpause to see individual pauses
[memory ][Sat Oct 27 00:45:28 2012][20525] 94.809: parallel nursery GC 6340080K->3191147K (25165824K), 450.886 ms
[gcpause][Sat Oct 27 00:45:28 2012][20525] nursery collection pause time: 450.886000 ms
[memory ][Sat Oct 27 00:46:51 2012][20525] 178.156: parallel nursery GC 6339947K->3191147K (25165824K), 561.764 ms
[gcpause][Sat Oct 27 00:46:51 2012][20525] nursery collection pause time: 561.764000 ms
[memory ][Sat Oct 27 00:48:09 2012][20525] 256.306: parallel nursery GC 8222675K->5073696K (25165824K), 410.587 ms
[gcpause][Sat Oct 27 00:48:09 2012][20525] nursery collection pause time: 410.587000 ms
[memory ][Sat Oct 27 00:49:29 2012][20525] 335.816: parallel nursery GC 8222496K->5073608K (25165824K), 445.738 ms
[gcpause][Sat Oct 27 00:49:29 2012][20525] nursery collection pause time: 445.738000 ms
[memory ][Sat Oct 27 00:50:18 2012][20525] 385.450: parallel nursery GC 8230521K->5081603K (25165824K), 350.694 ms
[gcpause][Sat Oct 27 00:50:18 2012][20525] nursery collection pause time: 350.694000 ms
[memory ][Sat Oct 27 00:50:44 2012][20525] 410.992: parallel nursery GC 8237571K->5088741K (25165824K), 295.708 ms
[gcpause][Sat Oct 27 00:50:44 2012][20525] nursery collection pause time: 295.708000 ms
[memory ][Sat Oct 27 00:51:08 2012][20525] 435.667: parallel nursery GC 9941756K->6792636K (25165824K), 251.494 ms
[gcpause][Sat Oct 27 00:51:08 2012][20525] nursery collection pause time: 251.494000 ms
[memory ][Sat Oct 27 00:51:36 2012][20525] 463.088: parallel nursery GC 10024320K->6875392K (25165824K), 690.500 ms
[gcpause][Sat Oct 27 00:51:36 2012][20525] nursery collection pause time: 690.500000 ms
[memory ][Sat Oct 27 00:52:02 2012][20525] 489.544: parallel nursery GC 10045233K->6896049K (25165824K), 311.326 ms
[gcpause][Sat Oct 27 00:52:02 2012][20525] nursery collection pause time: 311.326000 ms
[memory ][Sat Oct 27 00:52:29 2012][20525] 516.060: parallel nursery GC 10044849K->6896038K (25165824K), 239.515 ms
[gcpause][Sat Oct 27 00:52:29 2012][20525] nursery collection pause time: 239.515000 ms
[memory ][Sat Oct 27 00:53:21 2012][20525] 568.431: parallel nursery GC 10044838K->6895719K (25165824K), 798.607 ms
[gcpause][Sat Oct 27 00:53:21 2012][20525] nursery collection pause time: 798.607000 ms
[memory ][Sat Oct 27 00:53:45 2012][20525] 591.841: parallel nursery GC 11558106K->8409178K (25165824K), 506.198 ms
[gcpause][Sat Oct 27 00:53:45 2012][20525] nursery collection pause time: 506.198000 ms
[memory ][Sat Oct 27 00:54:07 2012][20525] 615.062: parallel nursery GC 11557978K->8408986K (25165824K), 98.024 ms
[gcpause][Sat Oct 27 00:54:07 2012][20525] nursery collection pause time: 98.024000 ms
[memory ][Sat Oct 27 00:54:36 2012][20525] 643.650: parallel nursery GC 11557786K->8408538K (25165824K), 117.877 ms
[gcpause][Sat Oct 27 00:54:36 2012][20525] nursery collection pause time: 117.877000 ms
[memory ][Sat Oct 27 00:55:47 2012][20525] 714.247: parallel nursery GC 11557338K->8408425K (25165824K), 466.579 ms
[gcpause][Sat Oct 27 00:55:47 2012][20525] nursery collection pause time: 466.579000 ms
[memory ][Sat Oct 27 00:56:59 2012][20525] 785.961: parallel nursery GC 12918981K->9770069K (25165824K), 515.358 ms
[gcpause][Sat Oct 27 00:56:59 2012][20525] nursery collection pause time: 515.358000 ms
[memory ][Sat Oct 27 00:58:10 2012][20525] 856.755: parallel nursery GC 14144406K->10995557K (25165824K), 567.206 ms
[gcpause][Sat Oct 27 00:58:10 2012][20525] nursery collection pause time: 567.206000 ms
[memory ][Sat Oct 27 00:59:20 2012][20525] 926.769: parallel nursery GC 14144357K->10995535K (25165824K), 556.395 ms
[gcpause][Sat Oct 27 00:59:20 2012][20525] nursery collection pause time: 556.395000 ms
[memory ][Sat Oct 27 01:00:35 2012][20525] 1002.191: parallel nursery GC 15246952K->12097768K (25165824K), 532.456 ms
[gcpause][Sat Oct 27 01:00:35 2012][20525] nursery collection pause time: 532.456000 ms
[memory ][Sat Oct 27 01:01:42 2012][20525] 1069.091: parallel nursery GC 16424287K->13275103K (25165824K), 675.740 ms
[gcpause][Sat Oct 27 01:01:42 2012][20525] nursery collection pause time: 675.740000 ms
[memory ][Sat Oct 27 01:02:52 2012][20525] 1139.299: parallel nursery GC 17493574K->14344390K (25165824K), 609.278 ms
[gcpause][Sat Oct 27 01:02:52 2012][20525] nursery collection pause time: 609.278000 ms
[memory ][Sat Oct 27 01:03:22 2012][20525] 1169.394: parallel nursery GC 17493190K->14344262K (25165824K), 181.491 ms

[chewiebug]

Thank you for testing! I'll have to check with Rupesh where the problem might be.

Regards, Jörg

[chewiebug]

Hi Ramesh,

I pushed a fix concerning log recognition for JRockit 1.5.0. Now logs like the initial sample you sent should be parsed (build date: 2012-11-20 22:19).

Your second sample is recognized as JRockit but no information is collected. It looks completely different from the first sample. Do you have an idea why? You seem to have used the same parameters as for the initial sample.

Regards, Jörg

[rdev1991]

Apologies,my bad. I was playing around with log files.

this is the latest one taken today.

[memory ][Sat Nov 17 16:36:45 2012][20346] Running with 32 bit heap and compressed references supporting 32GB heap.
[memory ][Sat Nov 17 16:36:45 2012][20346] GC mode: Garbage collection optimized for short pausetimes, strategy: Generational Concurrent Mark & Sweep.
[memory ][Sat Nov 17 16:36:45 2012][20346] Heap size: 25165824KB, maximal heap size: 25165824KB, nursery size: 4194304KB.
[memory ][Sat Nov 17 16:36:45 2012][20346] -: KB->KB (KB), ms, sum of pauses ms.
[memory ][Sat Nov 17 16:36:45 2012][20346] - start time of collection (seconds since jvm start).
[memory ][Sat Nov 17 16:36:45 2012][20346] - OC (old collection) or YC (young collection).
[memory ][Sat Nov 17 16:36:45 2012][20346] - end time of collection (seconds since jvm start).
[memory ][Sat Nov 17 16:36:45 2012][20346] - memory used by objects before collection (KB).
[memory ][Sat Nov 17 16:36:45 2012][20346] - memory used by objects after collection (KB).
[memory ][Sat Nov 17 16:36:45 2012][20346] - size of heap after collection (KB).
[memory ][Sat Nov 17 16:36:45 2012][20346] - total time of collection (milliseconds).
[memory ][Sat Nov 17 16:36:45 2012][20346] - total sum of pauses during collection (milliseconds).
[memory ][Sat Nov 17 16:36:45 2012][20346] Run with -Xverbose:gcpause to see individual phases.
[gcpause][Sat Nov 17 16:41:52 2012][20346] [YC#1] [---] 428.868 ms (306.486000-306.915000) YC
[gcpause][Sat Nov 17 16:41:52 2012][20346] [YC#1] [con] 0.003 ms (306.486000-306.486000) YC:PreGC
[gcpause][Sat Nov 17 16:41:52 2012][20346] [YC#1] [pau] 428.647 ms (306.486000-306.914000) YC:Main
[gcpause][Sat Nov 17 16:41:52 2012][20346] [YC#1] [con] 0.074 ms (306.915000-306.915000) YC:PostGC
[memory ][Sat Nov 17 16:41:52 2012][20346] [YC#1] 306.486-306.915: YC 4264185KB->1261907KB (25165824KB), 0.429 s, sum of pauses 428.647 ms, longest pause 428.647 ms.
[gcpause][Sat Nov 17 16:41:52 2012][20346] Thread "AD Thread Pool-Global1" id=22 idx=0x4c tid=20366 was in TLA-fetch 429.038 ms from 306.486 s (1 GCs).
[gcpause][Sat Nov 17 16:44:06 2012][20346] [YC#2] [---] 603.673 ms (440.085000-440.688000) YC
[gcpause][Sat Nov 17 16:44:06 2012][20346] [YC#2] [con] 0.003 ms (440.085000-440.085000) YC:PreGC
[gcpause][Sat Nov 17 16:44:06 2012][20346] [YC#2] [pau] 603.530 ms (440.085000-440.688000) YC:Main
[gcpause][Sat Nov 17 16:44:06 2012][20346] [YC#2] [con] 0.017 ms (440.688000-440.688000) YC:PostGC
[memory ][Sat Nov 17 16:44:06 2012][20346] [YC#2] 440.085-440.688: YC 4420715KB->1572997KB (25165824KB), 0.604 s, sum of pauses 603.530 ms, longest pause 603.530 ms.
[gcpause][Sat Nov 17 16:44:06 2012][20346] Thread "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60 tid=20408 was in TLA-fetch 604.229 ms from 440.084 s (1 GCs).
[gcpause][Sat Nov 17 16:46:15 2012][20346] [YC#3] [---] 605.475 ms (569.340000-569.946000) YC
[gcpause][Sat Nov 17 16:46:15 2012][20346] [YC#3] [con] 0.003 ms (569.340000-569.340000) YC:PreGC
[gcpause][Sat Nov 17 16:46:15 2012][20346] [YC#3] [pau] 605.356 ms (569.340000-569.945000) YC:Main
[gcpause][Sat Nov 17 16:46:15 2012][20346] [YC#3] [con] 0.011 ms (569.946000-569.946000) YC:PostGC
[memory ][Sat Nov 17 16:46:15 2012][20346] [YC#3] 569.340-569.946: YC 4730583KB->1871450KB (25165824KB), 0.605 s, sum of pauses 605.356 ms, longest pause 605.356 ms.
[gcpause][Sat Nov 17 16:46:15 2012][20346] Thread "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60 tid=20408 was in TLA-fetch 605.771 ms from 569.340 s (1 GCs).
[gcpause][Sat Nov 17 16:46:48 2012][20346] [YC#4] [---] 295.757 ms (602.767000-603.063000) YC
[gcpause][Sat Nov 17 16:46:48 2012][20346] [YC#4] [con] 0.004 ms (602.767000-602.767000) YC:PreGC
[gcpause][Sat Nov 17 16:46:48 2012][20346] [YC#4] [pau] 295.617 ms (602.767000-603.062000) YC:Main
[gcpause][Sat Nov 17 16:46:48 2012][20346] [YC#4] [con] 0.035 ms (603.063000-603.063000) YC:PostGC
[memory ][Sat Nov 17 16:46:48 2012][20346] [YC#4] 602.767-603.063: YC 5043972KB->2045176KB (25165824KB), 0.296 s, sum of pauses 295.617 ms, longest pause 295.617 ms.
[gcpause][Sat Nov 17 16:46:48 2012][20346] Thread "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60 tid=20408 was in TLA-fetch 296.355 ms from 602.766 s (1 GCs).
[gcpause][Sat Nov 17 16:47:18 2012][20346] [YC#5] [---] 233.577 ms (633.220000-633.454000) YC
[gcpause][Sat Nov 17 16:47:18 2012][20346] [YC#5] [con] 0.003 ms (633.220000-633.220000) YC:PreGC
[gcpause][Sat Nov 17 16:47:18 2012][20346] [YC#5] [pau] 233.367 ms (633.220000-633.454000) YC:Main
[gcpause][Sat Nov 17 16:47:18 2012][20346] [YC#5] [con] 0.014 ms (633.454000-633.454000) YC:PostGC
[memory ][Sat Nov 17 16:47:18 2012][20346] [YC#5] 633.220-633.454: YC 5224513KB->2146423KB (25165824KB), 0.234 s, sum of pauses 233.367 ms, longest pause 233.367 ms.
[gcpause][Sat Nov 17 16:47:44 2012][20346] [YC#6] [---] 341.869 ms (659.203000-659.545000) YC
[gcpause][Sat Nov 17 16:47:44 2012][20346] [YC#6] [con] 0.004 ms (659.203000-659.203000) YC:PreGC
[gcpause][Sat Nov 17 16:47:44 2012][20346] [YC#6] [pau] 341.655 ms (659.203000-659.544000) YC:Main
[gcpause][Sat Nov 17 16:47:44 2012][20346] [YC#6] [con] 0.137 ms (659.545000-659.545000) YC:PostGC
[memory ][Sat Nov 17 16:47:44 2012][20346] [YC#6] 659.203-659.545: YC 5368719KB->2295896KB (25165824KB), 0.342 s, sum of pauses 341.655 ms, longest pause 341.655 ms.
[gcpause][Sat Nov 17 16:47:44 2012][20346] Thread "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60 tid=20408 was in TLA-fetch 342.275 ms from 659.203 s (1 GCs).
[gcpause][Sat Nov 17 16:48:18 2012][20346] [YC#7] [---] 423.353 ms (692.258000-692.681000) YC
[gcpause][Sat Nov 17 16:48:18 2012][20346] [YC#7] [con] 0.003 ms (692.258000-692.258000) YC:PreGC
[gcpause][Sat Nov 17 16:48:18 2012][20346] [YC#7] [pau] 423.188 ms (692.258000-692.681000) YC:Main
[gcpause][Sat Nov 17 16:48:18 2012][20346] [YC#7] [con] 0.046 ms (692.681000-692.681000) YC:PostGC
[memory ][Sat Nov 17 16:48:18 2012][20346] [YC#7] 692.258-692.681: YC 5477122KB->2491626KB (25165824KB), 0.423 s, sum of pauses 423.188 ms, longest pause 423.188 ms.
[gcpause][Sat Nov 17 16:48:18 2012][20346] Thread "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60 tid=20408 was in TLA-fetch 423.505 ms from 692.258 s (1 GCs).
[gcpause][Sat Nov 17 16:48:45 2012][20346] [YC#8] [---] 207.027 ms (719.427000-719.634000) YC
[gcpause][Sat Nov 17 16:48:45 2012][20346] [YC#8] [con] 0.003 ms (719.427000-719.427000) YC:PreGC
[gcpause][Sat Nov 17 16:48:45 2012][20346] [YC#8] [pau] 206.618 ms (719.427000-719.633000) YC:Main
[gcpause][Sat Nov 17 16:48:45 2012][20346] [YC#8] [con] 0.012 ms (719.634000-719.634000) YC:PostGC
[memory ][Sat Nov 17 16:48:45 2012][20346] [YC#8] 719.427-719.634: YC 5647903KB->2578740KB (25165824KB), 0.207 s, sum of pauses 206.618 ms, longest pause 206.618 ms.
[gcpause][Sat Nov 17 16:49:53 2012][20346] [YC#9] [---] 607.777 ms (787.930000-788.538000) YC
[gcpause][Sat Nov 17 16:49:53 2012][20346] [YC#9] [con] 0.003 ms (787.930000-787.930000) YC:PreGC
[gcpause][Sat Nov 17 16:49:53 2012][20346] [YC#9] [pau] 607.584 ms (787.930000-788.538000) YC:Main
[gcpause][Sat Nov 17 16:49:53 2012][20346] [YC#9] [con] 0.064 ms (788.538000-788.538000) YC:PostGC
[memory ][Sat Nov 17 16:49:53 2012][20346] [YC#9] 787.930-788.538: YC 5779111KB->2810723KB (25165824KB), 0.608 s, sum of pauses 607.584 ms, longest pause 607.584 ms.
[gcpause][Sat Nov 17 16:49:53 2012][20346] Thread "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60 tid=20408 was in TLA-fetch 608.107 ms from 787.930 s (1 GCs).
[gcpause][Sat Nov 17 16:50:25 2012][20346] [YC#10] [---] 1503.319 ms (818.785000-820.289000) YC
[gcpause][Sat Nov 17 16:50:25 2012][20346] [YC#10] [con] 0.003 ms (818.785000-818.785000) YC:PreGC
[gcpause][Sat Nov 17 16:50:25 2012][20346] [YC#10] [pau] 1502.644 ms (818.786000-820.288000) YC:Main
[gcpause][Sat Nov 17 16:50:25 2012][20346] [YC#10] [con] 0.045 ms (820.289000-820.289000) YC:PostGC
[memory ][Sat Nov 17 16:50:25 2012][20346] [YC#10] 818.785-820.289: YC 5965811KB->3233066KB (25165824KB), 1.503 s, sum of pauses 1502.644 ms, longest pause 1502.644 ms.
[gcpause][Sat Nov 17 16:50:50 2012][20346] [YC#11] [---] 84.161 ms (845.311000-845.396000) YC
[gcpause][Sat Nov 17 16:50:50 2012][20346] [YC#11] [con] 0.003 ms (845.311000-845.311000) YC:PreGC
[gcpause][Sat Nov 17 16:50:50 2012][20346] [YC#11] [pau] 83.695 ms (845.312000-845.395000) YC:Main
[gcpause][Sat Nov 17 16:50:50 2012][20346] [YC#11] [con] 0.015 ms (845.396000-845.396000) YC:PostGC
[memory ][Sat Nov 17 16:50:50 2012][20346] [YC#11] 845.311-845.396: YC 6385950KB->3273605KB (25165824KB), 0.084 s, sum of pauses 83.695 ms, longest pause 83.695 ms.
[gcpause][Sat Nov 17 16:51:15 2012][20346] [YC#12] [---] 108.392 ms (870.423000-870.531000) YC
[gcpause][Sat Nov 17 16:51:15 2012][20346] [YC#12] [con] 0.003 ms (870.423000-870.423000) YC:PreGC
[gcpause][Sat Nov 17 16:51:15 2012][20346] [YC#12] [pau] 108.262 ms (870.423000-870.531000) YC:Main
[gcpause][Sat Nov 17 16:51:15 2012][20346] [YC#12] [con] 0.013 ms (870.531000-870.531000) YC:PostGC

[rdev1991]

getting same exception.

[chewiebug]

Hi Ramesh

I am working on improving the error message. I'll inform you of the next
version.

Regards, Jörg

[chewiebug]

Hi Ramesh

I have just pushed a fix and updated the SNAPSHOT-version of gcviewer. Could you please check against your log file?

If you should still get a "Failed to recognize file format." message it should be verbose enough for me to track down the source of the problem with your log file.

Regards, Jörg

[rdev1991]

downloaded a fresh log today and tested..
its working perfectly....

you guys rocks :)

[rdev1991]

i am having 5 different env having JRockit 1.5. i will check others and update you.

cheers.

[chewiebug]

I am glad, that it works. Looking forward to hearing from your other tests - thank you for taking the time!

Regards, Jörg

[rupeshr-zz]

Sorry, been too busy to reply. But I'm glad it worked. Jorg, thanks for
creating the SNAPSHOT build.
Ramesh, if you have a JRockit 1.6 env, would appreciate if you could test
it out there as well. I've tested with lot of JRockit verbose gc flags, but
I'm sure there's something I missed.

-Rupesh

On Thu, Nov 29, 2012 at 2:30 AM, Ramesh Devaraj [email protected]:

i am having 5 different env having JRockit 1.5. i will check others and
update you.

cheers.

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/45#issuecomment-10842098.

[rupeshr-zz]

Talking to JRockit experts at Oracle, it seems there is no equivalent of Hotspot's Full GC in JRockit, just the old collection (OC in logs). Nonetheless, I'd like to see OC in JRockit treated like Full GC for charting and stats and find that more useful. Let me know if anyone disagrees.

• Rupesh

On Dec 1, 2012, at 9:33 AM, chewiebug [email protected] wrote:

I am glad, that it works. Looking forward to hearing from your other tests - thank you for taking the time!

Regards, Jörg

—
Reply to this email directly or view it on GitHub.

[rdev1991]

out of 5 env one of env having different version of jrockit

Dev 1

java version "1.5.0_12"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_12-b04)
BEA JRockit(R) (build R27.4.0-90-89592-1.5.0_12-20070928-1715-linux-x86_64, compiled mode)

Dev 2
java version "1.5.0_34"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_34-b03)
Oracle JRockit(R) (build R28.2.3-13-149708-1.5.0_34-20120327-1523-linux-x86_64, compiled mode)

In Dev 1

[memory ][Tue Nov 27 20:46:32 2012][07945] Running with 64 bit heap and uncompressed references.
[memory ][Tue Nov 27 20:46:32 2012][07945] GC mode: Static, strategy: Generational Concurrent Mark & Sweep
[memory ][Tue Nov 27 20:46:32 2012][07945] heap size: 25165824K, maximal heap size: 25165824K, nursery size: 4194304K
[memory ][Tue Nov 27 20:46:32 2012][07945] -: GC K->K (K), ms
[memory ][Tue Nov 27 20:46:32 2012][07945] <s/start> - start time of collection (seconds since jvm start)
[memory ][Tue Nov 27 20:46:32 2012][07945] - end time of collection (seconds since jvm start)
[memory ][Tue Nov 27 20:46:32 2012][07945] - memory used by objects before collection (KB)
[memory ][Tue Nov 27 20:46:32 2012][07945] - memory used by objects after collection (KB)
[memory ][Tue Nov 27 20:46:32 2012][07945] - size of heap after collection (KB)
[memory ][Tue Nov 27 20:46:32 2012][07945] - total sum of pauses during collection (milliseconds)
[memory ][Tue Nov 27 20:46:32 2012][07945] run with -Xverbose:gcpause to see individual pauses
[memory ][Tue Nov 27 20:47:59 2012][07945] 86.338: parallel nursery GC 6342580K->3193677K (25165824K), 377.950 ms
[gcpause][Tue Nov 27 20:47:59 2012][07945] nursery collection pause time: 377.950000 ms
[memory ][Tue Nov 27 20:49:23 2012][07945] 170.474: parallel nursery GC 6342477K->3193589K (25165824K), 431.549 ms
[gcpause][Tue Nov 27 20:49:23 2012][07945] nursery collection pause time: 431.549000 ms
[memory ][Tue Nov 27 20:50:53 2012][07945] 260.912: parallel nursery GC 8225175K->5076375K (25165824K), 437.175 ms
[gcpause][Tue Nov 27 20:50:53 2012][07945] nursery collection pause time: 437.175000 ms
[memory ][Tue Nov 27 20:52:22 2012][07945] 349.327: parallel nursery GC 8225175K->5076258K (25165824K), 427.192 ms
[gcpause][Tue Nov 27 20:52:22 2012][07945] nursery collection pause time: 427.192000 ms
[memory ][Tue Nov 27 20:53:19 2012][07945] 406.469: parallel nursery GC 8233244K->5084331K (25165824K), 368.508 ms
[gcpause][Tue Nov 27 20:53:19 2012][07945] nursery collection pause time: 368.508000 ms
[memory ][Tue Nov 27 20:53:44 2012][07945] 431.552: parallel nursery GC 8243165K->5094301K (25165824K), 288.407 ms
[gcpause][Tue Nov 27 20:53:44 2012][07945] nursery collection pause time: 288.407000 ms
[memory ][Tue Nov 27 20:54:08 2012][07945] 456.082: parallel nursery GC 8256491K->5160146K (25165824K), 257.011 ms
[gcpause][Tue Nov 27 20:54:08 2012][07945] nursery collection pause time: 257.011000 ms
[memory ][Tue Nov 27 20:54:35 2012][07945] 482.139: parallel nursery GC 10078452K->6929460K (25165824K), 558.459 ms
[gcpause][Tue Nov 27 20:54:35 2012][07945] nursery collection pause time: 558.459000 ms
[memory ][Tue Nov 27 20:54:59 2012][07945] 506.868: parallel nursery GC 10106139K->6957339K (25165824K), 312.258 ms
[gcpause][Tue Nov 27 20:54:59 2012][07945] nursery collection pause time: 312.258000 ms
[memory ][Tue Nov 27 20:55:22 2012][07945] 530.069: parallel nursery GC 10106651K->6957787K (25165824K), 179.281 ms
[gcpause][Tue Nov 27 20:55:22 2012][07945] nursery collection pause time: 179.281000 ms
[memory ][Tue Nov 27 20:56:02 2012][07945] 569.325: parallel nursery GC 10106587K->6957659K (25165824K), 644.698 ms
[gcpause][Tue Nov 27 20:56:02 2012][07945] nursery collection pause time: 644.698000 ms
[memory ][Tue Nov 27 20:56:51 2012][07945] 618.198: parallel nursery GC 11613124K->8463876K (25165824K), 725.479 ms
[gcpause][Tue Nov 27 20:56:51 2012][07945] nursery collection pause time: 725.479000 ms
[memory ][Tue Nov 27 20:57:13 2012][07945] 641.285: parallel nursery GC 11613188K->8464388K (25165824K), 174.086 ms
[gcpause][Tue Nov 27 20:57:13 2012][07945] nursery collection pause time: 174.086000 ms
[memory ][Tue Nov 27 20:57:36 2012][07945] 663.828: parallel nursery GC 11613700K->8464708K (25165824K), 130.922 ms
[gcpause][Tue Nov 27 20:57:36 2012][07945] nursery collection pause time: 130.922000 ms
[memory ][Tue Nov 27 20:58:13 2012][07945] 701.379: parallel nursery GC 11613508K->8464452K (25165824K), 138.026 ms
[gcpause][Tue Nov 27 20:58:13 2012][07945] nursery collection pause time: 138.026000 ms
[memory ][Tue Nov 27 20:59:31 2012][07945] 778.216: parallel nursery GC 11613252K->8464324K (25165824K), 432.334 ms
[gcpause][Tue Nov 27 20:59:31 2012][07945] nursery collection pause time: 432.334000 ms
[memory ][Tue Nov 27 21:00:48 2012][07945] 855.609: parallel nursery GC 12969391K->9820591K (25165824K), 459.515 ms
[gcpause][Tue Nov 27 21:00:48 2012][07945] nursery collection pause time: 459.515000 ms
[memory ][Tue Nov 27 21:02:06 2012][07945] 933.180: parallel nursery GC 14189577K->11040738K (25165824K), 430.249 ms
[gcpause][Tue Nov 27 21:02:06 2012][07945] nursery collection pause time: 430.249000 ms
[memory ][Tue Nov 27 21:03:22 2012][07945] 1009.390: parallel nursery GC 14189538K->11040354K (25165824K), 499.022 ms
[gcpause][Tue Nov 27 21:03:22 2012][07945] nursery collection pause time: 499.022000 ms
[memory ][Tue Nov 27 21:04:42 2012][07945] 1089.308: parallel nursery GC 15287288K->12138232K (25165824K), 509.388 ms
[gcpause][Tue Nov 27 21:04:42 2012][07945] nursery collection pause time: 509.388000 ms
[memory ][Tue Nov 27 21:05:56 2012][07945] 1163.268: parallel nursery GC 16537519K->13388655K (25165824K), 602.746 ms
[gcpause][Tue Nov 27 21:05:56 2012][07945] nursery collection pause time: 602.746000 ms

Dev 2

[memory ][Sat Nov 17 16:36:45 2012][20346] Running with 32 bit heap and compressed references supporting 32GB heap.
[memory ][Sat Nov 17 16:36:45 2012][20346] GC mode: Garbage collection optimized for short pausetimes, strategy: Generational Concurrent Mark & Sweep.
[memory ][Sat Nov 17 16:36:45 2012][20346] Heap size: 25165824KB, maximal heap size: 25165824KB, nursery size: 4194304KB.
[memory ][Sat Nov 17 16:36:45 2012][20346] -: KB->KB (KB), ms, sum of pauses ms.
[memory ][Sat Nov 17 16:36:45 2012][20346] - start time of collection (seconds since jvm start).
[memory ][Sat Nov 17 16:36:45 2012][20346] - OC (old collection) or YC (young collection).
[memory ][Sat Nov 17 16:36:45 2012][20346] - end time of collection (seconds since jvm start).
[memory ][Sat Nov 17 16:36:45 2012][20346] - memory used by objects before collection (KB).
[memory ][Sat Nov 17 16:36:45 2012][20346] - memory used by objects after collection (KB).
[memory ][Sat Nov 17 16:36:45 2012][20346] - size of heap after collection (KB).
[memory ][Sat Nov 17 16:36:45 2012][20346] - total time of collection (milliseconds).
[memory ][Sat Nov 17 16:36:45 2012][20346] - total sum of pauses during collection (milliseconds).
[memory ][Sat Nov 17 16:36:45 2012][20346] Run with -Xverbose:gcpause to see individual phases.
[gcpause][Sat Nov 17 16:41:52 2012][20346] [YC#1] [---] 428.868 ms (306.486000-306.915000) YC
[gcpause][Sat Nov 17 16:41:52 2012][20346] [YC#1] [con] 0.003 ms (306.486000-306.486000) YC:PreGC
[gcpause][Sat Nov 17 16:41:52 2012][20346] [YC#1] [pau] 428.647 ms (306.486000-306.914000) YC:Main
[gcpause][Sat Nov 17 16:41:52 2012][20346] [YC#1] [con] 0.074 ms (306.915000-306.915000) YC:PostGC
[memory ][Sat Nov 17 16:41:52 2012][20346] [YC#1] 306.486-306.915: YC 4264185KB->1261907KB (25165824KB), 0.429 s, sum of pauses 428.647 ms, longest pause 428.647 ms.
[gcpause][Sat Nov 17 16:41:52 2012][20346] Thread "AD Thread Pool-Global1" id=22 idx=0x4c tid=20366 was in TLA-fetch 429.038 ms from 306.486 s (1 GCs).
[gcpause][Sat Nov 17 16:44:06 2012][20346] [YC#2] [---] 603.673 ms (440.085000-440.688000) YC
[gcpause][Sat Nov 17 16:44:06 2012][20346] [YC#2] [con] 0.003 ms (440.085000-440.085000) YC:PreGC
[gcpause][Sat Nov 17 16:44:06 2012][20346] [YC#2] [pau] 603.530 ms (440.085000-440.688000) YC:Main
[gcpause][Sat Nov 17 16:44:06 2012][20346] [YC#2] [con] 0.017 ms (440.688000-440.688000) YC:PostGC
[memory ][Sat Nov 17 16:44:06 2012][20346] [YC#2] 440.085-440.688: YC 4420715KB->1572997KB (25165824KB), 0.604 s, sum of pauses 603.530 ms, longest pause 603.530 ms.
[gcpause][Sat Nov 17 16:44:06 2012][20346] Thread "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60 tid=20408 was in TLA-fetch 604.229 ms from 440.084 s (1 GCs).
[gcpause][Sat Nov 17 16:46:15 2012][20346] [YC#3] [---] 605.475 ms (569.340000-569.946000) YC
[gcpause][Sat Nov 17 16:46:15 2012][20346] [YC#3] [con] 0.003 ms (569.340000-569.340000) YC:PreGC
[gcpause][Sat Nov 17 16:46:15 2012][20346] [YC#3] [pau] 605.356 ms (569.340000-569.945000) YC:Main
[gcpause][Sat Nov 17 16:46:15 2012][20346] [YC#3] [con] 0.011 ms (569.946000-569.946000) YC:PostGC
[memory ][Sat Nov 17 16:46:15 2012][20346] [YC#3] 569.340-569.946: YC 4730583KB->1871450KB (25165824KB), 0.605 s, sum of pauses 605.356 ms, longest pause 605.356 ms.
[gcpause][Sat Nov 17 16:46:15 2012][20346] Thread "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60 tid=20408 was in TLA-fetch 605.771 ms from 569.340 s (1 GCs).
[gcpause][Sat Nov 17 16:46:48 2012][20346] [YC#4] [---] 295.757 ms (602.767000-603.063000) YC
[gcpause][Sat Nov 17 16:46:48 2012][20346] [YC#4] [con] 0.004 ms (602.767000-602.767000) YC:PreGC
[gcpause][Sat Nov 17 16:46:48 2012][20346] [YC#4] [pau] 295.617 ms (602.767000-603.062000) YC:Main
[gcpause][Sat Nov 17 16:46:48 2012][20346] [YC#4] [con] 0.035 ms (603.063000-603.063000) YC:PostGC
[memory ][Sat Nov 17 16:46:48 2012][20346] [YC#4] 602.767-603.063: YC 5043972KB->2045176KB (25165824KB), 0.296 s, sum of pauses 295.617 ms, longest pause 295.617 ms.
[gcpause][Sat Nov 17 16:46:48 2012][20346] Thread "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=29 idx=0x60 tid=20408 was in TLA-fetch 296.355 ms from 602.766 s (1 GCs).
[gcpause][Sat Nov 17 16:47:18 2012][20346] [YC#5] [---] 233.577 ms (633.220000-633.454000) YC
[gcpause][Sat Nov 17 16:47:18 2012][20346] [YC#5] [con] 0.003 ms (633.220000-633.220000) YC:PreGC
[gcpause][Sat Nov 17 16:47:18 2012][20346] [YC#5] [pau] 233.367 ms (633.220000-633.454000) YC:Main
[gcpause][Sat Nov 17 16:47:18 2012][20346] [YC#5] [con] 0.014 ms (633.454000-633.454000) YC:PostGC

both completely diff but both are falls under jrockit 1.5. I need to check why i am having different version in Dev 1 but why this huge difference between 1.5.0_12 and 1.5.0_34

[rdev1991]

Will GC viewer support the JRockit 1.5.0_12 too ?

[rupeshr-zz]

I don't know any reason why it should not. If you have logs that wont
parse, please send it over and I'll take a look.

On Fri, Dec 7, 2012 at 4:06 AM, Ramesh Devaraj [email protected]:

Will GC viewer support the JRockit 1.5.0_12 too ?

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/45#issuecomment-11127683.

[rdev1991]

The log that i am not able to parse

In Dev 1

[memory ][Tue Nov 27 20:46:32 2012][07945] Running with 64 bit heap and uncompressed references.
[memory ][Tue Nov 27 20:46:32 2012][07945] GC mode: Static, strategy: Generational Concurrent Mark & Sweep
[memory ][Tue Nov 27 20:46:32 2012][07945] heap size: 25165824K, maximal heap size: 25165824K, nursery size: 4194304K
[memory ][Tue Nov 27 20:46:32 2012][07945] -: GC K->K (K), ms
[memory ][Tue Nov 27 20:46:32 2012][07945] - start time of collection (seconds since jvm start)
[memory ][Tue Nov 27 20:46:32 2012][07945] - end time of collection (seconds since jvm start)
[memory ][Tue Nov 27 20:46:32 2012][07945] - memory used by objects before collection (KB)
[memory ][Tue Nov 27 20:46:32 2012][07945] - memory used by objects after collection (KB)
[memory ][Tue Nov 27 20:46:32 2012][07945] - size of heap after collection (KB)
[memory ][Tue Nov 27 20:46:32 2012][07945] - total sum of pauses during collection (milliseconds)
[memory ][Tue Nov 27 20:46:32 2012][07945] run with -Xverbose:gcpause to see individual pauses
[memory ][Tue Nov 27 20:47:59 2012][07945] 86.338: parallel nursery GC 6342580K->3193677K (25165824K), 377.950 ms
[gcpause][Tue Nov 27 20:47:59 2012][07945] nursery collection pause time: 377.950000 ms
[memory ][Tue Nov 27 20:49:23 2012][07945] 170.474: parallel nursery GC 6342477K->3193589K (25165824K), 431.549 ms
[gcpause][Tue Nov 27 20:49:23 2012][07945] nursery collection pause time: 431.549000 ms
[memory ][Tue Nov 27 20:50:53 2012][07945] 260.912: parallel nursery GC 8225175K->5076375K (25165824K), 437.175 ms
[gcpause][Tue Nov 27 20:50:53 2012][07945] nursery collection pause time: 437.175000 ms
[memory ][Tue Nov 27 20:52:22 2012][07945] 349.327: parallel nursery GC 8225175K->5076258K (25165824K), 427.192 ms
[gcpause][Tue Nov 27 20:52:22 2012][07945] nursery collection pause time: 427.192000 ms
[memory ][Tue Nov 27 20:53:19 2012][07945] 406.469: parallel nursery GC 8233244K->5084331K (25165824K), 368.508 ms
[gcpause][Tue Nov 27 20:53:19 2012][07945] nursery collection pause time: 368.508000 ms
[memory ][Tue Nov 27 20:53:44 2012][07945] 431.552: parallel nursery GC 8243165K->5094301K (25165824K), 288.407 ms
[gcpause][Tue Nov 27 20:53:44 2012][07945] nursery collection pause time: 288.407000 ms
[memory ][Tue Nov 27 20:54:08 2012][07945] 456.082: parallel nursery GC 8256491K->5160146K (25165824K), 257.011 ms
[gcpause][Tue Nov 27 20:54:08 2012][07945] nursery collection pause time: 257.011000 ms
[memory ][Tue Nov 27 20:54:35 2012][07945] 482.139: parallel nursery GC 10078452K->6929460K (25165824K), 558.459 ms
[gcpause][Tue Nov 27 20:54:35 2012][07945] nursery collection pause time: 558.459000 ms
[memory ][Tue Nov 27 20:54:59 2012][07945] 506.868: parallel nursery GC 10106139K->6957339K (25165824K), 312.258 ms
[gcpause][Tue Nov 27 20:54:59 2012][07945] nursery collection pause time: 312.258000 ms
[memory ][Tue Nov 27 20:55:22 2012][07945] 530.069: parallel nursery GC 10106651K->6957787K (25165824K), 179.281 ms
[gcpause][Tue Nov 27 20:55:22 2012][07945] nursery collection pause time: 179.281000 ms
[memory ][Tue Nov 27 20:56:02 2012][07945] 569.325: parallel nursery GC 10106587K->6957659K (25165824K), 644.698 ms
[gcpause][Tue Nov 27 20:56:02 2012][07945] nursery collection pause time: 644.698000 ms
[memory ][Tue Nov 27 20:56:51 2012][07945] 618.198: parallel nursery GC 11613124K->8463876K (25165824K), 725.479 ms
[gcpause][Tue Nov 27 20:56:51 2012][07945] nursery collection pause time: 725.479000 ms
[memory ][Tue Nov 27 20:57:13 2012][07945] 641.285: parallel nursery GC 11613188K->8464388K (25165824K), 174.086 ms
[gcpause][Tue Nov 27 20:57:13 2012][07945] nursery collection pause time: 174.086000 ms
[memory ][Tue Nov 27 20:57:36 2012][07945] 663.828: parallel nursery GC 11613700K->8464708K (25165824K), 130.922 ms
[gcpause][Tue Nov 27 20:57:36 2012][07945] nursery collection pause time: 130.922000 ms
[memory ][Tue Nov 27 20:58:13 2012][07945] 701.379: parallel nursery GC 11613508K->8464452K (25165824K), 138.026 ms
[gcpause][Tue Nov 27 20:58:13 2012][07945] nursery collection pause time: 138.026000 ms
[memory ][Tue Nov 27 20:59:31 2012][07945] 778.216: parallel nursery GC 11613252K->8464324K (25165824K), 432.334 ms
[gcpause][Tue Nov 27 20:59:31 2012][07945] nursery collection pause time: 432.334000 ms
[memory ][Tue Nov 27 21:00:48 2012][07945] 855.609: parallel nursery GC 12969391K->9820591K (25165824K), 459.515 ms
[gcpause][Tue Nov 27 21:00:48 2012][07945] nursery collection pause time: 459.515000 ms
[memory ][Tue Nov 27 21:02:06 2012][07945] 933.180: parallel nursery GC 14189577K->11040738K (25165824K), 430.249 ms
[gcpause][Tue Nov 27 21:02:06 2012][07945] nursery collection pause time: 430.249000 ms
[memory ][Tue Nov 27 21:03:22 2012][07945] 1009.390: parallel nursery GC 14189538K->11040354K (25165824K), 499.022 ms
[gcpause][Tue Nov 27 21:03:22 2012][07945] nursery collection pause time: 499.022000 ms
[memory ][Tue Nov 27 21:04:42 2012][07945] 1089.308: parallel nursery GC 15287288K->12138232K (25165824K), 509.388 ms
[gcpause][Tue Nov 27 21:04:42 2012][07945] nursery collection pause time: 509.388000 ms
[memory ][Tue Nov 27 21:05:56 2012][07945] 1163.268: parallel nursery GC 16537519K->13388655K (25165824K), 602.746 ms
[gcpause][Tue Nov 27 21:05:56 2012][07945] nursery collection pause time: 602.746000 ms

[rupeshr-zz]

This looks significantly different from the other JRockit logs. What
version of JRockit is this? And please share the complete command line
options.
Thanks,
Rupesh

On Tue, Dec 11, 2012 at 8:43 AM, Ramesh Devaraj [email protected]:

The log that i am not able to parse

In Dev 1

[memory ][Tue Nov 27 20:46:32 2012][07945] Running with 64 bit heap and
uncompressed references.
[memory ][Tue Nov 27 20:46:32 2012][07945] GC mode: Static, strategy:
Generational Concurrent Mark & Sweep
[memory ][Tue Nov 27 20:46:32 2012][07945] heap size: 25165824K, maximal
heap size: 25165824K, nursery size: 4194304K
[memory ][Tue Nov 27 20:46:32 2012][07945] -: GC K->K (K), ms
[memory ][Tue Nov 27 20:46:32 2012][07945] - start time of collection
(seconds since jvm start)
[memory ][Tue Nov 27 20:46:32 2012][07945] - end time of collection
(seconds since jvm start)
[memory ][Tue Nov 27 20:46:32 2012][07945] - memory used by objects before
collection (KB)
[memory ][Tue Nov 27 20:46:32 2012][07945] - memory used by objects after
collection (KB)
[memory ][Tue Nov 27 20:46:32 2012][07945] - size of heap after collection
(KB)
[memory ][Tue Nov 27 20:46:32 2012][07945] - total sum of pauses during
collection (milliseconds)
[memory ][Tue Nov 27 20:46:32 2012][07945] run with -Xverbose:gcpause to
see individual pauses
[memory ][Tue Nov 27 20:47:59 2012][07945] 86.338: parallel nursery GC
6342580K->3193677K (25165824K), 377.950 ms
[gcpause][Tue Nov 27 20:47:59 2012][07945] nursery collection pause time:
377.950000 ms
[memory ][Tue Nov 27 20:49:23 2012][07945] 170.474: parallel nursery GC
6342477K->3193589K (25165824K), 431.549 ms
[gcpause][Tue Nov 27 20:49:23 2012][07945] nursery collection pause time:
431.549000 ms
[memory ][Tue Nov 27 20:50:53 2012][07945] 260.912: parallel nursery GC
8225175K->5076375K (25165824K), 437.175 ms
[gcpause][Tue Nov 27 20:50:53 2012][07945] nursery collection pause time:
437.175000 ms
[memory ][Tue Nov 27 20:52:22 2012][07945] 349.327: parallel nursery GC
8225175K->5076258K (25165824K), 427.192 ms
[gcpause][Tue Nov 27 20:52:22 2012][07945] nursery collection pause time:
427.192000 ms
[memory ][Tue Nov 27 20:53:19 2012][07945] 406.469: parallel nursery GC
8233244K->5084331K (25165824K), 368.508 ms
[gcpause][Tue Nov 27 20:53:19 2012][07945] nursery collection pause time:
368.508000 ms
[memory ][Tue Nov 27 20:53:44 2012][07945] 431.552: parallel nursery GC
8243165K->5094301K (25165824K), 288.407 ms
[gcpause][Tue Nov 27 20:53:44 2012][07945] nursery collection pause time:
288.407000 ms
[memory ][Tue Nov 27 20:54:08 2012][07945] 456.082: parallel nursery GC
8256491K->5160146K (25165824K), 257.011 ms
[gcpause][Tue Nov 27 20:54:08 2012][07945] nursery collection pause time:
257.011000 ms
[memory ][Tue Nov 27 20:54:35 2012][07945] 482.139: parallel nursery GC
10078452K->6929460K (25165824K), 558.459 ms
[gcpause][Tue Nov 27 20:54:35 2012][07945] nursery collection pause time:
558.459000 ms
[memory ][Tue Nov 27 20:54:59 2012][07945] 506.868: parallel nursery GC
10106139K->6957339K (25165824K), 312.258 ms
[gcpause][Tue Nov 27 20:54:59 2012][07945] nursery collection pause time:
312.258000 ms
[memory ][Tue Nov 27 20:55:22 2012][07945] 530.069: parallel nursery GC
10106651K->6957787K (25165824K), 179.281 ms
[gcpause][Tue Nov 27 20:55:22 2012][07945] nursery collection pause time:
179.281000 ms
[memory ][Tue Nov 27 20:56:02 2012][07945] 569.325: parallel nursery GC
10106587K->6957659K (25165824K), 644.698 ms
[gcpause][Tue Nov 27 20:56:02 2012][07945] nursery collection pause time:
644.698000 ms
[memory ][Tue Nov 27 20:56:51 2012][07945] 618.198: parallel nursery GC
11613124K->8463876K (25165824K), 725.479 ms
[gcpause][Tue Nov 27 20:56:51 2012][07945] nursery collection pause time:
725.479000 ms
[memory ][Tue Nov 27 20:57:13 2012][07945] 641.285: parallel nursery GC
11613188K->8464388K (25165824K), 174.086 ms
[gcpause][Tue Nov 27 20:57:13 2012][07945] nursery collection pause time:
174.086000 ms
[memory ][Tue Nov 27 20:57:36 2012][07945] 663.828: parallel nursery GC
11613700K->8464708K (25165824K), 130.922 ms
[gcpause][Tue Nov 27 20:57:36 2012][07945] nursery collection pause time:
130.922000 ms
[memory ][Tue Nov 27 20:58:13 2012][07945] 701.379: parallel nursery GC
11613508K->8464452K (25165824K), 138.026 ms
[gcpause][Tue Nov 27 20:58:13 2012][07945] nursery collection pause time:
138.026000 ms
[memory ][Tue Nov 27 20:59:31 2012][07945] 778.216: parallel nursery GC
11613252K->8464324K (25165824K), 432.334 ms
[gcpause][Tue Nov 27 20:59:31 2012][07945] nursery collection pause time:
432.334000 ms
[memory ][Tue Nov 27 21:00:48 2012][07945] 855.609: parallel nursery GC
12969391K->9820591K (25165824K), 459.515 ms
[gcpause][Tue Nov 27 21:00:48 2012][07945] nursery collection pause time:
459.515000 ms
[memory ][Tue Nov 27 21:02:06 2012][07945] 933.180: parallel nursery GC
14189577K->11040738K (25165824K), 430.249 ms
[gcpause][Tue Nov 27 21:02:06 2012][07945] nursery collection pause time:
430.249000 ms
[memory ][Tue Nov 27 21:03:22 2012][07945] 1009.390: parallel nursery GC
14189538K->11040354K (25165824K), 499.022 ms
[gcpause][Tue Nov 27 21:03:22 2012][07945] nursery collection pause time:
499.022000 ms
[memory ][Tue Nov 27 21:04:42 2012][07945] 1089.308: parallel nursery GC
15287288K->12138232K (25165824K), 509.388 ms
[gcpause][Tue Nov 27 21:04:42 2012][07945] nursery collection pause time:
509.388000 ms
[memory ][Tue Nov 27 21:05:56 2012][07945] 1163.268: parallel nursery GC
16537519K->13388655K (25165824K), 602.746 ms
[gcpause][Tue Nov 27 21:05:56 2012][07945] nursery collection pause time:
602.746000 ms

—

Reply to this email directly or view it on GitHubhttps://github.com//issues/45#issuecomment-11251192.

[rdev1991]

-Xverboselog:gc.log
-verbose:memory
-Xverbose:gcpause,gcreport
-Xverbosetimestamp

java version "1.5.0_12"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_12-b04)
BEA JRockit(R) (build R27.4.0-90-89592-1.5.0_12-20070928-1715-linux-x86_64, compiled mode)

The initial log that i provided was generated by the following Runtime.

java version "1.5.0_34"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_34-b03)
Oracle JRockit(R) (build R28.2.3-13-149708-1.5.0_34-20120327-1523-linux-x86_64, compiled mode)

[chewiebug]

Hi Rupesh

I would like to release 1.32 by the end of February. Do you think you are going to be able to add the missing parts for JRockit 1.5 by then?

Regards, Jörg

[rupeshr-zz]

Hi Jorg, been very busy at work. I will try to check this in by mid-Feb.

On Sun, Feb 3, 2013 at 1:11 PM, chewiebug [email protected] wrote:

Hi Rupesh

I would like to release 1.32 by the end of February. Do you think you are
going to be able to add the missing parts for JRockit 1.5 by then?

Regards, Jörg

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/45#issuecomment-13054413.

[chewiebug]

Hi Rupesh

Mid-Feb sounds very good to me!

By the way: I've just checked your online github repository for
GCViewer. It seems to be missing quite a few commits compared to my
master branch. Do you feel comfortable merging those commits into your
master branch? If not, I think I have an idea how I can help you before
you start committing again.

Regards, Jörg

Am 03.02.2013 22:21, schrieb Rupesh Ramachandran:

Hi Jorg, been very busy at work. I will try to check this in by mid-Feb.

On Sun, Feb 3, 2013 at 1:11 PM, chewiebug [email protected]
wrote:

Hi Rupesh

I would like to release 1.32 by the end of February. Do you think
you are
going to be able to add the missing parts for JRockit 1.5 by then?

Regards, Jörg

—
Reply to this email directly or view it on
GitHubhttps://github.com//issues/45#issuecomment-13054413.

—
Reply to this email directly or view it on GitHub
#45 (comment).

[rupeshr-zz]

Hi Jorg,
I've implemented the rest of the JRockit support, it now works for all
updates of JRockit 1.4, 1.5 and 1.6 (there will be no equivalent of 1.7 for
JRockit as development is discontinued and JRockit merges with Hotspot in
JDK1.8). It took longer than I expected. You're right, I haven't done an
update of my repository in a long time so I will have lots of changes to
merge. I will give it a shot tomorrow. Let me know if you have any tips to
make this process easier.
Thanks,
Rupesh

On Mon, Feb 4, 2013 at 12:31 PM, chewiebug [email protected] wrote:

Hi Rupesh

Mid-Feb sounds very good to me!

By the way: I've just checked your online github repository for
GCViewer. It seems to be missing quite a few commits compared to my
master branch. Do you feel comfortable merging those commits into your
master branch? If not, I think I have an idea how I can help you before
you start committing again.

Regards, Jörg

Am 03.02.2013 22:21, schrieb Rupesh Ramachandran:

Hi Jorg, been very busy at work. I will try to check this in by mid-Feb.

On Sun, Feb 3, 2013 at 1:11 PM, chewiebug [email protected]
wrote:

Hi Rupesh

I would like to release 1.32 by the end of February. Do you think
you are
going to be able to add the missing parts for JRockit 1.5 by then?

Regards, Jörg

—
Reply to this email directly or view it on
GitHub<
https://github.com/chewiebug/GCViewer/issues/45#issuecomment-13054413>.

—
Reply to this email directly or view it on GitHub
#45 (comment).

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/45#issuecomment-13097599.

[chewiebug]

Hi Rupesh,

Thank you for your contribution!

Concerning the merging process, I had in mind to send you a pull request. Assuming that you wouldn't have had merge conflicts you could have merged via the github website. But you seem to have mastered the merge.

In the future I recommend to push everything to a feature-branch of your repository. That will make future merges easier for you. If I decide not to merge your commits exactly as you submitted them (which I am about to do with the many log files), your next merge might be quite difficult if it is on the same branch you sent your pull request from. I like jQuerys explanations on how to contribute on github.

Regards, Jörg

[chewiebug]

Hi @dramezh,

I have merged Rupesh's pull request to the master branch. Now JRockit 1.5 logs should be parseable. If you find bugs in the current implementation, please reopen the issue and detail the problem.

Regards, Jörg

[rdev1991]

sure thing.. thanks for getting this done.. much appreciated

On Sun, Mar 10, 2013 at 2:07 PM, chewiebug [email protected] wrote:

Hi @dramezh https://github.com/dramezh,

I have merged Rupesh's pull request to the master branch. Now JRockit 1.5
logs should be parseable. If you find bugs in the current implementation,
please reopen the issue and detail the problem.

Regards, Jörg

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/45#issuecomment-14681902
.

Thanks and Regards
Ramesh Devaraj