topic Re: Time stamp difference Help! in Splunk Search

Time stamp difference Help!

kc_prane — Mon, 19 Aug 2024 17:59:32 GMT

Hi, how do i get the difference in the time stamp? . I want to know the difference between the starting timestamp and the completed time stamp

"My base query"  
| rex "status:\s+(?<Status>.*)\"}" 
| rex field=_raw "\((?<Message_Id>[^\)]*)" 
| rex "Path\:\s+(?<ResourcePath>.*)\"" 
| eval timestamp_s = timestamp/1000 
| eval human_readable_time = strftime(timestamp_s, "%Y-%m-%d %H:%M:%S") 
| transaction Message_Id startswith="Starting execution for request" endswith="Successfully completed execution"

RAW_LOG

8/19/24

9:56:05.113 AM

{"id":"38448254623555555", "timestamp":1724079365113, "message":"(fghhhhhh-244933333-456789-rrrrrrrrrr) Startingexecutionforrequest:f34444-22222-44444-999999-0888888"}

{"id":"38448254444444444", "timestamp":1724079365126, "message":"(fghhhhhh-244933333-456789-rrrrrrrrrr) Methodcompletedwithstatus:200"}

{"id":"38448222222222222", "timestamp":1724079365126, "message":"(fghhhhhh-244933333-456789-rrrrrrrrrr) Successfullycompletedexecution"}

{"id":"38417111111111111", "timestamp":1724079365126, "message":"(fghhhhhh-244933333-456789-rrrrrrrrrr) AWS Integration Endpoint RequestId :f32222-22222-44444-999999-0888888"}

Re: Time stamp difference Help!

richgalloway — Mon, 19 Aug 2024 18:18:54 GMT

The transaction command creates a field called "duration" that is the difference in the _time values from the first and last events of the transaction. That should fill this need, assuming _time is set by properly extracting the "timestamp" value at index time.

The transaction command is not very performant, however. A more efficient way to do it uses stats.

"My base query" ("Starting execution for request" OR "Successfully completed execution") | rex "status:\s+(?<Status>.*)\"}" | rex field=_raw "\((?<Message_Id>[^\)]*)" | rex "Path\:\s+(?<ResourcePath>.*)\"" | rex "timestamp\\\":(\d+)" | stats min(timestamp) as startTime, max(timestamp) as endTime by Message_Id | eval duration = endTime - startTime | eval end_timestamp_s = endTime/1000, start_timestamp_s = startTime/1000 | eval human_readable_etime = strftime(end_timestamp_s, "%Y-%m-%d %H:%M:%S"), human_readable_stime = strftime(start_timestamp_s, "%Y-%m-%d %H:%M:%S"), duration = tostring(duration, "duration") | table Message_Id human_readable_stime human_readable_etime duration

Re: Time stamp difference Help!

kc_prane — Tue, 20 Aug 2024 02:45:36 GMT

Hi @ richgalloway Thanks for the reply,The query looks good but I am missing the below two fields in the results. Can help in getting them populated.

1) | rex "status:\s+(?<Status>.*)\"}"
2) | rex "Path\:\s+(?<ResourcePath>.*)\""

Re: Time stamp difference Help!

richgalloway — Tue, 20 Aug 2024 12:48:29 GMT

Try this query

"My base query" ("Starting execution for request" OR "Successfully completed execution") | rex "status:\s+(?<Status>.*)\"}" | rex field=_raw "\((?<Message_Id>[^\)]*)" | rex "Path\:\s+(?<ResourcePath>.*)\"" | rex "timestamp\\\":(\d+)" | stats min(timestamp) as startTime, max(timestamp) as endTime, values(*) as * by Message_Id | eval duration = endTime - startTime | eval end_timestamp_s = endTime/1000, start_timestamp_s = startTime/1000 | eval human_readable_etime = strftime(end_timestamp_s, "%Y-%m-%d %H:%M:%S"), human_readable_stime = strftime(start_timestamp_s, "%Y-%m-%d %H:%M:%S"), duration = tostring(duration, "duration") | table Message_Id human_readable_stime human_readable_etime duration Status Path

Re: Time stamp difference Help!

kc_prane — Tue, 20 Aug 2024 18:59:07 GMT

Hi richgalloway the below query gives me all the required results when OR "status" OR "Path" is added to the query. However, its taking the wrong time stamp. Its taking the difference between the first two events. i need the duration of "Successfully completed execution" - "Starting execution for request" time stamps.

"My Base query" ("Starting execution for request" OR "Successfully completed execution" OR "status" OR "Path")

| rex "status:\s+(?<Status>.*)\"}" | rex field=_raw "\((?<Message_Id>[^\)]*)" | rex "Path\:\s+(?<ResourcePath>.*)\"" | rex "timestamp\:\s+(?<timestamp>.*)\"" | stats min(timestamp) as startTime, max(timestamp) as endTime, values(*) as * by Message_Id | stats values(*) as * by Message_Id | eval end_timestamp_s = endTime/1000, start_timestamp_s = startTime/1000 | eval duration = end_timestamp_s - start_timestamp_s | eval human_readable_etime = strftime(end_timestamp_s, "%Y-%m-%d %H:%M:%S"), human_readable_stime = strftime(start_timestamp_s, "%Y-%m-%d %H:%M:%S"), duration = tostring(duration, "duration") | table Message_Id human_readable_stime human_readable_etime duration Status ResourcePath

Re: Time stamp difference Help!

richgalloway — Tue, 20 Aug 2024 19:27:16 GMT

My original query only returned start and end events so the duration calculation worked. With the change to the base query, we'll have to change how we extract times.

"My Base query" ("Starting execution for request" OR "Successfully completed execution" OR "status" OR "Path") | rex "status:\s+(?<Status>.*)\"}" | rex field=_raw "\((?<Message_Id>[^\)]*)" | rex "Path\:\s+(?<ResourcePath>.*)\"" | rex "timestamp\:\s+(?<timestamp>.*)\"" | eval startTime = if(searchmatch("Starting execution for request"), timestamp, startTime), endTime = if(searchmatch("Successfully completed execution"), timestamp, endTime) | stats max(startTime) as startTime, max(endTime) as endTime, values(*) as * by Message_Id | stats values(*) as * by Message_Id | eval end_timestamp_s = endTime/1000, start_timestamp_s = startTime/1000 | eval duration = end_timestamp_s - start_timestamp_s | eval human_readable_etime = strftime(end_timestamp_s, "%Y-%m-%d %H:%M:%S"), human_readable_stime = strftime(start_timestamp_s, "%Y-%m-%d %H:%M:%S"), duration = tostring(duration, "duration") | table Message_Id human_readable_stime human_readable_etime duration Status ResourcePath