Splunk Search

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

andreafebbo
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

rjthibod
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

rjthibod
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

andreafebbo
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

andreafebbo
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

rjthibod
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.

andreafebbo
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

rjthibod
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.

andreafebbo
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

rjthibod
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

rjthibod
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

rjthibod
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")

andreafebbo
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

rjthibod
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.

rjthibod
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.

Get Updates on the Splunk Community!

What's new in Splunk Cloud Platform 9.1.2312?

Hi Splunky people! We are excited to share the newest updates in Splunk Cloud Platform 9.1.2312! Analysts can ...

What’s New in Splunk Security Essentials 3.8.0?

Splunk Security Essentials (SSE) is an app that can amplify the power of your existing Splunk Cloud Platform, ...

Let’s Get You Certified – Vegas-Style at .conf24

Are you ready to level up your Splunk game? Then, let’s get you certified live at .conf24 – our annual user ...