Splunk Search

Why am I unable to convert a duration value to a human readable time format?

Communicator

Hi all!

I have the following code:

index=BLA source=BLA 
                 | eval Day = strftime(_time,"%F")
                 | eval DateTime = strftime(_time,"%Y-%m-%d %H:%M:%S")
                 | stats Latest(LogType) as Status Latest(Result) as Result  Latest(DateTime) as When  by PackageName
                 | sort - Status - When
                 | table When, PackageName, Status, Result
                 | eval AlertLevel = case(Result=="OK",1,Result=="WARNING",2,Result=="KO",3)
                 | rangemap field=AlertLevel low=1-1 elevated=2-2 severe=3-3 default=guarded
                 | fields - AlertLevel
                 | join Type=Left PackageName[ search index=BLA source=BLA
                                             | eval Day = strftime(_time,"%F")
                                             | eval DateTime = strftime(_time,"%Y-%m-%d %H:%M:%S")
                                             | eval EndTime = if(Result="OK", _time, null)
                                             | eval StartTime = if(LogType ="START", _time, null)
                                             | stats Latest(StartTime) as StartTime Latest(EndTime) as EndTime by PackageName ExecutionInstanceGUID
                                             | eval Duration = (EndTime-StartTime)
                                             | where (Duration != "" OR Duration >= 0)
                                             | stats avg(EndTime) as AVGEndTime avg(Duration) as AVGDuration avg(StartTime) as AVGStartTime by PackageName
                                             ]

Now: if I use, in the columns AVGEndTime, AVGDuration, and AVGStartTime, the format in milliseconds (that come out naturally with the query) I get that -> AVGEndTime - AVGStartTime ≈ AVGDuration.

Instead, if I add the following code for converting time in a human friendly format:

| fieldformat AVGStartTime = strftime(AVGStartTime,"%H:%M:%S")
| fieldformat AVGEndTime = strftime(AVGEndTime,"%H:%M:%S")
| fieldformat AVGDuration = strftime(AVGDuration,"%H:%M:%S")

I get that the AVGDuration is almost always one hour bigger.

WHY?

It's really difficult to work with time in Splunk! Any suggestion?

1 Solution

Champion

The issue is probably because AVGDuration is a duration interval, not an epoch-based time value. You need to use a different function, because strftime assumes you are sending it some kind of epoch time.

I would replace your last formatting line with the following:

| eval AVGDuration = tostring(AVGDuration,"duration")

View solution in original post

Champion

Independent of my answer below, there are some optimizations you could make to your searches. Here is my suggestion for speeding things up. First, we get rid of the unnecessary time evals at the beginning of each search. Instead, you can move the formatting of "When" later in the first search. Second, we replace the join with append and stats. You can find many answers that talk about why this is a good idea. There was a talk at Splunk .conf 2016 about this as well.

index=BLA source=BLA 
                  | stats Latest(LogType) as Status Latest(Result) as Result Latest(_time) as When by PackageName
                  | sort - Status - When
                  | eval When = strftime(When,"%Y-%m-%d %H:%M:%S")
                  | table When, PackageName, Status, Result
                  | append [ search index=BLA source=BLA (Result="OK" OR LogType ="START")
                                              | eval EndTime = if(Result="OK", _time, null)
                                              | eval StartTime = if(LogType ="START", _time, null)
                                              | stats Latest(StartTime) as StartTime Latest(EndTime) as EndTime by PackageName ExecutionInstanceGUID
                                              | eval Duration = (EndTime-StartTime)
                                              | where (Duration != "" OR Duration >= 0)
                                              | stats avg(EndTime) as AVGEndTime avg(Duration) as AVGDuration avg(StartTime) as AVGStartTime by PackageName
                                              ]
                  | stats first(When) as When, first(Status) as Status, first(Result) as Result, max(AVG*) as AVG* by PackageName
                  | table When, PackageName, Status, Result, AVGEndTime, AVGDuration, AVGStartTime
                  | eval AlertLevel = case(Result=="OK",1,Result=="WARNING",2,Result=="KO",3)
                  | rangemap field=AlertLevel low=1-1 elevated=2-2 severe=3-3 default=guarded
                  | fields - AlertLevel

Communicator

I'll check ASAP the changes you suggested.
In the meantime I have another problem.
I would like to have another column (like with 1 or 0) that is 1 if (now - when) > AVGDuration.
This is for giving knowing the rows which are taking more time than in average.

Thanks a lot!

0 Karma

Communicator

I checked the changes you suggest, but i don't understand how a join can be substitute by an append. I also don't understand for what is the following row:

stats first(When) as When, first(Status) as Status, first(Result) as Result, max(AVG*) as AVG* by PackageName

Thank you!

0 Karma

Champion

First, did it give you the correct result to use my suggestion? Just curious.

Going back to your question, substituting append and stats for join is meant to help hopefully make things more performant and also as a tool to help you think about searching in a different way. The join command is straightforward to use in this case, but join is more and more considered a less than optimal command in the Splunk community. The stats command I gave you should allow you to do the same thing as the join. It takes the first value of the "When", "Status", and "Result" fields from your top-level search (pre-append), and then adds to the results the averages from the append-level search. This does the same thing as the inner join on the PackageName field.

Communicator

you said that substituting the join with append ans stats: "This does the same thing as the inner join on the PackageName field".
But i need a left join.

0 Karma

Champion

I missed the left join aspect of your previous search. Sorry about that.

Still, I suggest you look at the last search I posted which consolidated everything into a single search and see if that works. If it does, I suggest you try to use that approach since it should greatly improve performance.

Communicator

BTW i refined my search:

index=BLA source=BLA
| stats Latest(LogType) as Status Latest(Result) as Result  Latest(_time) as When  by PackageName
| table When, PackageName, Status, Result
| join Type=Left PackageName[ search index=BLA source=BLA
                            | eval EndTime = if(Result="OK", _time, null)
                            | eval StartTime = if(LogType ="START", _time, null)
                            | stats Latest(StartTime) as StartTime Latest(EndTime) as EndTime by PackageName ExecutionInstanceGUID
                            | eval Duration = (EndTime-StartTime)
                            | where (Duration != "" OR Duration >= 0)
                            | stats avg(EndTime) as AVGEndTime avg(Duration) as AVGDuration avg(StartTime) as AVGStartTime by PackageName
                            ]
| fieldformat AVGStartTime = strftime(AVGStartTime,"%H:%M:%S")
| fieldformat AVGEndTime = strftime(AVGEndTime,"%H:%M:%S")
| fieldformat When = strftime(When,"%Y-%m-%d %H:%M:%S")
| eval AVGDuration = tostring(round(AVGDuration, 0),"duration")
| eval Duration = if(Status== "START", tostring(now() - When ,"duration"), "" )
| eval Timing = if (Status== "START", if( Duration > AVGDuration, "InLate", "OnTime"), "")
| eval AlertLevel = case(Result=="OK", if(Timing=="InLate", 0, 1), Result=="WARNING",2,Result=="KO",3)
| rangemap field=AlertLevel guarded=0-0 low=1-1 elevated=2-2 severe=3-3
| table When PackageName Status Result Duration AVGDuration Timing AVGStartTime AVGEndTime range
| sort Result, -Status,  Timing, -When
0 Karma

Champion

If you want to try even more extra credit, play with this to see if it gets the same results as your original search. This one tries to eliminate the need for append or join

index=BLA source=BLA 
| fields _time LogType Result PackageName ExecutionInstanceGUID
| eval EndTime = if(Result="OK", _time, null)
| eval StartTime = if(LogType ="START", _time, null)
| eventstats Latest(LogType) as Status Latest(Result) as Result Latest(_time) as When by PackageName
| stats Latest(StartTime) as StartTime Latest(EndTime) as EndTime first(Status) as Status first(Result) as Result first(When) as When by PackageName ExecutionInstanceGUID
| eval Duration = (EndTime-StartTime)
| where (Duration != "" OR Duration >= 0)
| stats avg(EndTime) as AVGEndTime avg(Duration) as AVGDuration avg(StartTime) as AVGStartTime first(When) as When first(Status) as Status first(Result) as Result by PackageName
| sort -Status -When
| eval Excessive = if ((now() - When) > AVGDuration, 1, 0)
| eval When = strftime(When,"%Y-%m-%d %H:%M:%S")
| table When PackageName Status Result AVGEndTime AVGDuration AVGStartTime Excessive
| eval AlertLevel = case(Result=="OK",1,Result=="WARNING",2,Result=="KO",3)
| rangemap field=AlertLevel low=1-1 elevated=2-2 severe=3-3 default=guarded
| fields - AlertLevel
0 Karma

Champion

If you mean "now" as the current time, then that is easy to add. Without going back and changing other parts of you search, you should be able to add the following.

| eval Excessive = if ((now() - strptime(When,"%Y-%m-%d %H:%M:%S")) > AVGDuration, 1, 0)
0 Karma

Champion

The issue is probably because AVGDuration is a duration interval, not an epoch-based time value. You need to use a different function, because strftime assumes you are sending it some kind of epoch time.

I would replace your last formatting line with the following:

| eval AVGDuration = tostring(AVGDuration,"duration")

View solution in original post

Communicator

Now it works fine but how can I convert from this duration from nr of minutes in HH:MM:SS ?

What is an epoch-based timestamp?

0 Karma

Champion

I am sorry, I got my time functions a little confused. I have updated my response to use a different function that should get you the duration value in the format you are looking for.

When I said "epoch-based timestamp", I really meant an epoch time value. I have corrected the wording. The point is that strftime expects the argument you pass to it to be a time value based on the number of seconds since the epoch time of Jan 1, 1970. Your duration value is only the number seconds indicating the amount of time between two other time values, so strftime is not appropriate for formatting the duration.

Champion

I do realize this has a slightly different effect compared to using fieldformat, but I am unclear on how to achieve the desired effect of altering the display value for the duration without altering the actual values. Maybe someone else can help with that.

State of Splunk Careers

Access the Splunk Careers Report to see real data that shows how Splunk mastery increases your value and job satisfaction.

Find out what your skills are worth!