topic Re: How to calculate the duration of a single event? in Splunk Search

How to calculate the duration of a single event?

johnoke — Mon, 26 Sep 2016 18:42:21 GMT

Please bear with me as I’m sure this is very simple. I’ve seen examples here of calculating duration for a transaction with multiple log events, but this one has the start and end times in a single event.

In the above example, I’ve tried

|eval  myduration=STIN_END_DTM-STIN_BEG_DTM

And

|concurrency duration=STIN_END_DTM-STIN_BEG_DTM

both which take the command without error but does not create a duration field.

Please be gentle in telling me what I’m missing! Thanks.

Re: How to calculate the duration of a single event?

MuS — Mon, 26 Sep 2016 19:27:45 GMT

Hi johnoke,

your STIN_END_DTM and STIN_BEG_DTM are strings and not numeric values, therefore Splunk cannot calculate a duration with them. You need to strptime() them first and use the resulting epoch to calculation the duration:

  your base search here 
  | eval STIN_END_DTM=strptime(STIN_END_DTM, "%b %d %Y %H:%M:%S.%3N%P"), STIN_BEG_DTM=strptime(STIN_BEG_DTM, "%b %d %Y %H:%M:%S.%3N%P")
  | eval duration=STIN_END_DTM - STIN_BEG_DTM

Take a look at the docs http://docs.splunk.com/Documentation/Splunk/6.4.3/SearchReference/Commontimeformatvariables#Date_variables for more details on the Date and time format variables.

Hope this helps ...

cheers, MuS

Re: How to calculate the duration of a single event?

johnoke — Tue, 29 Sep 2020 11:10:18 GMT

That makes perfect sense and I've tried several variations of the above, all to no effect. it simply ignores the resulting field, so I assume a conversion error is still happening. Is that error logged somewhere? I couldn't find it on the server (ironic?). Or a debug option to see where it's failing?

The reserved fields date_hour, date_minute and date_second are fine and can be used in an eval. But this isn't cutting it for whatever reason.
... | eval EVAL-myfield1 = strptime(STIN_BEG_DTM,"%b %d %Y %I:%M:%S.%3N%P")

Thanks again.

Re: How to calculate the duration of a single event?

MuS — Tue, 27 Sep 2016 19:40:35 GMT

Can you please provide some real world samples of your events as text not as screen shot?

Re: How to calculate the duration of a single event?

johnoke — Tue, 29 Sep 2020 11:10:54 GMT

I set up a field extraction (maybe that's the problem?) like this. I took the defaults after highlighting the 2 Transaction_Start,Transaction_End fields. I re-imported the sample below and the field extracts appear to work well.

EXTRACT- Transaction_Start,Transaction_End
Owner admin
App search
Permissions Owner App All apps
Source type SAMPLE_CMLU
Sample event

00007103-FFA4-4BF7-BB30-D3EE3F83807D|93075237|438A0E3E-CA6A-4320-8ABB-C7C7F40DBDD7|Processing|EADJ|Sep 19 2016  4:41:58:003PM|Sep 19 2016  4:41:59:390PM|cmcaclcl.cpp|2511|CMC_APP_CLAIMS_BASE::SetStatTime|cmcaclcl.cpp|2540|CMC_APP_CLAIMS_BASE::SetStatTime|E|1|Jan  1 1753 12:00:00:000AM
Fields Transaction_Start,Transaction_End

Regular Expression

^(?:[^\|\n]*\|){5}(?P[^\|]+)\|(?P[^\|]+)

My search is this:

host= | eval T_Start=strptime(Transaction_Start, "%b %d %Y %I:%M:%S.%3N%P"), T_End=strptime(Transaction_End, "%b %d %Y %I:%M:%S.%3N%P")

T_Start and T_End are not displayed.

It won't let me attach a file due to my karma deficiency, but here's a copy/paste of a few rows of data.

00002A81-A2E6-4F0C-BBE0-157D8CF8F2B1|93075229|BC433907-71D5-4F58-9135-F4E10FC5F066|XSQL.POSTSAVE|EXTM|Sep 19 2016  3:28:33:936PM|Sep 19 2016  3:28:34:060PM|ceraxmgr.cpp|652|CER_EXIT_MGR::CallExit|ceraxmgr.cpp|654|CER_EXIT_MGR::CallExit|E|1|Jan 1 1753 12:00:00:000AM 00002B07-4AF8-4CBF-97DD-03DF217D5952|93075275|CBAA78E2-4FB5-453C-B0B0-5D12AF04DEA6|XSQL.POSTSAVE|EXTM|Sep 19 2016  4:04:49:823PM|Sep 19 2016  4:04:49:933PM|ceraxmgr.cpp|652|CER_EXIT_MGR::CallExit|ceraxmgr.cpp|654|CER_EXIT_MGR::CallExit|E|1|Jan 1 1753 12:00:00:000AM 00006119-1E3E-4636-8596-0C8F9F85F57F|93075175|255A972F-9DCD-4676-9D07-A640BC53A2A0|XSQL.POSTSAVE|EXTM|Sep 19 2016  2:32:31:646PM|Sep 19 2016  2:32:31:706PM|ceraxmgr.cpp|652|CER_EXIT_MGR::CallExit|ceraxmgr.cpp|654|CER_EXIT_MGR::CallExit|E|1|Jan 1 1753 12:00:00:000AM 00007103-FFA4-4BF7-BB30-D3EE3F83807D|93075237|438A0E3E-CA6A-4320-8ABB-C7C7F40DBDD7|Processing|EADJ|Sep 19 2016  4:41:58:003PM|Sep 19 2016  4:41:59:390PM|cmcaclcl.cpp|2511|CMC_APP_CLAIMS_BASE::SetStatTime|cmcaclcl.cpp|2540|CMC_APP_CLAIMS_BASE::SetStatTime|E|1|Jan 1 1753 12:00:00:000AM 0000884A-F7F1-475C-9691-EEFAFA08AFD1|93075167|                                    |Electronic Claim|EADJ|Sep 19 2016  4:57:15:016PM|Sep 19 2016  4:58:30:610PM|cmcaclcl.cpp|2511|CMC_APP_CLAIMS_BASE::SetStatTime|cmcaclcl.cpp|2540|CMC_APP_CLAIMS_BASE::SetStatTime|E|1|Jan 1 1753 12:00:00:000AM 0000A99A-87A3-41AB-8D4C-93DEBCD490BE|93075237|90321E52-5EF1-4E7B-B2F7-40CB60BCF248|PRESAVE|EXTT|Sep 19 2016  3:11:16:863PM|Sep 19 2016  3:11:17:160PM|ceraxmgr.cpp|562|CER_EXIT_MGR::CallExits|ceraxmgr.cpp|600|CER_EXIT_MGR::CallExits|E|1|Jan 1 1753 12:00:00:000AM 0000C487-7A06-44B5-B2ED-33C2C590A0A4|93075211|AD666596-797D-4385-8EFB-B9EB0A10322C|PRESAVE|EXTT|Sep 19 2016  1:35:02:923PM|Sep 19 2016  1:35:03:000PM|ceraxmgr.cpp|562|CER_EXIT_MGR::CallExits|ceraxmgr.cpp|600|CER_EXIT_MGR::CallExits|E|1|Jan 1 1753 12:00:00:000AM 0000C66E-EA51-4924-B862-36C9A946FC2D|93075207|B8260148-8FFD-4522-80A1-AB9B65255552|XSQL.POSTSAVE|EXTM|Sep 19 2016  2:24:34:376PM|Sep 19 2016  2:24:34:423PM|ceraxmgr.cpp|652|CER_EXIT_MGR::CallExit|ceraxmgr.cpp|654|CER_EXIT_MGR::CallExit|E|1|Jan 1 1753 12:00:00:000AM 0000E31F-A5DF-4207-B7B5-E33A13D4D9BD|93075175|F7C77CEB-00DA-4888-9551-68878576AE0E|POSTSAVE|EXTT|Sep 19 2016  1:59:42:586PM|Sep 19 2016  1:59:42:786PM|ceraxmgr.cpp|562|CER_EXIT_MGR::CallExits|ceraxmgr.cpp|600|CER_EXIT_MGR::CallExits|E|1|Jan 1 1753 12:00:00:000AM 0001151F-C540-4EE5-871A-69CC4EEC0881|93075267|797E20D7-C2CB-4F0C-9678-3DF66A0C562D|XSQL.POSTSAVE|EXTM|Sep 19 2016  2:23:10:956PM|Sep 19 2016  2:23:10:986PM|ceraxmgr.cpp|652|CER_EXIT_MGR::CallExit|ceraxmgr.cpp|654|CER_EXIT_MGR::CallExit|E|1|Jan 1 1753 12:00:00:000AM 00012937-948A-452F-A542-261F8C77FDEF|93075275|8225051D-67EB-4C4A-BBB5-0E13F6B0764E|POSTSAVE|EXTT|Sep 19 2016  5:02:13:290PM|Sep 19 2016  5:02:13:366PM|ceraxmgr.cpp|562|CER_EXIT_MGR::CallExits|ceraxmgr.cpp|600|CER_EXIT_MGR::CallExits|E|1|Jan 1 1753 12:00:00:000AM

Thanks!

Re: How to calculate the duration of a single event?

gcusello — Wed, 28 Sep 2016 13:36:26 GMT

try

mysearch | eval STIN_END_DTM=strptime(STIN_END_DTM, "%b %d %Y %H:%M:%S:%3N%P"), STIN_BEG_DTM=strptime(STIN_BEG_DTM, "%b %d %Y %H:%M:%S:%3N%P")| eval duration=STIN_END_DTM - STIN_BEG_DTM| table STIN_BEG_DTM STIN_END_DTM duration

with the examples you inserted you'll have

STIN_BEG_DTM         STIN_END_DTM        duration
1474254451.276000   1474254451.290000   0.014000

Bye.
Giuseppe

Re: How to calculate the duration of a single event?

johnoke — Wed, 28 Sep 2016 16:05:16 GMT

ah yes it was the colon vs the dot for millisconds. Took me forever to find that.

Wow, great catch. Thanks to @MuS and @cusello! Great job.

Re: How to calculate the duration of a single event?

johnoke — Wed, 28 Sep 2016 16:06:29 GMT

Thanks so much for pointing out the original issue and docs. %M:%S:%3N%P worked.