Time stamp difference Help!

[kc_prane]

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"}

[richgalloway]

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

[kc_prane]

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>.*)\"" 

[richgalloway]

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

[kc_prane]

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

[richgalloway · Accepted solution]

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