Setting up parser to timestamp GC CMS Logs

Notes, tips, and other usefull things on how to use LogMX

Moderator: admin

Post Reply
apnakon
Posts: 10
Joined: Mon Oct 04, 2010 11:30 am

Setting up parser to timestamp GC CMS Logs

Post by apnakon »

HI Guys,

I would greatly appreciate if someone could me please.
I am using the 2.0.2 Pro version (awesome program, by the way!), and would like to
create timestamp entries (so I can merge from a number of files).

However, I'm having some trouble with specifying a timestamp that is made up of
seconds.mills only. I have tried various combinations of %d but with no luck.

I am wondering now about user defined fields, but I don't know how to use them / how
they work (I'm new LogMX). Any ideas would be greatly appreciated - esp. how to cut up the
following listing properly for viewing / examining in LogMX.

I have an example listing below.

Many Thanks for your help,

Adrian.

---------

1.961: [GC 1.961: [ParNew
Desired survivor size 53673984 bytes, new threshold 16 (max 31)
- age 1: 4888288 bytes, 4888288 total
: 838912K->4825K(943744K), 0.0177870 secs] 838912K->4825K(3040896K), 0.0178860 secs] [Times: user=0.05 sys=0.01, real=0.02 secs]
2.701: [Full GC 2.701: [CMS: 0K->20181K(2097152K), 0.1891620 secs] 199868K->20181K(3040896K), [CMS Perm : 16383K->16371K(16384K)], 0.1893470 secs] [Times: user=0.16 sys=0.03, real=0.19 secs]
2.892: [GC [1 CMS-initial-mark: 20181K(2097152K)] 20181K(3040896K), 0.0009570 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2.893: [CMS-concurrent-mark-start]
4.743: [Full GC 4.743: [CMS4.834: [CMS-concurrent-mark: 0.091/1.941 secs] [Times: user=5.87 sys=0.28, real=1.95 secs]
(concurrent mode failure): 20181K->27723K(2097152K), 0.4035670 secs] 282995K->27723K(3040896K), [CMS Perm : 27240K->27223K(27288K)], 0.4037520 secs] [Times: user=0.41 sys=0.00, real=0.41 secs]
8.322: [GC [1 CMS-initial-mark: 27723K(2097152K)] 405308K(3040896K), 0.3473680 secs] [Times: user=0.35 sys=0.00, real=0.35 secs]
8.669: [CMS-concurrent-mark-start]
8.825: [CMS-concurrent-mark: 0.155/0.155 secs] [Times: user=0.38 sys=0.03, real=0.16 secs]
8.825: [CMS-concurrent-preclean-start]
8.850: [CMS-concurrent-preclean: 0.024/0.025 secs] [Times: user=0.04 sys=0.01, real=0.02 secs]
8.850: [CMS-concurrent-abortable-preclean-start]
234.453: [GC 234.453: [ParNew
Desired survivor size 53673984 bytes, new threshold 16 (max 31)
- age 1: 51371792 bytes, 51371792 total
: 838912K->50529K(943744K), 0.2349800 secs] 866635K->78252K(3040896K), 0.2351750 secs] [Times: user=0.58 sys=0.03, real=0.23 secs]
CMS: abort preclean due to time 420.240: [CMS-concurrent-abortable-preclean: 0.276/411.390 secs] [Times: user=14.04 sys=2.22, real=411.39 secs]
420.240: [GC[YG occupancy: 428411 K (943744 K)]420.241: [Rescan (parallel) , 0.3542200 secs]420.595: [weak refs processing, 0.0000130 secs] [1 CMS-remark: 27723K(2097152K)] 456135K(3040896K), 0.3543730 secs] [Times: user=1.18 sys=0.01, real=0.36 secs]
420.595: [CMS-concurrent-sweep-start]
420.610: [CMS-concurrent-sweep: 0.015/0.015 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
420.610: [CMS-concurrent-reset-start]
420.619: [CMS-concurrent-reset: 0.008/0.008 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
1076.814: [GC 1076.814: [ParNew
Desired survivor size 53673984 bytes, new threshold 16 (max 31)
- age 1: 2224592 bytes, 2224592 total
- age 2: 37423792 bytes, 39648384 total
: 889441K->55351K(943744K), 0.0989330 secs] 916339K->82249K(3040896K) icms_dc=5 , 0.0991490 secs] [Times: user=0.34 sys=0.02, real=0.10 secs]
1446.737: [GC [1 CMS-initial-mark: 26898K(2097152K)] 481941K(3040896K), 0.5868710 secs] [Times: user=0.59 sys=0.00, real=0.59 secs]
1447.325: [CMS-concurrent-mark-start]
1447.497: [CMS-concurrent-mark: 0.173/0.173 secs] [Times: user=0.17 sys=0.00, real=0.17 secs]
1447.497: [CMS-concurrent-preclean-start]
1447.512: [CMS-concurrent-preclean: 0.013/0.014 secs] [Times: user=0.01 sys=0.01, real=0.02 secs]
1447.512: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 1452.631: [CMS-concurrent-abortable-preclean: 2.578/5.120 secs] [Times: user=2.63 sys=0.03, real=5.12 secs]
1452.632: [GC[YG occupancy: 455043 K (943744 K)]1452.632: [Rescan (parallel) , 0.4493940 secs]1453.081: [weak refs processing, 0.0000140 secs] [1 CMS-remark: 26898K(2097152K)] 481941K(3040896K), 0.4495460 secs] [Times: user=1.57 sys=0.03, real=0.45 secs]
1453.082: [CMS-concurrent-sweep-start]
1453.102: [CMS-concurrent-sweep: 0.020/0.020 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
1453.103: [CMS-concurrent-reset-start]
1453.110: [CMS-concurrent-reset: 0.008/0.008 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2073.021: [GC 2073.021: [ParNew
Desired survivor size 53673984 bytes, new threshold 16 (max 31)
- age 1: 953608 bytes, 953608 total
- age 2: 1987928 bytes, 2941536 total
- age 3: 36241632 bytes, 39183168 total
: 894263K->57391K(943744K), 0.0953870 s
admin
Site Admin
Posts: 555
Joined: Sun Dec 17, 2006 10:30 pm

Re: Setting up parser to timestamp GC CMS Logs

Post by admin »

Hello Adrian,

You may have to use your own Java Class Parser to do so (one of the ways to read logs with LogMX).
You will find an example of a CMS GC Log parser here: http://www.logmx.com/downloads/forum/CM ... arser.java
With this Parser, I successfully merged several CMS GC log files, interlaced by date.
Feel free to modify this Parser according to your needs.
To know how to use this example, you can read this: http://www.logmx.com/p_parser_dev.php

Yet, in your log file example, it seems that it contains extra line feeds ("\n") that don't appear in these logs description: http://blogs.sun.com/poonam/entry/under ... ms_gc_logs (maybe it's due to this forum text layout...

Feel free to post again if you have trouble using this Parser.

Xavier
apnakon
Posts: 10
Joined: Mon Oct 04, 2010 11:30 am

Re: Setting up parser to timestamp GC CMS Logs

Post by apnakon »

Hi Xavier,

*Many* Thanks for that mate!

I used your example (using NetBeans) and it works a treat! Terrific. :D

Just an idea - but I think it would be good if you included such parsers (or perhaps, a library of parsers)
with LogMX.

The reason I say this is because, even though I am knowledgeable in Java, many of the guys here would would
be *very* interested in using LogMX are not. To them, Java is a 'black art' (they are system admins for Databases, Apps, etc.).
Having a suite of 'generally useful' parsers at your fingertips (that don't fit the standard Log4j format) would be pretty cool.

Thanks again,

Adrian.
admin
Site Admin
Posts: 555
Joined: Sun Dec 17, 2006 10:30 pm

Re: Setting up parser to timestamp GC CMS Logs

Post by admin »

Hello,

Yes, indeed we plan to add a "Parsers Repository" to our website :P .

Future versions of LogMX will be able to access this repository.
LogMX developers but also LogMX users will be able to add Parsers to his Repository.

Xavier.
Post Reply