Analysing State from Event Logs in SQL

A task that comes up repeatedly is evaluation of state intervals generated from event logs. If the event log is stored (or can be migrated to) SQL Server, this can be done easily and performantly in SQL.

I generally work with SQL Server but this technique appears to be compatible with most modern SQL implementations.

As an example, a system might have a number of valid states and an event is captured each time the system enters a new state.

What we’re after is a list of intervals showing the time that the system was in each state. This can be done with a query like:

WITH [CTE_SequencedEvents] AS
(
  SELECT
      *
      ,ROW_NUMBER() OVER (ORDER BY [Time]) AS [Sequence]
    FROM [#Events]
)
SELECT
    StartEvent.[Time] AS [Start Time]
    ,EndEvent.[Time] AS [End Time]
    ,DATEDIFF(SECOND, StartEvent.[Time], EndEvent.[Time])/60.0 AS [Duration (Minutes)]
    ,StartEvent.[State]
  FROM [CTE_SequencedEvents] AS StartEvent
  JOIN [CTE_SequencedEvents] AS EndEvent ON EndEvent.[Sequence] = StartEvent.[Sequence] + 1
  ORDER BY StartEvent.[Time]

Here’s what’s happening:

• The ROW_NUMBER() windowing function is used to generate a sequential list of row numbers on the fly.
• A CTE (common table expression) is wrapped around the sequenced rows. This can be referenced multiple times in the query.
• Each row of the CTE is joined back on the next row, creating a contiguous timeline of intervals.

This gives us the required intervals:

Wrap the intervals up in another CTE for readability and the intervals can be used for all sort of analysis, for example a histogram of time in each state:

WITH [CTE_SequencedEvents] AS
(
  SELECT
      *
      ,ROW_NUMBER() OVER (ORDER BY [Time]) AS [Sequence]
    FROM [#Events]
)
,[CTE_Intervals] AS
(
  SELECT
      StartEvent.[Time] AS [StartTime]
      ,EndEvent.[Time] AS [EndTime]
      ,DATEDIFF(SECOND, StartEvent.[Time], EndEvent.[Time])/60.0 AS [DurationMinutes]
      ,StartEvent.[State]
    FROM [CTE_SequencedEvents] AS StartEvent
    JOIN [CTE_SequencedEvents] AS EndEvent ON EndEvent.[Sequence] = StartEvent.[Sequence] + 1
)
SELECT
    [State]
    ,SUM([DurationMinutes]) AS [Total Duration (Minutes)]
  FROM [CTE_Intervals]
  GROUP BY [State]
  ORDER BY [State]

Cleaning Up Duplicate and Repeated Events

Depending on the source of the data, you may have duplicate or repeated events:

Using the previous query results in the duplicate and repeated events carrying through to the intervals.

Depending on your requirements, this may be fine. But say you want to know the minimum duration that the system was in for each state?

WITH [CTE_SequencedEvents] AS
(
  SELECT
      *
      ,ROW_NUMBER() OVER (ORDER BY [Time]) AS [Sequence]
    FROM [#Events]
)
,[CTE_Intervals] AS
(
  SELECT
      StartEvent.[Time] AS [Start Time]
      ,EndEvent.[Time] AS [End Time]
      ,DATEDIFF(SECOND, StartEvent.[Time], EndEvent.[Time])/60.0 AS [DurationMinutes]
      ,StartEvent.[State]
    FROM [CTE_SequencedEvents] AS StartEvent
    JOIN [CTE_SequencedEvents] AS EndEvent ON EndEvent.[Sequence] = StartEvent.[Sequence] + 1
)
SELECT 
    [State]
    ,MIN([DurationMinutes]) AS [Minimum Duration (Minutes)]
  FROM [CTE_Intervals] 
  GROUP BY [State]
  ORDER BY [State];

In this case the results are incorrect for states B and C due to incorrect and repeated events:

Fortunately, this is easily remedied by recursively pipelining the above approach to filter out (debounce) the duplicate and repeated events.

WITH [CTE_SequencedEvents] AS
(
  SELECT
      *
      ,ROW_NUMBER() OVER (ORDER BY [Time]) AS [Sequence]
    FROM [#Events]
)
,[CTE_DebouncedSequencedEvents] AS
(
  SELECT
      StartEvent.[Time]
      ,StartEvent.[State]
      ,ROW_NUMBER() OVER (ORDER BY StartEvent.[Time]) AS [Sequence]
    FROM [CTE_SequencedEvents] AS StartEvent
    LEFT OUTER JOIN [CTE_SequencedEvents] AS EndEvent ON EndEvent.[Sequence] = StartEvent.[Sequence] + 1
    WHERE StartEvent.[State] <> EndEvent.[State] OR EndEvent.[Sequence] IS NULL
)
,[CTE_Intervals] AS
(
  SELECT
      StartEvent.[Time] AS [Start Time]
      ,EndEvent.[Time] AS [End Time]
      ,DATEDIFF(SECOND, StartEvent.[Time], EndEvent.[Time])/60.0 AS [Duration (Minutes)]
      ,StartEvent.[State]
    FROM [CTE_DebouncedSequencedEvents] AS StartEvent
    JOIN [CTE_DebouncedSequencedEvents] AS EndEvent ON EndEvent.[Sequence] = StartEvent.[Sequence] + 1
)
SELECT 
    * 
  FROM [CTE_Intervals]
  ORDER BY [Start Time]

Note that it is necessary to perform a left outer join in the CTE_DebouncedSequenceEvents step to ensure that the last event isn’t lost due to a null comparison in the StartEvent.State <> EndEvent.State condition.

The resulting intervals are now both contiguous and distinct from the previous state.

Truncating the Reporting Window

Often state analysis needs to be performed between a fixed start and end time. It’s unlikely that your events will align with the bounds of the reporting window and we’ll need to employ a few tricks to truncate the intervals so that the total duration of reported intervals is the same as the duration of the reporting window.

Let’s take our original data set and report on intervals between 7:30AM. and 8:30AM.

Note that the highlighted window falls outside the reporting window but remains of relevance, as it is required to determine the state for the interval between 7:05AM and 7:35AM to be truncated by the start of the reporting interval.

This can be achieved by adding a truncating step in our CTE pipeline:

DECLARE @reportStart datetime = '2022-03-24 07:30:00.000';
DECLARE @reportEnd datetime = '2022-03-24 08:30:00.000';
WITH [CTE_SequencedEvents] AS
(
  SELECT
      *
      ,ROW_NUMBER() OVER (ORDER BY [Time]) AS [Sequence]
    FROM [#Events]
)
,[CTE_Intervals] AS
(
  SELECT
      StartEvent.[Time] AS [StartTime]
      ,EndEvent.[Time] AS [EndTime]
      ,StartEvent.[State]
    FROM [CTE_SequencedEvents] AS StartEvent
    JOIN [CTE_SequencedEvents] AS EndEvent ON EndEvent.[Sequence] = StartEvent.[Sequence] + 1
)
,[CTE_TruncatedIntervals] AS
(
  SELECT
      CASE WHEN [StartTime] < @reportStart THEN @reportStart ELSE [StartTime] END AS [StartTime]
      ,CASE WHEN [EndTime] > @reportEnd THEN @reportEnd ELSE [EndTime] END AS [EndTime]
      ,[State]
  FROM [CTE_Intervals]
  WHERE @reportStart < [EndTime] AND @reportEnd > [StartTime]
)
SELECT
    [StartTime] AS [Start Time]
    ,[EndTime] AS [End Time]
    ,DATEDIFF(SECOND, [StartTime], [EndTime])/60.0 AS [Duration (Minutes)]
    ,[State]
  FROM [CTE_TruncatedIntervals]

The condition @reportStart < [EndTime] AND @reportEnd > [StartTime] filters out any intervals that do not overlap with the reporting window. The diagram below may help to see why.

Note also the CASE statements that serve to discard the portion of any interval laying outside the reporting window boundary.

On large datasets this query will not perform well as the filtering overlap condition cannot be calculated without fully loading all events. If the maximum interval size is known, the following modification may be made to the CTE_Events clause to improve performance.

DECLARE @reportStart datetime = '2022-03-24 07:30:00.000';
DECLARE @reportEnd datetime = '2022-03-24 08:30:00.000';
DECLARE @maximumIntervalSizeMinutes int = 60;
WITH [CTE_SequencedEvents] AS
(
  SELECT
      *
      ,ROW_NUMBER() OVER (ORDER BY [Time]) AS [Sequence]
    FROM [#Events]
    WHERE [Time] > DATEADD(MINUTE, -@maximumINtervalSizeMinutes, @reportStart)
    AND [Time] < DATEADD(MINUTE, @maximumIntervalSizeMinutes, @reportEnd)
)
,[CTE_Intervals] AS
(
  SELECT
      StartEvent.[Time] AS [StartTime]
      ,EndEvent.[Time] AS [EndTime]
      ,StartEvent.[State]
    FROM [CTE_SequencedEvents] AS StartEvent
    JOIN [CTE_SequencedEvents] AS EndEvent ON EndEvent.[Sequence] = StartEvent.[Sequence] + 1
)
,[CTE_TruncatedIntervals] AS
(
  SELECT
      CASE WHEN [StartTime] < @reportStart THEN @reportStart ELSE [StartTime] END AS [StartTime]
      ,CASE WHEN [EndTime] > @reportEnd THEN @reportEnd ELSE [EndTime] END AS [EndTime]
      ,[State]
  FROM [CTE_Intervals]
  WHERE @reportStart < [EndTime] AND @reportEnd > [StartTime]
)
SELECT
    [StartTime] AS [Start Time]
    ,[EndTime] AS [End Time]
    ,DATEDIFF(SECOND, [StartTime], [EndTime])/60.0 AS [Duration (Minutes)]
    ,[State]
  FROM [CTE_TruncatedIntervals]