Why are milliseconds getting padded with multiple zeros when converting timestamps to epoch format to calculate time difference?

[ambujhbti]

Hello ,

I am trying to calculate time diff between two fields in a single event.

My current search:

sourcetype="XXXXXX"   host="XXXXXX" |convert timeformat="%m/%d/%Y %H:%M:%S:%N" mktime(End_time)|convert timeformat="%m/%d/%Y %H:%M:%S:%N" mktime(WILY_Date)| eval diff=End_time-WILY_Date| where diff <0| eval eventid=index + "__" + _cd+"__" + splunk_server|table eventid diff End_time WILY_Date

I also tried

sourcetype="XXXXXX"   host="XXXXXX"  |eval diff= strptime(End_time,"%m/%d/%Y %H:%M:%S:%3N")- strptime(WILY_Date,"%m/%d/%Y %H:%M:%S:%3N")  |where diff <0| eval eventid=index + "__" + _cd+"__" + splunk_server|table eventid diff End_time WILY_Date

But what I see is, when then the timestamp is converted to epoch format, the milliseconds field is padded with 0s.

For example:

WILY_Date: 06/25/2015 09:59:43:58
End_time: 06/25/2015 09:59:43:230

the above time is converted to

WILY_Date: 06/25/2015 09:59:43:5800000
End_time: 06/25/2015 09:59:43:23000000

So that difference between diff=End_time-WILY_Date results in negative values. For more clarity I have attached the screen-shot.

I don't know what to do about it. Can somebody help me? It's already eaten much of my time.

Thank you!

[martin_mueller · Accepted solution]

The key issue is that your subseconds aren't padded with zeroes to the left. Basically, Splunk is seeing 43.58 seconds and not 43 seconds, 58 milliseconds. Use this instead of your convert:

... | eval WILY_Date = strptime(replace(replace(WILY_Date, ":(\d)$", ":0\1"), ":(\d\d)$", ":0\1"), "%m/%d/%Y %H:%M:%S:%N")

This will add one or two zeroes between the colon and the milliseconds to turn it into proper subseconds.

[ambujhbti]

Hello Martin,

Thank you so much!

[ambujhbti]

Hello,

One more example

TimeDifference End_time WILY_Date
-.22 07/15/2015 16:21:09:343000000 07/15/2015 16:21:09:560000000
-.65 07/15/2015 16:21:09:299000000 07/15/2015 16:21:09:950000000
-.53 07/15/2015 16:21:08:269000000 07/15/2015 16:21:08:800000000
-.29 07/15/2015 16:21:08:155000000 07/15/2015 16:21:08:440000000
-.3 07/15/2015 16:21:21:550000000 07/15/2015 16:21:21:580000000
-.11 07/15/2015 16:21:21:505000000 07/15/2015 16:21:21:620000000
-.44 07/15/2015 16:21:21:400000000 07/15/2015 16:21:21:840000000
-.63 07/15/2015 16:21:21:347000000 07/15/2015 16:21:21:980000000

Thank you!

[ambujhbti]

Hello ,

I am presenting one more example to show data.

TimeDifference End_time WILY_Date
-.22 07/15/2015 16:21:09:343000000 07/15/2015 16:21:09:560000000
-.65 07/15/2015 16:21:09:299000000 07/15/2015 16:21:09:950000000
-.53 07/15/2015 16:21:08:269000000 07/15/2015 16:21:08:800000000
-.29 07/15/2015 16:21:08:155000000 07/15/2015 16:21:08:440000000
-.3 07/15/2015 16:21:21:550000000 07/15/2015 16:21:21:580000000
-.11 07/15/2015 16:21:21:505000000 07/15/2015 16:21:21:620000000
-.44 07/15/2015 16:21:21:400000000 07/15/2015 16:21:21:840000000
-.63 07/15/2015 16:21:21:347000000 07/15/2015 16:21:21:980000000

Thank you.