How to find the time difference between two events?

[ominous_ghost]

Our application logs for each method: when it begins, when it ends, and the thread it is on. 

We are wanting to visualize how long each method takes. 

The logging structure is as follows: 

[Thread #] Timestamp Begin/End MethodName

Example: 
[Thread-13569 (ActiveMQ-client-global-threads)] Fri Oct 21 14:29:00 EDT 2022 Begin purgeHistory(Connection, String)

[Thread-13569 (ActiveMQ-client-global-threads)] Fri Oct 21 14:29:00 EDT 2022 End purgeHistory(Connection, String)

So we need a way to match every method "Begin" with every method "End" that's on the same thread, to be able to calculate and display how long each method took to execute. Is there any way we could get some help tackling this query? 

[ominous_ghost]

What would need to change if the following assumption was not true?

“I'll also assume each thread/method combination has a single Begin and End event.” 

We are hoping to be able to do many things with the above base search, like find the maximum time, average time, etc a particular method took within the logs. Or even just list the methods being called over and over and how long each of those took. 

[ITWhisperer]

Please expand on your usecase

For example, if your methods can be called multiple times by a thread, but the methods are not called recursively, you could do something like this

| sort 0 _time
| streamstats count as invocation global=f by event thread method
| streamstats window=1 current=f global=f values(_time) as previous_time by invocation thread method
| eval duration=if(event="end",_time-previous_time,null())

where event holds "begin" or "end" as appropriate for your events

[richgalloway]

I'll assume the thread number, method, and timestamps are already extracted.  I'll also assume each thread/method combination has a single Begin and End event.

The first step is to match the events.  We'll do that with the stats command.  Then we can compare timestamps.  The only way to do that is to convert them into epoch form using strptime.

<<your search for the events>>
```Convert timestamps into epoch form, with separate fields for Begin/End```
| eval beginTS=if(searchmatch("Begin"),strptime(Timestamp, "%a %b %d %H:%M:%S %Z %Y"), null()), endTS=if(searchmatch("End"),strptime(Timestamp, "%a %b %d %H:%M:%S %Z %Y"), null())
```Group events by thread and method```
| stats values(*) as * by Thread, MethodName
```Compute the duration and display it as H:MM:SS```
| eval duration=(tostring(endTS-beginTS, "duration")