topic Re: Not extracting all Full GC events in Splunk Search

Not extracting all Full GC events

nagaraju_chitta — Fri, 29 Sep 2017 09:10:57 GMT

Could not be able to pull all the Full GC events. Is there any tweak requires in the regex?

| makeresults
 | eval _raw="28820.220: [Full GC (System.gc()) 8832K->8624K(37888K), 0.0261704 secs]
29372.500: [GC (Allocation Failure) 23984K->8816K(37888K), 0.0013546 secs]
29932.500: [GC (Allocation Failure) 24176K->8808K(37888K), 0.0017082 secs]
30492.500: [GC (Allocation Failure) 24168K->8960K(37888K), 0.0017122 secs]
31047.500: [GC (Allocation Failure) 24320K->8944K(37888K), 0.0020634 secs]
31602.500: [GC (Allocation Failure) 24304K->8992K(37888K), 0.0017542 secs]
32157.500: [GC (Allocation Failure) 24352K->8968K(37888K), 0.0018971 secs]
32420.247: [GC (System.gc()) 16160K->8944K(37888K), 0.0012816 secs] 
 8186.000: [GC (Allocation Failure)  91332K->36212K(246272K), 0.0081127 secs]
8347.676: [GC (System.gc())  42225K->35996K(246272K), 0.0040077 secs]
8347.678: [Full GC (System.gc())  35996K->21313K(246272K), 0.1147433 secs]
8929.342: [GC (Allocation Failure)  76609K->24356K(246784K), 0.0047687 secs]
8952.577: [GC (Allocation Failure)  80164K->29098K(246272K), 0.0053928 secs]
9921.694: [GC (Allocation Failure)  84906K->27626K(247808K), 0.0053474 secs]
11567.840: [GC (Allocation Failure)  85994K->27730K(247808K), 0.0030062 secs]
11947.795: [GC (System.gc())  41757K->27562K(248320K), 0.0035917 secs]
11947.797: [Full GC (System.gc())  27562K->22923K(248320K), 0.1237187 secs]
13602.721: [GC (Allocation Failure)  81803K->23467K(247808K), 0.0029760 secs]
15283.208: [GC (Allocation Failure)  82347K->23363K(249344K), 0.0035369 secs]
15547.924: [GC (System.gc())  33663K->23283K(248832K), 0.0142619 secs]
15547.937: [Full GC (System.gc())  23283K->22914K(248832K), 0.0788277 secs]
17283.683: [GC (Allocation Failure)  83842K->23298K(250368K), 0.0077597 secs]
19069.372: [GC (Allocation Failure)  86274K->23354K(249856K), 0.0027577 secs]

 | rex max_match=0 field=_raw "^(?<timestamp>[^:]+):\s+\[Full GC\s\(([^\)]+)\)\)\s+(?<field1>\d+)K-\>(?<field2>\d+)K\((?<field3>\d+)K\),\s+(?<gctime>[^\s]+)\ssecs\]"

Re: Not extracting all Full GC events

harsmarvania57 — Fri, 29 Sep 2017 09:23:05 GMT

It looks like you are missing double quotes in eval statement.

| makeresults
  | eval _raw="28820.220: [Full GC (System.gc()) 8832K->8624K(37888K), 0.0261704 secs]
 29372.500: [GC (Allocation Failure) 23984K->8816K(37888K), 0.0013546 secs]
 29932.500: [GC (Allocation Failure) 24176K->8808K(37888K), 0.0017082 secs]
 30492.500: [GC (Allocation Failure) 24168K->8960K(37888K), 0.0017122 secs]
 31047.500: [GC (Allocation Failure) 24320K->8944K(37888K), 0.0020634 secs]
 31602.500: [GC (Allocation Failure) 24304K->8992K(37888K), 0.0017542 secs]
 32157.500: [GC (Allocation Failure) 24352K->8968K(37888K), 0.0018971 secs]
 32420.247: [GC (System.gc()) 16160K->8944K(37888K), 0.0012816 secs] 
  8186.000: [GC (Allocation Failure)  91332K->36212K(246272K), 0.0081127 secs]
 8347.676: [GC (System.gc())  42225K->35996K(246272K), 0.0040077 secs]
 8347.678: [Full GC (System.gc())  35996K->21313K(246272K), 0.1147433 secs]
 8929.342: [GC (Allocation Failure)  76609K->24356K(246784K), 0.0047687 secs]
 8952.577: [GC (Allocation Failure)  80164K->29098K(246272K), 0.0053928 secs]
 9921.694: [GC (Allocation Failure)  84906K->27626K(247808K), 0.0053474 secs]
 11567.840: [GC (Allocation Failure)  85994K->27730K(247808K), 0.0030062 secs]
 11947.795: [GC (System.gc())  41757K->27562K(248320K), 0.0035917 secs]
 11947.797: [Full GC (System.gc())  27562K->22923K(248320K), 0.1237187 secs]
 13602.721: [GC (Allocation Failure)  81803K->23467K(247808K), 0.0029760 secs]
 15283.208: [GC (Allocation Failure)  82347K->23363K(249344K), 0.0035369 secs]
 15547.924: [GC (System.gc())  33663K->23283K(248832K), 0.0142619 secs]
 15547.937: [Full GC (System.gc())  23283K->22914K(248832K), 0.0788277 secs]
 17283.683: [GC (Allocation Failure)  83842K->23298K(250368K), 0.0077597 secs]
 19069.372: [GC (Allocation Failure)  86274K->23354K(249856K), 0.0027577 secs]"
  | rex max_match=0 field=_raw "^(?<timestamp>[^:]+):\s+\[Full GC\s\(([^\)]+)\)\)\s+(?<field1>\d+)K-\>(?<field2>\d+)K\((?<field3>\d+)K\),\s+(?<gctime>[^\s]+)\ssecs\]"

What you want to achieve, want to extract all "Full GC" events ?

Re: Not extracting all Full GC events

nagaraju_chitta — Fri, 29 Sep 2017 09:32:44 GMT

Thanks for quick response.double quotes missing was my typo.I want to extract all Full GC events.

Re: Not extracting all Full GC events

inventsekar — Fri, 29 Sep 2017 09:54:12 GMT

Updated -
(?m) is the trick

    | makeresults
      | eval _raw="28820.220: [Full GC (System.gc()) 8832K->8624K(37888K), 0.0261704 secs]
     29372.500: [GC (Allocation Failure) 23984K->8816K(37888K), 0.0013546 secs]
     29932.500: [GC (Allocation Failure) 24176K->8808K(37888K), 0.0017082 secs]
     30492.500: [GC (Allocation Failure) 24168K->8960K(37888K), 0.0017122 secs]
     31047.500: [GC (Allocation Failure) 24320K->8944K(37888K), 0.0020634 secs]
     31602.500: [GC (Allocation Failure) 24304K->8992K(37888K), 0.0017542 secs]
     32157.500: [GC (Allocation Failure) 24352K->8968K(37888K), 0.0018971 secs]
     32420.247: [GC (System.gc()) 16160K->8944K(37888K), 0.0012816 secs] 
      8186.000: [GC (Allocation Failure)  91332K->36212K(246272K), 0.0081127 secs]
     8347.676: [GC (System.gc())  42225K->35996K(246272K), 0.0040077 secs]
     8347.678: [Full GC (System.gc())  35996K->21313K(246272K), 0.1147433 secs]
     8929.342: [GC (Allocation Failure)  76609K->24356K(246784K), 0.0047687 secs]
     8952.577: [GC (Allocation Failure)  80164K->29098K(246272K), 0.0053928 secs]
     9921.694: [GC (Allocation Failure)  84906K->27626K(247808K), 0.0053474 secs]
     11567.840: [GC (Allocation Failure)  85994K->27730K(247808K), 0.0030062 secs]
     11947.795: [GC (System.gc())  41757K->27562K(248320K), 0.0035917 secs]
     11947.797: [Full GC (System.gc())  27562K->22923K(248320K), 0.1237187 secs]
     13602.721: [GC (Allocation Failure)  81803K->23467K(247808K), 0.0029760 secs]
     15283.208: [GC (Allocation Failure)  82347K->23363K(249344K), 0.0035369 secs]
     15547.924: [GC (System.gc())  33663K->23283K(248832K), 0.0142619 secs]
     15547.937: [Full GC (System.gc())  23283K->22914K(248832K), 0.0788277 secs]
     17283.683: [GC (Allocation Failure)  83842K->23298K(250368K), 0.0077597 secs]
     19069.372: [GC (Allocation Failure)  86274K->23354K(249856K), 0.0027577 secs]"
      | rex max_match=0 field=_raw "(?m)^(?<timestamp>[^:]+):\s+\[Full GC\s\((?<SysGC>[^\)]+)\)\)\s+(?<field1>\d+)K-\>(?<field2>\d+)K\((?<field3>\d+)K\),\s+(?<gctime>[^\s]+)\ssecs\]" 
| table timestamp SysGC field1 field2 field3 gctime

Re: Not extracting all Full GC events

nagaraju_chitta — Fri, 29 Sep 2017 10:46:11 GMT

Great...its working ...somehow lost it....in the same regex....can I extract Full GC text irrespective of System.gc()

Re: Not extracting all Full GC events

inventsekar — Fri, 29 Sep 2017 11:05:53 GMT

Hi @nagaraju_chittathuru, can you please check the new answer which extracts both Full GC (System.gc()) and GC (Allocation Failure). maybe, you can upvote ( 😉 ) and accept as answer !

Re: Not extracting all Full GC events

nagaraju_chitta — Fri, 29 Sep 2017 13:47:59 GMT

@inventsekar ....

Would like to pull the Full GC events for various scenarios highlighted below. little tweak may require. Any advise?

608: [Full GC (Ergonomics) 33806K->21894K(81408K), 0.0384745 secs]
3.102: [GC (Allocation Failure) 53638K->41494K(114176K), 0.0274036 secs]
3.487: [GC (Allocation Failure) 99862K->59842K(118784K), 0.0536328 secs]
3.540: [Full GC (Ergonomics) 59842K->38677K(142848K), 0.0676180 secs]
14.343: [Full GC (Metadata GC Threshold) 59169K->18823K(210432K), 0.0509631 secs]
19.146: [GC (Metadata GC Threshold) 98790K->36405K(217088K), 0.0176669 secs]
19.164: [Full GC (Metadata GC Threshold) 36405K->29323K(233472K), 0.0738457 secs]
23.284: [GC (Allocation Failure) 168073K->59373K(267264K), 0.0291682 secs]

3630.851: [GC (System.gc()) 315130K->78088K(455168K), 0.0149945 secs]
3630.867: [Full GC (System.gc()) 78088K->68561K(455168K), 0.2917172 secs]

Re: Not extracting all Full GC events

inventsekar — Mon, 02 Oct 2017 00:56:59 GMT

Would like to pull the Full GC events for various scenarios highlighted below. little tweak may require. Any advise?

608: [Full GC (Ergonomics) 33806K->21894K(81408K), 0.0384745 secs]
3.102: [GC (Allocation Failure) 53638K->41494K(114176K), 0.0274036 secs]
3.487: [GC (Allocation Failure) 99862K->59842K(118784K), 0.0536328 secs]
3.540: [Full GC (Ergonomics) 59842K->38677K(142848K), 0.0676180 secs]
14.343: [Full GC (Metadata GC Threshold) 59169K->18823K(210432K), 0.0509631 secs]
19.146: [GC (Metadata GC Threshold) 98790K->36405K(217088K), 0.0176669 secs]
19.164: [Full GC (Metadata GC Threshold) 36405K->29323K(233472K), 0.0738457 secs]
23.284: [GC (Allocation Failure) 168073K->59373K(267264K), 0.0291682 secs]

3630.851: [GC (System.gc()) 315130K->78088K(455168K), 0.0149945 secs]
3630.867: [Full GC (System.gc()) 78088K->68561K(455168K), 0.2917172 secs]

To extract the Full GC Events, please check this -

 | rex max_match=0 field=_raw "(?m)^(?<timestamp>[^:]+):\s+\[(?<FullGCEvents>Full.*)\s+(?<field1>\d+)K-\>(?<field2>\d+)K\((?<field3>\d+)K\),\s+(?<gctime>[^\s]+)\ssecs\]" 
| table timestamp FullGCEvents field1 field2 field3 gctime

Re: Not extracting all Full GC events

nagaraju_chitta — Mon, 02 Oct 2017 08:07:21 GMT

@inventsekar: Thanks for the regex...it works fine.
would like to show a trend chart for the Full GC events with values of timestamp in x-axis and gctime at y-axis..kind of line chart...I know some stats functions we have to use here but how to populate the actual values of timestamp and gctime and show the graph

| rex max_match=0 field=_raw "(?m)^(?<timestamp>[^:]+):\s+\[(?<FullGCEvents>Full.*)\s+(?<field1>\d+)K-\>(?<field2>\d+)K\((?<field3>\d+)K\),\s+(?<gctime>[^\s]+)\ssecs\]" |where like(serv1,"%serv1%") |  chart values(gctime) as gctime by timestamp

timestamp:
28820.220
8347.678
11947.797

gctime:
0.0261704
0.1147433
0.1237187

serv name from the filename which is source
serv1

Re: Not extracting all Full GC events

inventsekar — Mon, 02 Oct 2017 08:56:43 GMT

when you run this, do you get the chart?
| rex max_match=0 field=_raw "(?m)^(?<timestamp>[^:]+):\s+\[(?<FullGCEvents>Full.*)\s+(?<field1>\d+)K-\>(?<field2>\d+)K\((?<field3>\d+)K\),\s+(?<gctime>[^\s]+)\ssecs\]" |where like(serv1,"%serv1%") | chart values(gctime) as gctime by timestamp

maybe, the timestamp need to be converted first (strptime/strftime).

Re: Not extracting all Full GC events

nagaraju_chitta — Mon, 02 Oct 2017 09:23:39 GMT

I am not getting the chart only in the x-axis the values of timestamp are populating. my requirement is I no need to convert the time as I have to display the as is of timestamp and gctime...somehow could not be able to attach image
![alt text][1]

Re: Not extracting all Full GC events

inventsekar — Mon, 02 Oct 2017 09:50:38 GMT

you can not attached image inside this comment box.
Please write a new "answer" and attach then you can attach the image.

Re: Not extracting all Full GC events

niketn — Mon, 02 Oct 2017 09:54:34 GMT

@nagaraju_chittathuru, you can upload image to any image sharing site and the attach the same using Image <img> button in the comment.

Re: Not extracting all Full GC events

nagaraju_chitta — Mon, 02 Oct 2017 11:31:14 GMT

@inventsekar
Here is the image values when I run the below query...but the goal is on x-axis needs to show the timestamp and y-axis the duration with line graph when hover both the timestamp and duration has to show as per the below image. Now this is showing the max values...but has to show all the values

rex max_match=0 field=_raw "(?m)^(?<timestamp>[^:]+):\s+\[(?<FullGCEvents>Full.*)\s+(?<field1>\d+)K-\>(?<field2>\d+)K\((?<field3>\d+)K\),\s+(?<gctime>[^\s]+)\ssecs\]" |  chart max(gctime) as Duration by timestamp

Re: Not extracting all Full GC events

nagaraju_chitta — Mon, 02 Oct 2017 12:34:43 GMT

unfortunately blocked from my work place