How can I find delta between events using transaction command?

[limalbert]

I could retrieve the list of the transactions as a single event below. Transactions start with "Dashboard Load:" and end with "Total Dashboard Load Time"

| rex "Account: (?<account>[^\,]*), SiteID: (?<siteID>[^\s]*) - (?<duration_in_ms>[^\s]*) milliseconds on Requestor: (?<requestor>[^\,]*)"
| transaction agent endswith="Total Dashboard Load Time"
| eval duration_in_sec=round(avg(duration_in_ms)/1000,2)
| table agent account siteID flow duration_in_sec

I could find the delta between each event as multiple events with below

| rex "Account: (?<account>[^\,]*), SiteID: (?<siteID>[^\s]*) - (?<duration_in_ms>[^\s]*) milliseconds on Requestor: (?<requestor>[^\,]*)"
| streamstats current=f last(_time) as last_time2 by agent
| rename _time as current_time2
| eval delta= last_time2 - current_time2
| eval last_time =strftime(last_time2, "%m/%d, %H:%M:%S.%6N")
| eval current_time =strftime(current_time2, "%m/%d, %H:%M:%S.%6N")
| table agent account siteID flow duration_in_sec last_time current_time delta

I'm looking to see if I can find a delta between events in a single transaction. The transaction starts with "Dashboard Load" and ends with "Total Dashboard Load Time"

Expected Result Format:

agent, account, siteID, list of flow (all 5 Dashboard Load actions), duration_in_sec, list of event times, list of delta between event time

1. agent - the name of the agent
2. account - account #
3. siteID - site#
4. list of flow - all action flows
5. durations_in_sec - Total Dashboard Load Time
6. list of event times - List showing all event time
7. list of the delta between event time - List showing 4 delta times between each flow

Below are a sample of 2 data of 5 events

2021-12-16 05:30:43,834 alpha - Dashboard Load: User Clicked on New
2021-12-16 05:30:46,498 alpha - Dashboard Load: User Clicked on AccountSearch
2021-12-16 05:31:05,420 alpha - Dashboard Load: User Clicked on Search with String abcdef
2021-12-16 05:31:08,557 alpha - Dashboard Load: User clicked on Searched Result 123456
2021-12-16 05:31:12,234 alpha - Total Dashboard Load Time for Account: 000111222, SiteID: 123- 3438.0 milliseconds on Requestor: xoxoxo

[yuanliu]

Based on your sample code and data, I am guessing that values(X) and list(X) are what you are looking for, not transaction, something like this:

| rex "(?<agent>\w+)\s-\s(?<event>.+)" ```I have to guess that "alpha" is agent```
| rex field=event "Account: (?<account>[^\,]*), SiteID: (?<siteID>[^\s]*) - (?<duration_in_ms>[^\s]*) milliseconds on Requestor: (?<requestor>[^\,]*)"
| streamstats current=f last(_time) as last_time2 by agent
| rename _time as current_time2
| eval delta= if(isnull(last_time2), "n/a", last_time2 - current_time2)
| eval last_time =if(isnull(last_time2), "n/a", strftime(last_time2, "%m/%d, %H:%M:%S.%6N"))
| eval current_time =strftime(current_time2, "%m/%d, %H:%M:%S.%6N")
| eval duration_in_sec=round(avg(duration_in_ms)/1000,2)

| stats values(account) as account values(siteID) as siteID values(duration_in_sec) as duration_in_sec list(event) as flow list(current_time) as current_time list(last_time) as last_time list(delta) as delta by agent
| table agent account siteID flow duration_in_sec last_time current_time delta

[limalbert]

I would need transaction because each transaction starts with the event of "Total Dashboard Load Time" and ends with "Total Dashboard Load Time for Account:". I would need to group these events together and find the delta for each event in a transaction (in this case 5 events)

[yuanliu · Accepted solution]

You can combine transaction with streamstats.  I'll illustrate two slightly different tweaks.

The first is perhaps closest to the described end result.

| rex "(?<agent>\w+)\s-\s(?<event>.+)"
| rex field=event "Account: (?<account>[^\,]*), SiteID: (?<siteID>[^\s]*) - (?<duration_in_ms>[^\s]*) milliseconds on Requestor: (?<requestor>[^\,]*)"
| reverse
| streamstats current=f last(_time) as last_time2 by agent
| eval current_time2 = _time
| eval delta= if(isnull(last_time2), "n/a", current_time2 - last_time2)
| eval event = strftime(_time, "%Y-%m-%d %H:%M:%S,%3Q") . " <" . delta . "> " . event
| eval last_time =if(isnull(last_time2), "n/a", strftime(last_time2, "%m/%d, %H:%M:%S.%6N"))
| reverse
| transaction agent endswith="Total Dashboard Load Time" startswith="Clicked on New"
| eval duration_in_sec=round(avg(duration_in_ms)/1000,2)
| rename event as flow
| table _time agent account siteID flow duration duration_in_sec last_time

The first note is that the two reverse's will be very expensive for large volumes.  I removed delta as a column because transaction takes away its ordering; instead, "current time" and "delta" are both embedded into flow.  If desired, you can extract them out as columns for display purposes. (Note that delta "n/a" in the first event will be replaced by the delta between that event and the preceding last event.)  Additionally, "duration_in_sec" is actually the dashboard load time; duration of the transaction is provided by the transaction command, which I included for illustration.   Sample output as follows:

_time	agent	account	siteID	flow	duration	duration_in_sec	last_time
2021-12-16 05:30:43.834	alpha	000111222	123	2021-12-16 05:30:43,834 <n/a> Dashboard Load: User Clicked on New 2021-12-16 05:30:46,498 <2.664000> Dashboard Load: User Clicked on AccountSearch 2021-12-16 05:31:05,420 <18.922000> Dashboard Load: User Clicked on Search with String abcdef 2021-12-16 05:31:08,557 <3.137000> Dashboard Load: User clicked on Searched Result 123456 2021-12-16 05:31:12,234 <3.677000> Total Dashboard Load Time for Account: 000111222, SiteID: 123 - 3438.0 milliseconds on Requestor: xoxoxo	28.4	3.44	12/16, 05:30:43.834000 12/16, 05:30:46.498000 12/16, 05:31:05.420000 12/16, 05:31:08.557000 n/a

The second tweak is more economic because there is no reverse, but you have to tolerate some odd artifacts, or correct them in some way after you get the list.

| rex "(?<agent>\w+)\s-\s(?<event>.+)"
| rex field=event "Account: (?<account>[^\,]*), SiteID: (?<siteID>[^\s]*) - (?<duration_in_ms>[^\s]*) milliseconds on Requestor: (?<requestor>[^\,]*)"
| streamstats current=f last(_time) as last_time2 by agent
| eval current_time2 = _time
| eval delta= if(isnull(last_time2), "n/a", last_time2 - current_time2)
| eval event = strftime(_time, "%Y-%m-%d %H:%M:%S,%3Q") . " <" . delta . "> " . event
| eval last_time =if(isnull(last_time2), "n/a", strftime(last_time2, "%m/%d, %H:%M:%S.%6N"))
| transaction agent endswith="Total Dashboard Load Time" startswith="Clicked on New"
| eval duration_in_sec=round(avg(duration_in_ms)/1000,2)
| rename event as flow
| table _time agent account siteID flow duration duration_in_sec last_time

Sample result follows:

_time	agent	account	siteID	flow	duration	duration_in_sec	last_time
2021-12-16 05:30:43.834	alpha	000111222	123	2021-12-16 05:30:43,834 <2.664000> Dashboard Load: User Clicked on New 2021-12-16 05:30:46,498 <18.922000> Dashboard Load: User Clicked on AccountSearch 2021-12-16 05:31:05,420 <3.137000> Dashboard Load: User Clicked on Search with String abcdef 2021-12-16 05:31:08,557 <3.677000> Dashboard Load: User clicked on Searched Result 123456 2021-12-16 05:31:12,234 <n/a> Total Dashboard Load Time for Account: 000111222, SiteID: 123 - 3438.0 milliseconds on Requestor: xoxoxo	28.4	3.44	12/16, 05:30:46.498000 12/16, 05:31:05.420000 12/16, 05:31:08.557000 12/16, 05:31:12.234000 n/a

You can see that the delta and "last_time" are misaligned by one event.

Hope these help.