0

First Event

06:09:17:362 INFO com.x.y.ConnApp - Making a GET Request

Second Event

06:09:17:480 INFO com.a.b.Response - Output Status Code: 200

Now I want to calculate duration of these two events for every request. I went over the solutions on splunk and Stack Overflow, but still can't get the proper result.

Sat
  • 3,520
  • 9
  • 39
  • 66

2 Answers2

1

The easy answer is the transaction command, although it has a couple of drawbacks. The first is the command can be a resource hog. The other is can be "greedy" in that multiple requests might be taken to be a single transaction. We'll take care of the second issue with the maxevents option. There's not much we can do about the first except avoid using transaction.

index=foo ("Making a GET Request" OR "Output Status Code:")
| transaction maxevents=2 startswith="Making a GET Request" endswith="Output Status Code:"
| table duration

Another option uses the streamstats command to calculate the difference between adjacent events. This should perform better than transaction.

index=foo ("Making a GET Request" OR "Output Status Code:")
| streamstats window=2 range(_time) as duration
``` Erase the duration field for start events. ```
| eval duration = if(searchmatch("Making a GET Request"),"", duration)
| table _raw duration

Both queries assume the start and end events for different requests are not intermingled.

RichG
  • 9,063
  • 2
  • 18
  • 29
  • if the events from different requests are intermingled, you can `sort` first - do this semifrequently – warren Jan 23 '23 at 13:14
1

With the current logging messages, it will be tricky to group logs who are linked by the same source (imagine multiple calls who generate successive Making a GET messages)

In this case, I suggest to spread a ‘correlation Id’ in the logging message

Then you can identify exactly the messages who are triggered by the same source

This involve a change of the app logging function (you can search the following libs: log4/mcd/sleuth)

Hakan
  • 126
  • 5