Splunk Search

How do you find the duration between A to C events (startswith & endswith) where event B needs to be there in the middle?

rsharma1984
Explorer

Example:

Event A: LoggingAspect.BeforeController
Event B: Found in Cache
Event C: LoggingAspect.afterReturningController

I want to know the total execution time from A to C. The common field between all 3 events is traceId.

We have an application that tries to fetch the data from Cache, and if data is not found in Cache, it goes to a Webservice. So I wanted to know how much is the average response times when I am serving the data from cache vs from webservice. Basically, the event B is printed in the log when the data is served from cache.

 index=rs | transaction traceId startswith="LoggingAspect.BeforeController " endswith="LoggingAspect.afterReturningController" | timechart span=1h avg(duration)

But the above query gives me other events as well, which don't have B. I wanna add Event B to the query and eventually see a response time chart.

niketn
Legend

@rsharma1984, you can try the following to filter and keep only required events.

 index=rs traceId=* ("LoggingAspect.BeforeController" OR "LoggingAspect.afterReturningController")
| transaction traceId startswith="LoggingAspect.BeforeController " endswith="LoggingAspect.afterReturningController" 
| timechart span=1h avg(duration)

If your use case is to plot hourly average duration between Before and After Controller events over time, you can also try out stats command:

 index=rs traceId=* ("LoggingAspect.BeforeController" OR "LoggingAspect.afterReturningController")
 | eval type=case( searchmatch("LoggingAspect.BeforeController"),"BeforeController",searchmatch("LoggingAspect.afterReturningController"), "afterReturningController")
 | stats count as eventCount values(type) as type min(_time) as _time max(_time) as LatestTime by traceId
 | search eventCount=2 AND (type="BeforeController" AND type="afterReturningController")
 | eval duration=LatestTime-_time
 | timechart span=1h avg(duration)

You can find several examples on Splunk Answers to use stats for transaction for improved performance. Refer to Splunk Documentation for deciding between Event Grouping and correlation method: https://docs.splunk.com/Documentation/Splunk/latest/Search/Abouteventcorrelation

____________________________________________
| makeresults | eval message= "Happy Splunking!!!"

rsharma1984
Explorer

Hi @niketnilay If you see my question above, I need to find all transactions which must have "Found in Cache" event as well (which triggers after "LoggingAspect.BeforeController" and before "LoggingAspect.afterReturningController" events).

0 Karma

niketn
Legend

As per your question the final pipe is a timechart of average duration between BeforeController and afterReturningController. So I dont know how you want the intermediate Event to fit in. Can you describe your use case with examples as to what you want your Splunk query to output and then we would be able to assist you better?

Do you just want to show all average duration of only the events that have all three types for a specific id? I believe your transaction command in the question was doing the same. This can also be done by stats which would perform better than transaction.

____________________________________________
| makeresults | eval message= "Happy Splunking!!!"
0 Karma

rsharma1984
Explorer

@niketnilay , Sure let me explain.

We have an application which tries to fetch the data from Cache & if data is not found in Cache it goes to a Webservice. So I wanted to know how much is the average response times when I am serving the data from cache vs from webservice. Basically, the event B is printed in log when data is served from cache. Also updated the question. Thanks

0 Karma

vishaltaneja070
Motivator

Hello @rsharma1984

Try this:

index=rs | transaction traceId startswith="LoggingAspect.BeforeController " endswith="Found in Cache" | append [search index=rs | transaction traceId startswith="Found in Cache" endswith="LoggingAspect.afterReturningController"] | transaction traceId startswith="LoggingAspect.BeforeController " endswith="LoggingAspect.afterReturningController"
0 Karma

rsharma1984
Explorer

@vishaltaneja07011993 , I see few concerns with this
1. its gonna be very expensive
2. While finding events between A & B, and then B & C and then A & C - I don't think if get "duration" field here it will tell me the right value?

0 Karma

vishaltaneja070
Motivator

@rsharma1984

The best way is to not use transaction, try to replace it with eventstats and also for duration case, we need to rename after the first search and try to add the result to the other to get the results.

0 Karma
Get Updates on the Splunk Community!

What's new in Splunk Cloud Platform 9.1.2312?

Hi Splunky people! We are excited to share the newest updates in Splunk Cloud Platform 9.1.2312! Analysts can ...

What’s New in Splunk Security Essentials 3.8.0?

Splunk Security Essentials (SSE) is an app that can amplify the power of your existing Splunk Cloud Platform, ...

Let’s Get You Certified – Vegas-Style at .conf24

Are you ready to level up your Splunk game? Then, let’s get you certified live at .conf24 – our annual user ...