I'm trying to find out-of-order events in Splunk. This example is analogous to what happens in our system:
...
Time=15:40.09 Id=11 ScenarioId=7 Event=BlockChange Block=A-A
Time=15:40.11 Id=12 ScenarioId=7 Event=BlockChangeConfirmed Block=1-7
Time=15:41.00 Id=13 ScenarioId=2 Event=BlockChange Block=E-6
Time=15:41.01 Id=14 ScenarioId=7 Event=Restart
Time=15:41.05 Id=15 ScenarioId=2 Event=BlockChangeConfirmed Block=B-2
Time=15:41.14 Id=16 ScenarioId=3 Event=BlockChangeConfirmed Block=2-4
Time=15:41.15 Id=17 ScenarioId=2 Event=Restart
Time=15:41.16 Id=18 ScenarioId=3 Event=BlockChange Block=E-1
Time=15:43.24 Id=19 ScenarioId=8 Event=BlockChange Block=C-7
Time=15:43.27 Id=20 ScenarioId=8 Event=BlockChangeConfirmed Block=D-2
Time=15:43.35 Id=21 ScenarioId=8 Event=BlockChange Block=D-2
Time=15:43.40 Id=22 ScenarioId=8 Event=BlockChangeConfirmed Block=4-A
...
After a BlockChange event occurs for a particular Scenario, it needs to be confirmed before a new Block is assigned. Occasionally though a BlockChangeConfirmed event will be received before the BlockChange event (see Ids 16 and 18). I'm trying to write a query that will identify these out-of-order events.
My approach is to only consider Block* events , group them into transactions by ScenarioId starting with BlockChangeConfirmed and ending with BlockChange within a timespan of 10 seconds. So from a logical perspective, it would transform the above data into this:
ScenarioId=3: Time=15:41.14 Id=16 Event=BlockChangeConfirmed Block=2-4
Time=15:41.16 Id=18 Event=BlockChange Block=E-1
ScenarioId=8: Time=15:43.27 Id=20 Event=BlockChangeConfirmed Block=D-2
Time=15:43.35 Id=21 Event=BlockChange Block=D-2
This correctly identifies Ids 16 and 18, but also incorrectly identifies 20 and 21. So I need to include the Block field since it always changes between corresponding BlockChange and BlockChangeConfirmed events.
I'm having trouble expressing this in Splunk though. Depending on the query I use, it either returns every BlockChangeConfirmed event, or it doesn't identify when the Block field changes.
This is the base query that I'm using:
index="foo" sourcetype="bar" Block AND (Event=BlockChange OR Event=BlockChangeConfirmed)
| streamstats latest(Block) AS last earliest(Block) AS first
| transaction ScenarioId startswith="(Event=BlockChangeConfirmed)" endswith="(Event=BlockChange)" maxspan=10s
I've tried adding and changing the conditions to:
| search first != last
| search eval(first != last)
| where first != last
endswith=eval(first != last)
without success.
How can I obtain the results I want?
For this particular example, I solved it by searching where the number of block changes was more than 1 using mvcount:
index="foo" sourcetype="bar" Block AND (Event=BlockChange OR Event=BlockChangeConfirmed)
| streamstats earliest(Block) AS first
| transaction ScenarioId startswith="(Event=BlockChangeConfirmed)" endswith="(Event=BlockChange)" maxspan=10s
| eval numberOfBlocks=mvcount(first)
| search numberOfBlocks > 1