Splunk Search

Time stamp difference Help!

kc_prane
Communicator

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-rrrrrrrrrrAWS Integration Endpoint RequestId :f32222-22222-44444-999999-0888888"}

 

 

 

kc_prane_0-1724083710019.png


 

 

 

 

Labels (3)
Tags (1)
0 Karma
1 Solution

richgalloway
SplunkTrust
SplunkTrust

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
---
If this reply helps you, Karma would be appreciated.

View solution in original post

richgalloway
SplunkTrust
SplunkTrust

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

 

---
If this reply helps you, Karma would be appreciated.
0 Karma

kc_prane
Communicator

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

0 Karma

richgalloway
SplunkTrust
SplunkTrust

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
---
If this reply helps you, Karma would be appreciated.
0 Karma

kc_prane
Communicator

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
0 Karma

richgalloway
SplunkTrust
SplunkTrust

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
---
If this reply helps you, Karma would be appreciated.
Get Updates on the Splunk Community!

How to Monitor Google Kubernetes Engine (GKE)

We’ve looked at how to integrate Kubernetes environments with Splunk Observability Cloud, but what about ...

Index This | How can you make 45 using only 4?

October 2024 Edition Hayyy Splunk Education Enthusiasts and the Eternally Curious!  We’re back with this ...

Splunk Education Goes to Washington | Splunk GovSummit 2024

If you’re in the Washington, D.C. area, this is your opportunity to take your career and Splunk skills to the ...