How to get sum of GC time spend in last 4 hours?

[slipinski]

Hi Splunkers,

I have a GC log like below:

[716920.165s][info][gc] GC(27612) Concurrent reset 24.051ms
[716909.883s][info][gc] GC(27611) Concurrent update references 3124.593ms
[716909.885s][info][gc] GC(27611) Pause Final Update Refs 1.336ms
[716909.885s][info][gc] GC(27611) Concurrent cleanup 79178M->58868M(153600M) 0.143ms
[716906.314s][info][gc] GC(27611) Pause Final Mark 2121.376ms
[716906.315s][info][gc] GC(27611) Concurrent cleanup 71900M->71709M(153600M) 0.240ms
[716906.757s][info][gc] GC(27611) Concurrent evacuation 441.920ms
[716906.758s][info][gc] GC(27611) Pause Init Update Refs 0.126ms

I'm trying to get statistic related to total time spend by all these fields (the values in ms at the end of line).  I mean calculated all events in ms and drew a chart or table with total value from last 4 hours.

For instance 

19.00 - 245000ms

20.00 - 344000ms 

21.00 - 345500ms

22.00 - 452000ms 

I did manage to extract time needed in ms from all fields, but when I use query like:

timechart span=1h sum(eval(Concurrent_reset+Concurrent_Update+ Pause_Final_Mark+Concurrent_cleanup+Concurrant_evacuation+Pause_Init_Update)) as total

i just receive results from 19.00-20.00 timespan. What I doing wrong here? 

regards,

Sz

[slipinski]

@bowesmana You nail it!

I had to play with regex a little bit, but I managed to achieve what I wanted. 

Thanks a lot. 

[bowesmana]

What is your _time value in the event? Splunk calculates it's buckets based on the event time and there is no obvious time value in that data.

The initial number could be time, but there's no reference point and if it represents seconds, that data is only covering 14 seconds

716906.314 - 716920.165

[slipinski]

Hi,

I don't take into account the timestamp at the beginning of every line. Relying on Splunk-added timestamp is okay. 

716906.314 - 716920.165

 I'm struggling with an accumulation of time  in ms at the end of every log line like:

24.051

3124.593

and divide it into hours (Splunk timestampt) 

[bowesmana]

How are you struggling? Your example shows that you expect the following information

19.00 - 245000ms
20.00 - 344000ms 
21.00 - 345500ms
22.00 - 452000ms 

but from your visible data there is no way it can add up to those values in those time ranges.

timechart will calculate the sum in the 1 hour time range based on its value of _time and the sum of the extracted fields in your sum(eval(...)) statement

So please explain and provide an example of your data and an example of the output you are seeing - long with the search you are running. Without that, it's very difficult to suggest what the problem is.

[slipinski]

Dear @bowesmana 

Apologies for not being entirely clear in previous messages. No wonder you got confused.

Let me clarify this again.

I got logs:

Splunk_timestamp EventA time_used [249.34ms]
Splunk_timestamp EventB time_used [246.23ms]
Splunk_timestamp EventC time_used [323.11ms]
Splunk_timestamp EventA time_used [1445.12ms]

 I managed to extract time_used value per event. 

I would like to have a total sum of time_used from all events per hour. 

The next step would be having percentage of time_used total number/number of ms in day i.e. (3 600 000 ms - 1000ms*60*60). 

My query was a crap, so I'm not attaching it here. 

[bowesmana · Accepted solution]

It's a pretty straightforward query for that

your_search_to_get_data
``` Extract the ms time field from your event with a suitable rex statement ```
| rex "\[(?<ms>[\d\.]*)\]"
| timechart span=1h sum(ms) as total
``` Calculate the percentage of total ms per hour ```
| eval percent=round(total / 3600000 * 100, 2)

If that is not giving you what you expect, post your search and results.

The rex regular expression will work on your _raw event - if you already have field extractions, it may need modification.