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

[rsharma1984]

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]

@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

[rsharma1984]

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).

[niketn]

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.

[rsharma1984]

@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

[vishaltaneja070]

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"

[rsharma1984]

@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?

[vishaltaneja070]

@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.