fix: re-process events from debouncing

Author: niieani

src/stories/mockComponentsv3/App.tsx

@@ -60,7 +60,7 @@ const ticketOperationTracer = traceManager.createTracer({
 const simulateEventPeriodically = (ticketId: number | null) => {
   const interval = setInterval(() => {
     performance.mark(`ticket-${ticketId}-event`)
-  }, 2_000)
+  }, 4_000)
 
   return () => void clearInterval(interval)
 }
@@ -73,22 +73,6 @@ export const App: React.FC = () => {
     [selectedTicketId],
   )
 
-  observePerformanceWithTraceManager(traceManager, [
-    'element',
-    'event',
-    'first-input',
-    'largest-contentful-paint',
-    'layout-shift',
-    // 'long-animation-frame',
-    'longtask',
-    'mark',
-    'measure',
-    'navigation',
-    'paint',
-    'resource',
-    'visibility-state',
-  ])
-
   const handleTicketClick = (id: number) => {
     // traceManager.startOperation({
     //   operationName: `ticket-activation`,

src/stories/mockComponentsv3/Ticket.tsx

@@ -1,6 +1,6 @@
 /* eslint-disable import/no-extraneous-dependencies */
 import React from 'react'
-import { Cell, Row } from '@zendeskgarden/react-tables'
+import { Table } from '@zendeskgarden/react-tables'
 
 interface TicketProps {
   id: number
@@ -9,12 +9,12 @@ interface TicketProps {
 }
 
 export const Ticket: React.FC<TicketProps> = ({ id, subject, onClick }) => (
-  <Row
+  <Table.Row
     onClick={() => void onClick(id)}
     style={{ cursor: 'pointer' }}
     isStriped={id % 2 === 0}
   >
-    <Cell width={70}>{id}</Cell>
-    <Cell>{subject}</Cell>
-  </Row>
+    <Table.Cell width={70}>{id}</Table.Cell>
+    <Table.Cell>{subject}</Table.Cell>
+  </Table.Row>
 )

src/stories/mockComponentsv3/TicketView.tsx

@@ -10,6 +10,7 @@ import { Paragraph, Span, XXL } from '@zendeskgarden/react-typography'
 import { ReactComponent as UserIcon } from '@zendeskgarden/svg-icons/src/16/user-solo-stroke.svg'
 import { TimingComponent } from '../../v2/element'
 import { mockTickets } from './mockTickets'
+import { triggerLongTasks } from './simulateLongTasks'
 import { useBeacon } from './traceManager'
 
 export const StyledSpan = styled(Span).attrs({ isBold: true, hue: 'blue' })`
@@ -40,6 +41,16 @@ export const TicketView: React.FC<TicketViewProps> = ({
     isIdle: cached,
   })
 
+  useEffect(
+    () =>
+      triggerLongTasks({
+        minTime: 50,
+        maxTime: 100,
+        totalClusterDuration: 300,
+      }),
+    [ticketId, cached],
+  )
+
   const ticket = mockTickets.find((ticket) => ticket.id === ticketId)
 
   useEffect(() => {

src/stories/mockComponentsv3/simulateLongTasks.ts

@@ -0,0 +1,48 @@
+export function triggerLongTasks({
+  minTime,
+  maxTime,
+  totalClusterDuration,
+}: {
+  minTime: number
+  maxTime: number
+  totalClusterDuration: number
+}): () => void {
+  const controller = new AbortController()
+  const startTime = Date.now()
+
+  function randomDuration(min: number, max: number): number {
+    return Math.floor(Math.random() * (max - min + 1)) + min
+  }
+
+  function executeLongTask() {
+    const taskDuration = randomDuration(minTime, maxTime)
+    const endTime = Date.now()
+
+    if (controller.signal.aborted) {
+      console.log('Cluster aborted.')
+      return
+    }
+
+    if (endTime - startTime < totalClusterDuration) {
+      console.log(`Starting long task for ${taskDuration} ms`)
+      const taskEnd = Date.now() + taskDuration
+
+      // Simulating a blocking long task
+      while (Date.now() < taskEnd) {
+        if (controller.signal.aborted) {
+          console.log('Task aborted.')
+          return
+        }
+      }
+
+      executeLongTask() // Trigger the next task
+    } else {
+      console.log('Completed all tasks within the cluster duration.')
+    }
+  }
+
+  executeLongTask()
+
+  // Return a callback that can abort the current cluster
+  return () => void controller.abort()
+}

src/stories/mockComponentsv3/traceManager.tsx

@@ -1,4 +1,5 @@
 import { generateUseBeacon } from '../../v3/hooks'
+import { observePerformanceWithTraceManager } from '../../v3/observePerformanceWithTraceManager'
 import { TraceManager } from '../../v3/traceManager'
 
 export interface TicketIdScope {
@@ -13,4 +14,20 @@ export const traceManager = new TraceManager<TicketIdScope>({
   generateId: () => Math.random().toString(36).slice(2),
 })
 
+observePerformanceWithTraceManager(traceManager, [
+  'element',
+  'event',
+  'first-input',
+  'largest-contentful-paint',
+  'layout-shift',
+  'long-animation-frame',
+  'longtask',
+  'mark',
+  'measure',
+  'navigation',
+  'paint',
+  'resource',
+  'visibility-state',
+])
+
 export const useBeacon = generateUseBeacon(traceManager)

src/v3/ActiveTrace.ts

@@ -116,6 +116,11 @@ export class TraceStateMachine<ScopeT extends ScopeBase> {
   interactiveDeadline: number = Number.POSITIVE_INFINITY
   timeoutDeadline: number = Number.POSITIVE_INFINITY
 
+  // while debouncing, we need to buffer any spans that come in so they can be re-processed
+  // once we transition to the 'waiting-for-interactive' state
+  // otherwise we might miss out on spans that are relevant to calculating the interactive
+  debouncingSpanBuffer: SpanAndAnnotation<ScopeT>[] = []
+
   readonly states = {
     recording: {
       onEnterState: () => {
@@ -158,13 +163,6 @@ export class TraceStateMachine<ScopeT extends ScopeBase> {
           }
         }
 
-        console.log(
-          `# processing span ${spanAndAnnotation.span.name} ${spanAndAnnotation.annotation.occurrence}`,
-          'requiredToEnd',
-          this.context.definition.requiredToEnd,
-          'this span',
-          spanAndAnnotation,
-        )
         for (let i = 0; i < this.context.definition.requiredToEnd.length; i++) {
           if (!this.context.requiredToEndIndexChecklist.has(i)) {
             // we previously checked off this index
@@ -258,6 +256,9 @@ export class TraceStateMachine<ScopeT extends ScopeBase> {
             interruptionReason: 'timeout',
           }
         }
+
+        this.debouncingSpanBuffer.push(spanAndAnnotation)
+
         if (spanEndTimeEpoch > this.debounceDeadline) {
           // done debouncing
           return { transitionToState: 'waiting-for-interactive' }
@@ -361,6 +362,27 @@ export class TraceStateMachine<ScopeT extends ScopeBase> {
           typeof interactiveConfig === 'object' ? interactiveConfig : {},
         )
 
+        // sort the buffer before processing
+        // DECISION TODO: do we want to sort by end time or start time?
+        this.debouncingSpanBuffer.sort(
+          (a, b) =>
+            a.span.startTime.now +
+            a.span.duration -
+            (b.span.startTime.now + b.span.duration),
+        )
+
+        // process any spans that were buffered during the debouncing phase
+        while (this.debouncingSpanBuffer.length > 0) {
+          const span = this.debouncingSpanBuffer.shift()!
+          const transition: OnEnterStatePayload<ScopeT> | undefined = this.emit(
+            'onProcessSpan',
+            span,
+          )
+          if (transition) {
+            return transition
+          }
+        }
+
         return undefined
       },
 
@@ -609,6 +631,15 @@ export class ActiveTrace<ScopeT extends ScopeBase> {
       !existingAnnotation &&
       (!transition || transition.transitionToState !== 'interrupted')
 
+    console.log(
+      `# processed span ${spanAndAnnotation.span.type} ${spanAndAnnotation.span.name} ${spanAndAnnotation.annotation.occurrence}`,
+      spanAndAnnotation,
+      'shouldRecord?',
+      shouldRecord,
+      'transition?',
+      transition,
+    )
+
     // DECISION: if the final state is interrupted, we should not record the entry nor annotate it externally
     if (shouldRecord) {
       this.recordedItems.push(spanAndAnnotation)

src/v3/observePerformanceWithTraceManager.ts

@@ -1,4 +1,5 @@
 import { getSpanFromPerformanceEntry } from './getSpanFromPerformanceEntry'
+import type { NativePerformanceEntryType } from './spanTypes'
 import type { TraceManager } from './traceManager'
 import type { ScopeBase } from './types'
 
@@ -23,7 +24,7 @@ import type { ScopeBase } from './types'
 
 export const observePerformanceWithTraceManager = <ScopeT extends ScopeBase>(
   traceManager: TraceManager<ScopeT>,
-  entryTypes: string[],
+  entryTypes: NativePerformanceEntryType[],
 ) => {
   const observer = new PerformanceObserver((entryList) => {
     entryList.getEntries().forEach((entry) => {