How to find difference between endTime and beginTime to find response time?

[huligesh]

In logs we have endTime and beginTime, the difference of these timings gives response time of that event. Format of beginTime and endtime are %Y-%m-%d %H:%M:%S.%3N (eg. 2017/01/20 14:24:48.288).

Could some explain how to find difference of these timing variables of same event?

[somesoni2 · Accepted solution]

Assuming the fields endTime and beginTime are extracted, Splunk will be treating them as strings. To do mathematical operations on them, you need to convert them to epoch format (may be temporarily) using strptime function in eval, like this:

Updated Time format for sample events provided in comments below

your base search | eval response_time=strptime(endTime,"%Y/%m/%d %H:%M:%S.%3N") - strptime(beginTime,"%Y/%m/%d %H:%M:%S.%3N") 

See this for more information on strptime command.
http://docs.splunk.com/Documentation/Splunk/latest/SearchReference/CommonEvalFunctions#Date_and_Time...

[huligesh]

Thank you!

[huligesh]

Thank you! Appreciate, I got response_time now.

Response times are format x.xxxxxx. I want to display x.xxx, how this could be done?

[somesoni2]

You can use the round command to trim it to show only 3 digits after decimal.

 your base search | eval response_time=strptime(endTime,"%Y/%m/%d %H:%M:%S.%3N") - strptime(beginTime,"%Y/%m/%d %H:%M:%S.%3N") | eval response_time=round(response_time,3)

[huligesh]

Hi,
I tried below query:
base search | rex "beginTime=(?[^;]+);endTime=(?[^;]+)" | eval response_time=strptime(endTime,"%Y-%m-%d %H:%M:%S.%3N") - strptime(beginTime,"%Y-%m-%d %H:%M:%S.%3N") | table response_time, beginTime

Result: response_time column is blank, beginTime has data

[somesoni2]

The timeformat has to be changed in the strptime command. Have you tried updated one?

your base search | eval response_time=strptime(endTime,"%Y/%m/%d %H:%M:%S.%3N") - strptime(beginTime,"%Y/%m/%d %H:%M:%S.%3N")

[huligesh]

Hi,
could you provide the updated query? I don't see updated query in your previous commet

[somesoni2]

The original answer is updated.

[huligesh]

Hi,
base search | head 10 | table beginTime endTime result is displaying beginTime and endTime in table without any issues. However, I tried 2nd query you provided and not getting values in response_time column.

Please let me know if you need info here. Appreciate you time!

[somesoni2]

Found the issue. The time.format doesn't match the raw data. Try the updated query

[huligesh]

Hi,
Thanks for you time. I tried and I got blank data in response_time. You have assumed endTime and beginTime are extracted, I want to make sure how our log looks. Below is the sample log:

timestamp=2017/01/20 14:24:48.335;resource=;beginTime=2017/01/20 14:24:48.288;endTime=2017/01/20 14:24:48.335;generateRecord=True;os=Longhorn;gmtOffset=-0500;
taxonomyNodeGuid=;topicName=;transId=ddb4kbc4-2rc4-4265-9484-6be12b4ca0ef;sessionId=c99r725c-aa5c-4553-9ddb-5f74e3543e36;researchThreadId=60552351-f47f-49fc-a2f6-eba5hf521033;.....

beginTime and endTime field type are "string" as seen in AllFields window. I see no data in response time column for below query:

base search| eval response_time=strptime(endTime,"%Y-%m-%d %H:%M:%S.%3N") - strptime(beginTime,"%Y-%m-%d %H:%M:%S.%3N") | table response_time, beginTime, endTime

[somesoni2]

Since the field values contain space, I'm guessing the full values are not captured. Could you run this and see if you get full date in format "%Y-%m-%d %H:%M:%S.%3N" for both beginTime and endTime?

your base search | head 10 | table beginTime endTime

If they are not coming as full values, try something like this.

your base search | rex "beginTime=(?<beginTime>[^;]+);endTime=(?<endTime>[^;]+)" | eval response_time=strptime(endTime,"%Y-%m-%d %H:%M:%S.%3N") - strptime(beginTime,"%Y-%m-%d %H:%M:%S.%3N")