From cafbadd5647020c06d052e9e3d0f6081351e8736 Mon Sep 17 00:00:00 2001 From: Spencer Torres Date: Thu, 22 Oct 2026 12:54:26 -0700 Subject: [PATCH 1/2] feat: browser events in trace waterfall --- .changeset/trace-waterfall-browser-events.md | 5 + .../src/components/DBTraceWaterfallChart.tsx | 83 ++++- .../TimelineChart/TimelineSpanEventMarker.tsx | 1 + .../__tests__/DBTraceWaterfallChart.test.tsx | 286 ++++++++++++++++++ .../hooks/__fixtures__/browserTraceEvents.ts | 90 ++++++ .../__tests__/useBrowserTraceEvents.test.tsx | 262 ++++++++++++++++ .../app/src/hooks/useBrowserTraceEvents.ts | 215 +++++++++++++ packages/app/src/hooks/useRowHighlightHint.ts | 22 +- packages/app/src/hooks/useSessionLogEvents.ts | 2 +- .../__tests__/browserTraceContext.test.ts | 144 +++++++++ .../__tests__/resourceTimingMarkers.test.ts | 278 +++++++++++++++++ .../utils/__tests__/traceTriggerClick.test.ts | 152 ++++++++++ packages/app/src/utils/browserEvents.ts | 1 + packages/app/src/utils/browserTraceContext.ts | 140 +++++++++ packages/app/src/utils/httpSpanAttributes.ts | 2 +- .../app/src/utils/resourceTimingMarkers.ts | 228 ++++++++++++++ packages/app/src/utils/sessionLogEvents.ts | 158 ++++++---- packages/app/src/utils/traceTriggerClick.ts | 103 +++++++ .../app/tests/e2e/features/sessions.spec.ts | 26 +- packages/app/tests/e2e/seed-otel-sessions.ts | 29 +- 20 files changed, 2138 insertions(+), 89 deletions(-) create mode 100644 .changeset/trace-waterfall-browser-events.md create mode 100644 packages/app/src/hooks/__fixtures__/browserTraceEvents.ts create mode 100644 packages/app/src/hooks/__tests__/useBrowserTraceEvents.test.tsx create mode 100644 packages/app/src/hooks/useBrowserTraceEvents.ts create mode 100644 packages/app/src/utils/__tests__/browserTraceContext.test.ts create mode 100644 packages/app/src/utils/__tests__/resourceTimingMarkers.test.ts create mode 100644 packages/app/src/utils/__tests__/traceTriggerClick.test.ts create mode 100644 packages/app/src/utils/browserTraceContext.ts create mode 100644 packages/app/src/utils/resourceTimingMarkers.ts create mode 100644 packages/app/src/utils/traceTriggerClick.ts diff --git a/.changeset/trace-waterfall-browser-events.md b/.changeset/trace-waterfall-browser-events.md new file mode 100644 index 0000000000..26be802d3c --- /dev/null +++ b/.changeset/trace-waterfall-browser-events.md @@ -0,0 +1,5 @@ +--- +'@hyperdx/app': patch +--- + +feat: Trace waterfall shows OpenTelemetry browser SDK request timings as dots on fetch and XHR spans, and the click that triggered a browser trace diff --git a/packages/app/src/components/DBTraceWaterfallChart.tsx b/packages/app/src/components/DBTraceWaterfallChart.tsx index 7811018e2f..ce11723dd1 100644 --- a/packages/app/src/components/DBTraceWaterfallChart.tsx +++ b/packages/app/src/components/DBTraceWaterfallChart.tsx @@ -35,6 +35,7 @@ import { IconChevronsDown, IconChevronsRight, IconLogs, + IconPointer, } from '@tabler/icons-react'; import { ContactSupportText } from '@/components/ContactSupportText'; @@ -51,6 +52,7 @@ import { TRACE_WATERFALL_FETCH_LIMIT, TRACE_WATERFALL_ROW_LIMIT, } from '@/components/traceWaterfallLimits'; +import { useBrowserTraceEvents } from '@/hooks/useBrowserTraceEvents'; import { useColumns } from '@/hooks/useMetadata'; import useOffsetPaginatedQuery from '@/hooks/useOffsetPaginatedQuery'; import { @@ -107,6 +109,7 @@ export type SpanRow = { Attributes: Record; }>; __hdx_hidden?: boolean | 1 | 0; + triggeredBy?: string; }; type TimestampedRow = { @@ -785,7 +788,7 @@ export function DBTraceWaterfallChartContainer({ logColumns?.some(column => column.name === 'SeverityNumber') ?? false; const { - rows: logRowsData, + rows: fetchedLogRows, isFetching: logIsFetching, meta: logRowsMeta, filterError: logFilterError, @@ -816,8 +819,31 @@ export function DBTraceWaterfallChartContainer({ // shown), otherwise the fatal error (no logs could be loaded at all). const logError = logFilterError ?? logFatalError; + const [showSpanEvents, setShowSpanEvents] = useState(true); + const [showSpans, setShowSpans] = useState(true); + const [showLogs, setShowLogs] = useState(true); + + const { + logRows: logRowsData, + resourceTimingBySpanId, + triggerRow, + } = useBrowserTraceEvents({ + traceRows: traceRowsData, + logRows: fetchedLogRows, + logSource: logTableSource, + traceId, + highlightedRowWhere, + initialRowHighlightHint, + // Only while the dots show. A log filter asks for the rows it matches. + foldTimingRows: showSpans && showSpanEvents && !logWhere, + enabled: !traceIsFetching, + }); + const rows: any[] = useMemo(() => { - const nextRows: Array<(typeof traceRowsData)[number] & TimestampedRow> = [ + // The trigger row goes first so a click with the same timestamp as the + // root span sorts before it (the sort is stable). + const nextRows: TimestampedRow[] = [ + ...(triggerRow ? [triggerRow] : []), ...traceRowsData, ...logRowsData, ]; @@ -833,7 +859,7 @@ export function DBTraceWaterfallChartContainer({ }); return nextRows; - }, [traceRowsData, logRowsData]); + }, [triggerRow, traceRowsData, logRowsData]); const validSpanIDs = useMemo(() => { return new Set( @@ -983,9 +1009,6 @@ export function DBTraceWaterfallChartContainer({ }; const [collapsedIds, setCollapsedIds] = useState>(new Set()); - const [showSpanEvents, setShowSpanEvents] = useState(true); - const [showSpans, setShowSpans] = useState(true); - const [showLogs, setShowLogs] = useState(true); const { nodesMap, flattenedNodes, parentIdsByLevel } = useMemo(() => { const rootNodes: Node[] = []; @@ -1128,6 +1151,8 @@ export function DBTraceWaterfallChartContainer({ const visibleNodes = useMemo(() => { if (showSpans && showLogs) return flattenedNodes; return flattenedNodes.filter(node => { + // The click belongs with the spans it started, not with the logs. + if (node.triggeredBy) return showSpans; if (node.type === SourceKind.Log) return showLogs; return showSpans; }); @@ -1137,7 +1162,7 @@ export function DBTraceWaterfallChartContainer({ node => node.type !== SourceKind.Log, ).length; const logCount = visibleNodes.filter( - node => node.type === SourceKind.Log, + node => node.type === SourceKind.Log && !node.triggeredBy, ).length; const errorCount = visibleNodes.filter( node => getRowSeverity(node) === 'error', @@ -1178,6 +1203,7 @@ export function DBTraceWaterfallChartContainer({ id, type, aliasWith, + triggeredBy, } = result; let body = `${_body}`; try { @@ -1193,12 +1219,16 @@ export function DBTraceWaterfallChartContainer({ const httpUrl = isRpcSpan(spanAttributes) ? undefined : getHttpUrl(spanAttributes); - const displayText = httpUrl ? `${body} ${httpUrl}` : body; + const displayText = + triggeredBy ?? (httpUrl ? `${body} ${httpUrl}` : body); + const startedAt = !isNaN(startOffset) + ? ` | Started at ${formatTime(new Date(startOffset), { format: 'withMs' })}` + : ''; // Process span events into markers (only if showSpanEvents is enabled) - const markers = - showSpanEvents && result.SpanEvents - ? result.SpanEvents.map(spanEvent => { + const markers = showSpanEvents + ? [ + ...(result.SpanEvents ?? []).map(spanEvent => { const epochMs = parseTimestampToMs(spanEvent.Timestamp); return { timestamp: epochMs - minOffset, @@ -1206,8 +1236,17 @@ export function DBTraceWaterfallChartContainer({ name: spanEvent.Name, attributes: spanEvent.Attributes || {}, }; - }) - : []; + }), + // Log rows carry their parent span's SpanId. + ...(type !== SourceKind.Log + ? (resourceTimingBySpanId.get(result.SpanId) ?? []) + : [] + ).map(marker => ({ + ...marker, + timestamp: marker.epochMs - minOffset, + })), + ] + : []; const severity = getRowSeverity(result); const isError = severity === 'error'; @@ -1316,7 +1355,13 @@ export function DBTraceWaterfallChartContainer({ )} - {type === SourceKind.Log ? ( + {triggeredBy ? ( + + ) : type === SourceKind.Log ? ( {serviceName && <>{serviceName} } @@ -1347,7 +1395,9 @@ export function DBTraceWaterfallChartContainer({ aliasWith, start, end, - tooltip: `${displayText} ${tookMs >= 0 ? `took ${tookMs.toFixed(4)}ms` : ''} ${status ? `| Status: ${status}` : ''}${!isNaN(startOffset) ? ` | Started at ${formatTime(new Date(startOffset), { format: 'withMs' })}` : ''}`, + tooltip: triggeredBy + ? `${triggeredBy}${startedAt}` + : `${displayText} ${tookMs >= 0 ? `took ${tookMs.toFixed(4)}ms` : ''} ${status ? `| Status: ${status}` : ''}${startedAt}`, color: 'var(--color-text-inverted)', backgroundColor: barColor({ isHighlighted, @@ -1373,6 +1423,7 @@ export function DBTraceWaterfallChartContainer({ highlightedRowWhere, minOffset, onClick, + resourceTimingBySpanId, serviceColorMap, showSpanEvents, toggleCollapse, diff --git a/packages/app/src/components/TimelineChart/TimelineSpanEventMarker.tsx b/packages/app/src/components/TimelineChart/TimelineSpanEventMarker.tsx index ad142ad5be..219e88ecdb 100644 --- a/packages/app/src/components/TimelineChart/TimelineSpanEventMarker.tsx +++ b/packages/app/src/components/TimelineChart/TimelineSpanEventMarker.tsx @@ -81,6 +81,7 @@ export const TimelineSpanEventMarker = memo(function ({ }} >
({ jest.mock('../DBRowDataPanel', () => ({ getJSONColumnNames: jest.fn().mockReturnValue([]), })); +jest.mock('@/hooks/useBrowserTraceEvents', () => ({ + useBrowserTraceEvents: jest.fn(), +})); +const mockUseBrowserTraceEvents = jest.mocked(useBrowserTraceEvents); +const passBrowserTraceEventsThrough: typeof useBrowserTraceEvents = ({ + logRows, +}) => ({ logRows, resourceTimingBySpanId: new Map(), triggerRow: undefined }); // Lightweight stub: the real SearchWhereInput renders SearchInputV2, which // pulls in useMe()/metadata hooks that require a QueryClientProvider not present @@ -215,6 +226,7 @@ describe('DBTraceWaterfallChartContainer', () => { // Reset mocks before each test beforeEach(() => { jest.clearAllMocks(); + mockUseBrowserTraceEvents.mockImplementation(passBrowserTraceEventsThrough); mockUseRowWhere.mockReturnValue(() => ({ where: 'row-id', aliasWith: [] })); MockTimelineChart.latestProps = {}; mockUseWaterfallSearchState.mockReturnValue(makeWaterfallSearchState()); @@ -225,6 +237,9 @@ describe('DBTraceWaterfallChartContainer', () => { const renderComponent = ( logTableSource: typeof mockLogTableSource | null = mockLogTableSource, traceId: string = mockTraceId, + props: Partial< + React.ComponentProps + > = {}, ) => { return renderWithMantine( @@ -234,6 +249,7 @@ describe('DBTraceWaterfallChartContainer', () => { traceId={traceId} dateRange={mockDateRange} focusDate={mockFocusDate} + {...props} /> , ); @@ -789,6 +805,50 @@ describe('DBTraceWaterfallChartContainer', () => { expect(screen.getByText(label)).toBeInTheDocument(); }); + const findRow = (type: string) => + MockTimelineChart.latestProps.rows.find( + (row: { type?: string }) => row.type === type, + ); + + it('builds the tooltip and title of a span with a URL and of a log', async () => { + setupQueryMocks({ + traceData: { + data: [ + { ...mockTraceData.data[0], SpanAttributes: { 'url.full': apiUrl } }, + ], + meta: [{ totalCount: 1 }], + }, + logData: { + data: [{ ...mockLogData.data[0], ServiceName: 'test-service' }], + meta: [{ totalCount: 1 }], + }, + }); + renderComponent(); + await waitForLoading(); + + const spanRow = findRow(SourceKind.Trace); + expect(spanRow.events[0].tooltip).toBe( + `test span ${apiUrl} took 100.0000ms | Started at Jan 1 1:00:00.000 AM`, + ); + const spanLabel = renderWithMantine(spanRow.label); + expect( + spanLabel.getByTitle(`test-service test span ${apiUrl}`), + ).toBeInTheDocument(); + expect( + spanLabel.queryByLabelText('Correlated Log Line'), + ).not.toBeInTheDocument(); + + const logRow = findRow(SourceKind.Log); + expect(logRow.events[0].tooltip).toBe( + 'test log took 0.0000ms | Status: warn | Started at Jan 1 1:00:00.000 AM', + ); + const logLabel = renderWithMantine(logRow.label); + expect(logLabel.getByTitle('test-service')).toHaveTextContent( + 'test-service test log', + ); + expect(logLabel.getByLabelText('Correlated Log Line')).toBeInTheDocument(); + }); + // Main drew icons only for exact lowercase 'error'/'warn' and counted only // SeverityText 'error'. it.each([ @@ -1051,6 +1111,232 @@ describe('DBTraceWaterfallChartContainer', () => { expect(screen.getByTestId('trace-search-input')).toBeInTheDocument(); expect(screen.queryByTestId('log-search-input')).not.toBeInTheDocument(); }); + + describe('browser trace events', () => { + const spanStartMs = Date.parse('2024-01-01T06:00:00.000Z'); + const responseEnd = { + epochMs: spanStartMs + 20, + name: 'responseEnd', + attributes: { duration: '19.2ms' }, + }; + const mockTimingMarkers = () => + mockUseBrowserTraceEvents.mockImplementation(({ logRows }) => ({ + logRows, + resourceTimingBySpanId: new Map([['span-1', [responseEnd]]]), + triggerRow: undefined, + })); + + it('draws span events, then timing dots, on the span and not on its log, and none with span events off', async () => { + mockTimingMarkers(); + setupQueryMocks({ + traceData: { + data: [ + { + ...mockTraceData.data[0], + SpanEvents: [ + { + Timestamp: '2024-01-01T06:00:00.050000000Z', + Name: 'exception', + Attributes: { 'exception.message': 'boom' }, + }, + { + Timestamp: '2024-01-01T06:00:00.075000000Z', + Name: 'cache miss', + Attributes: {}, + }, + ], + }, + ], + meta: [{ totalCount: 1 }], + }, + logData: mockLogData, + }); + renderComponent(); + await waitForLoading(); + + expect(findRow(SourceKind.Trace).events[0].markers).toEqual([ + { + timestamp: 50, + epochMs: spanStartMs + 50, + name: 'exception', + attributes: { 'exception.message': 'boom' }, + }, + { + timestamp: 75, + epochMs: spanStartMs + 75, + name: 'cache miss', + attributes: {}, + }, + { timestamp: 20, ...responseEnd }, + ]); + expect(findRow(SourceKind.Log).events[0].markers).toEqual([]); + + await userEvent.click(screen.getByTestId('show-span-events-chip')); + await waitFor(() => { + expect(findRow(SourceKind.Trace).events[0].markers).toEqual([]); + }); + }); + + it('draws timing dots on a span without span events', async () => { + mockTimingMarkers(); + setupQueryMocks({ traceData: mockTraceData }); + renderComponent(null); + await waitForLoading(); + + expect(findRow(SourceKind.Trace).events[0].markers).toEqual([ + { timestamp: 20, ...responseEnd }, + ]); + }); + + it('renders the log rows the hook keeps', async () => { + mockUseBrowserTraceEvents.mockImplementation(() => ({ + logRows: [], + resourceTimingBySpanId: new Map(), + triggerRow: undefined, + })); + setupQueryMocks({ traceData: mockTraceData, logData: mockLogData }); + renderComponent(); + await waitForLoading(); + + expect(MockTimelineChart.latestProps.rows).toHaveLength(1); + expect(screen.getByText('1 span,')).toBeInTheDocument(); + }); + + it('holds the hook while the trace fetches', () => { + setupQueryMocks({ traceData: mockTraceData, isFetching: true }); + renderComponent(); + + expect(mockUseBrowserTraceEvents).toHaveBeenLastCalledWith( + expect.objectContaining({ enabled: false }), + ); + }); + + it('passes the trace, its log rows, the selection and the hint', async () => { + const hint = { + timestamp: mockLogData.data[0].Timestamp, + spanId: 'span-1', + body: 'test log', + }; + setupQueryMocks({ traceData: mockTraceData, logData: mockLogData }); + renderComponent(mockLogTableSource, mockTraceId, { + highlightedRowWhere: 'selected-row', + initialRowHighlightHint: hint, + }); + await waitForLoading(); + + expect(mockUseBrowserTraceEvents).toHaveBeenLastCalledWith({ + traceRows: [expect.objectContaining({ SpanId: 'span-1' })], + logRows: [expect.objectContaining({ Body: 'test log' })], + logSource: mockLogTableSource, + traceId: mockTraceId, + highlightedRowWhere: 'selected-row', + initialRowHighlightHint: hint, + foldTimingRows: true, + enabled: true, + }); + }); + + const lastFold = () => + mockUseBrowserTraceEvents.mock.lastCall?.[0].foldTimingRows; + + it.each(['show-span-events-chip', 'show-spans-chip'])( + 'keeps the timing rows while %s is off', + async chip => { + setupQueryMocks({ traceData: mockTraceData, logData: mockLogData }); + renderComponent(); + await waitForLoading(); + + await userEvent.click(screen.getByTestId(chip)); + await waitFor(() => expect(lastFold()).toBe(false)); + }, + ); + + it('keeps the timing rows under a log filter', async () => { + mockUseWaterfallSearchState.mockReturnValue({ + ...makeWaterfallSearchState(), + logWhere: 'EventName:"browser.resource_timing"', + }); + setupQueryMocks({ traceData: mockTraceData, logData: mockLogData }); + renderComponent(); + await waitForLoading(); + + expect(lastFold()).toBe(false); + }); + + describe('triggered-by row', () => { + const triggeredBy = 'Triggered by: Clicked testid=checkout · 3ms before'; + const triggerRow: TraceTriggerRow = { + Timestamp: mockTraceData.data[0].Timestamp, + Body: '', + SpanId: '', + type: SourceKind.Log, + id: 'click-row', + aliasWith: [], + __hdx_hidden: false, + triggeredBy, + }; + const mockTriggerRow = () => + mockUseBrowserTraceEvents.mockImplementation(({ logRows }) => ({ + logRows, + resourceTimingBySpanId: new Map(), + triggerRow, + })); + const rowTypes = () => + MockTimelineChart.latestProps.rows.map( + (row: { id: string; type?: string }) => `${row.type}:${row.id}`, + ); + + it('comes first, labeled as the triggering click, and opens the click log', async () => { + mockTriggerRow(); + const onClick = jest.fn(); + setupQueryMocks({ traceData: mockTraceData, logData: mockLogData }); + renderComponent(mockLogTableSource, mockTraceId, { onClick }); + await waitForLoading(); + + expect(rowTypes()).toEqual([ + 'log:click-row', + 'trace:row-id', + 'log:row-id', + ]); + const [row] = MockTimelineChart.latestProps.rows; + expect(row.events[0].tooltip).toBe( + `${triggeredBy} | Started at Jan 1 1:00:00.000 AM`, + ); + const label = renderWithMantine(row.label); + expect(label.getByTitle(triggeredBy)).toHaveTextContent(triggeredBy); + expect(label.getByLabelText('Triggering click')).toBeInTheDocument(); + expect( + label.queryByLabelText('Correlated Log Line'), + ).not.toBeInTheDocument(); + expect(screen.getByText('1 span, 1 log,')).toBeInTheDocument(); + + await userEvent.click(label.getByTitle(triggeredBy)); + expect(onClick).toHaveBeenCalledWith({ + id: 'click-row', + type: SourceKind.Log, + aliasWith: [], + }); + }); + + it('follows the Spans chip, not the Logs chip', async () => { + mockTriggerRow(); + setupQueryMocks({ traceData: mockTraceData, logData: mockLogData }); + renderComponent(); + await waitForLoading(); + + await userEvent.click(screen.getByTestId('show-logs-chip')); + await waitFor(() => { + expect(rowTypes()).toEqual(['log:click-row', 'trace:row-id']); + }); + + await userEvent.click(screen.getByTestId('show-logs-chip')); + await userEvent.click(screen.getByTestId('show-spans-chip')); + await waitFor(() => { + expect(rowTypes()).toEqual(['log:row-id']); + }); + }); + }); + }); }); describe('useEventsAroundFocus', () => { diff --git a/packages/app/src/hooks/__fixtures__/browserTraceEvents.ts b/packages/app/src/hooks/__fixtures__/browserTraceEvents.ts new file mode 100644 index 0000000000..72d88ccd6c --- /dev/null +++ b/packages/app/src/hooks/__fixtures__/browserTraceEvents.ts @@ -0,0 +1,90 @@ +import { SourceKind } from '@hyperdx/common-utils/dist/types'; + +import type { BrowserEventLogSource } from '@/utils/browserTraceContext'; + +export const logSource: BrowserEventLogSource = { + id: 'logs', + kind: SourceKind.Log, + name: 'Logs', + connection: 'conn', + from: { databaseName: 'default', tableName: 'otel_logs' }, + timestampValueExpression: 'Timestamp', + defaultTableSelectExpression: 'Timestamp, Body', + implicitColumnExpression: 'Body', + serviceNameExpression: 'ServiceName', + eventNameExpression: 'EventName', + eventAttributesExpression: 'LogAttributes', + traceIdExpression: 'TraceId', + spanIdExpression: 'SpanId', +}; + +export const PAGE_URL = 'http://localhost:5173/'; +export const SPAN_START = '2026-10-22T04:52:37.818000000Z'; +export const SPAN_START_MS = Date.parse('2026-10-22T04:52:37.818Z'); +export const TIMING_TIMESTAMP = '2026-10-22T04:52:37.838000000Z'; +export const CLICK_TIMESTAMP = '2026-10-22T04:52:37.815000000Z'; + +export const browserSpan = { + Timestamp: SPAN_START, + Duration: 0.012, + SpanId: 'span-1', + ServiceName: 'web', + SpanAttributes: { + 'browser.document.url.full': PAGE_URL, + 'session.id': 's1', + }, +}; +export const legacySpan = { + ...browserSpan, + SpanAttributes: { 'http.url': 'http://localhost:5173/api' }, +}; + +const timingLogRow = { + id: 'timing-row', + Timestamp: TIMING_TIMESTAMP, + SpanId: 'span-1', + Body: '', +}; +export const consoleLogRow = { + id: 'console-row', + Timestamp: '2026-10-22T04:52:37.825000000Z', + SpanId: 'span-1', + Body: 'loading cart', +}; +export const logRows = [timingLogRow, consoleLogRow]; + +export const timingResult = { + data: [ + { + span_id: 'span-1', + timestamp: TIMING_TIMESTAMP, + attributes: { + 'browser.resource_timing.fetch_start': '1000.5', + 'browser.resource_timing.response_end': '1011.5', + }, + }, + ], + meta: [{ name: 'timestamp', type: 'DateTime64(9)' }], +}; + +export const clickResult = { + data: [ + { + timestamp: CLICK_TIMESTAMP, + event_name: 'browser.user_action.click', + session_id: 's1', + body: '', + attributes: { + 'browser.tag_name': 'BUTTON', + 'browser.element.attributes.testid': 'checkout', + }, + }, + ], + meta: [ + { name: 'timestamp', type: 'DateTime64(9)' }, + { name: 'event_name', type: 'String' }, + { name: 'session_id', type: 'String' }, + { name: 'body', type: 'String' }, + { name: 'attributes', type: 'Map(LowCardinality(String), String)' }, + ], +}; diff --git a/packages/app/src/hooks/__tests__/useBrowserTraceEvents.test.tsx b/packages/app/src/hooks/__tests__/useBrowserTraceEvents.test.tsx new file mode 100644 index 0000000000..4f8f25de34 --- /dev/null +++ b/packages/app/src/hooks/__tests__/useBrowserTraceEvents.test.tsx @@ -0,0 +1,262 @@ +import { SourceKind, TLogSource } from '@hyperdx/common-utils/dist/types'; +import { renderHook } from '@testing-library/react'; + +import { + browserSpan, + CLICK_TIMESTAMP, + clickResult, + consoleLogRow, + legacySpan, + logRows, + logSource, + TIMING_TIMESTAMP, + timingResult, +} from '@/hooks/__fixtures__/browserTraceEvents'; +import { useBrowserTraceEvents } from '@/hooks/useBrowserTraceEvents'; + +const mockUseQueriedChartConfig = jest.fn(); +const mockUseFieldExpressionGenerator = jest.fn(); + +jest.mock('@/hooks/useChartConfig', () => ({ + useQueriedChartConfig: (...args: unknown[]) => + mockUseQueriedChartConfig(...args), +})); +jest.mock('@/hooks/useFieldExpressionGenerator', () => ({ + __esModule: true, + default: (source?: TLogSource) => { + mockUseFieldExpressionGenerator(source); + return { + isLoading: false, + getFieldExpression: source + ? (column: string, key: string) => `${column}['${key}']` + : undefined, + }; + }, +})); + +const TIMING = 'TraceResourceTiming'; +const TRIGGER = 'TraceTriggerClick'; + +type Props = Parameters[0]; +type QueryState = { data?: unknown; isError?: boolean }; + +function setup( + props: Partial = {}, + queries: { [TIMING]?: QueryState; [TRIGGER]?: QueryState } = {}, +) { + const states: Record = { + [TIMING]: { data: timingResult, ...queries[TIMING] }, + [TRIGGER]: { data: clickResult, ...queries[TRIGGER] }, + }; + mockUseQueriedChartConfig.mockImplementation( + (_config: unknown, { queryKeyPrefix }: { queryKeyPrefix: string }) => ({ + isError: false, + ...states[queryKeyPrefix], + }), + ); + const initialProps: Props = { + traceRows: [browserSpan], + logRows, + logSource, + traceId: 't1', + foldTimingRows: true, + enabled: true, + ...props, + }; + const hook = renderHook((p: Props) => useBrowserTraceEvents(p), { + initialProps, + }); + return { ...hook, initialProps }; +} + +const lastQuery = (prefix: string) => + mockUseQueriedChartConfig.mock.calls.findLast( + ([, options]) => options.queryKeyPrefix === prefix, + ); +const queriesEnabled = () => ({ + timing: lastQuery(TIMING)?.[1].enabled, + trigger: lastQuery(TRIGGER)?.[1].enabled, +}); + +describe('useBrowserTraceEvents', () => { + beforeEach(() => { + mockUseQueriedChartConfig.mockReset(); + mockUseFieldExpressionGenerator.mockReset(); + }); + + it.each([ + ['legacy SDK spans', { traceRows: [legacySpan] }], + [ + 'a log source without an event name', + { logSource: { ...logSource, eventNameExpression: undefined } }, + ], + ['no log source', { logSource: null }], + ])('sends nothing and returns the rows as given for %s', (_name, props) => { + const { result, rerender, initialProps } = setup(props); + + expect(queriesEnabled()).toEqual({ timing: false, trigger: false }); + expect(mockUseFieldExpressionGenerator).toHaveBeenLastCalledWith(undefined); + expect(result.current.triggerRow).toBeUndefined(); + expect(result.current.logRows).toBe(logRows); + const markers = result.current.resourceTimingBySpanId; + expect(markers.size).toBe(0); + + rerender({ ...initialProps, traceRows: [...initialProps.traceRows] }); + expect(result.current.resourceTimingBySpanId).toBe(markers); + }); + + it('holds both queries while the trace fetches', () => { + setup({ enabled: false }); + + expect(queriesEnabled()).toEqual({ timing: false, trigger: false }); + }); + + it('queries the trace timing logs from the browser spans', () => { + setup(); + + expect(lastQuery(TIMING)).toEqual([ + expect.objectContaining({ + source: 'logs', + where: "TraceId = 't1'", + dateRange: [ + new Date('2026-10-22T04:52:37.000Z'), + new Date('2026-10-22T04:57:37.830Z'), + ], + }), + { enabled: true, queryKeyPrefix: TIMING, staleTime: Infinity }, + ]); + }); + + it("queries the clicks before the first browser span in the span's session", () => { + setup(); + + expect(mockUseFieldExpressionGenerator).toHaveBeenLastCalledWith(logSource); + expect(lastQuery(TRIGGER)).toEqual([ + expect.objectContaining({ + source: 'logs', + dateRange: [ + new Date('2026-10-22T04:52:37.000Z'), + new Date('2026-10-22T04:52:37.818Z'), + ], + filters: expect.arrayContaining([ + { type: 'lucene', condition: 'LogAttributes.session.id:"s1"' }, + ]), + }), + { enabled: true, queryKeyPrefix: TRIGGER, staleTime: Infinity }, + ]); + }); + + it('shows the click as a row with its log row id', () => { + const { result } = setup(); + + expect(result.current.triggerRow).toEqual({ + Timestamp: CLICK_TIMESTAMP, + Body: '', + SpanId: '', + type: SourceKind.Log, + id: `Timestamp=parseDateTime64BestEffort('${CLICK_TIMESTAMP}', 9) AND toString(EventName)='browser.user_action.click' AND LogAttributes['session.id']='s1' AND Body=''`, + aliasWith: [], + __hdx_hidden: false, + triggeredBy: 'Triggered by: Clicked testid=checkout · 3ms before', + }); + }); + + it('hides the click row with the span it anchors on', () => { + const { result } = setup({ + traceRows: [{ ...browserSpan, __hdx_hidden: true }], + }); + + expect(result.current.triggerRow?.__hdx_hidden).toBe(true); + }); + + it('skips the click lookup, metadata included, when the span has no session id', () => { + const { result } = setup({ + traceRows: [ + { + ...browserSpan, + SpanAttributes: { + 'browser.document.url.full': 'http://localhost:5173/', + }, + }, + ], + }); + + expect(mockUseFieldExpressionGenerator).toHaveBeenLastCalledWith(undefined); + expect(queriesEnabled()).toEqual({ timing: true, trigger: false }); + expect(result.current.triggerRow).toBeUndefined(); + }); + + it('shows no click row when the row id cannot be built', () => { + const consoleError = jest + .spyOn(console, 'error') + .mockImplementation(() => {}); + const { result } = setup( + {}, + { + [TRIGGER]: { + data: { ...clickResult, meta: clickResult.meta.slice(0, 1) }, + }, + }, + ); + + expect(result.current.triggerRow).toBeUndefined(); + expect(consoleError).toHaveBeenCalled(); + consoleError.mockRestore(); + }); + + it('draws the timing log as dots and folds its row, keeping another log on the span', () => { + const { result } = setup(); + + expect( + result.current.resourceTimingBySpanId.get('span-1')?.map(m => m.name), + ).toEqual(['fetchStart', 'responseEnd']); + expect(result.current.logRows).toEqual([consoleLogRow]); + }); + + it('keeps the timing row while its dots are off screen', () => { + const { result, rerender, initialProps } = setup({ + foldTimingRows: false, + }); + + expect(result.current.resourceTimingBySpanId.has('span-1')).toBe(true); + expect(result.current.logRows).toBe(logRows); + + rerender({ ...initialProps, foldTimingRows: true }); + expect(result.current.logRows).toEqual([consoleLogRow]); + }); + + it('changes nothing when the queries fail', () => { + const { result } = setup( + {}, + { [TIMING]: { isError: true }, [TRIGGER]: { isError: true } }, + ); + + expect(result.current.logRows).toBe(logRows); + expect(result.current.resourceTimingBySpanId.size).toBe(0); + expect(result.current.triggerRow).toBeUndefined(); + }); + + it('keeps the selected timing row until another row is selected', () => { + const { result, rerender, initialProps } = setup({ + highlightedRowWhere: 'timing-row', + }); + + expect(result.current.logRows).toEqual(logRows); + expect(result.current.resourceTimingBySpanId.has('span-1')).toBe(true); + + rerender({ ...initialProps, highlightedRowWhere: 'console-row' }); + expect(result.current.logRows).toEqual([consoleLogRow]); + }); + + it('keeps the timing row the panel was opened from', () => { + const { result } = setup({ + initialRowHighlightHint: { + timestamp: TIMING_TIMESTAMP, + spanId: 'span-1', + body: '', + }, + }); + + expect(result.current.logRows).toEqual(logRows); + }); +}); diff --git a/packages/app/src/hooks/useBrowserTraceEvents.ts b/packages/app/src/hooks/useBrowserTraceEvents.ts new file mode 100644 index 0000000000..21b29cda80 --- /dev/null +++ b/packages/app/src/hooks/useBrowserTraceEvents.ts @@ -0,0 +1,215 @@ +import { useMemo } from 'react'; +import { SourceKind, TLogSource } from '@hyperdx/common-utils/dist/types'; + +import { useQueriedChartConfig } from '@/hooks/useChartConfig'; +import useFieldExpressionGenerator from '@/hooks/useFieldExpressionGenerator'; +import { + matchesRowHighlightHint, + RowHighlightHint, +} from '@/hooks/useRowHighlightHint'; +import useRowWhere, { WithClause } from '@/hooks/useRowWhere'; +import { PLACEHOLDER_CONFIG } from '@/hooks/useSessionLogEvents'; +import { formatDurationMs } from '@/utils'; +import { getBrowserEventLabel } from '@/utils/browserEvents'; +import { + BrowserTraceRow, + getBrowserTraceContext, + isBrowserEventLogSource, +} from '@/utils/browserTraceContext'; +import { + buildResourceTimingQuery, + getResourceTimingMarkers, + ResourceTimingMarker, + resourceTimingRowKey, +} from '@/utils/resourceTimingMarkers'; +import { SESSION_LOG_EVENT_KEY_COLUMNS } from '@/utils/sessionLogEvents'; +import { + buildTriggerClickQuery, + pickTriggerClick, +} from '@/utils/traceTriggerClick'; + +type TraceRow = BrowserTraceRow & { SpanId?: unknown }; + +type LogRow = { + id: string; + Timestamp: string; + SpanId?: unknown; + Body?: unknown; +}; + +/** The click that triggered the trace, as a waterfall log row. */ +export type TraceTriggerRow = { + Timestamp: string; + Body: string; + SpanId: string; + type: SourceKind.Log; + id: string; + aliasWith: WithClause[]; + __hdx_hidden: boolean; + triggeredBy: string; +}; + +// Stable, so the waterfall's row memos don't rerun while there is nothing. +const NO_RESOURCE_TIMING: ReturnType = { + markersBySpanId: new Map(), + drawnRowKeys: new Set(), +}; + +/** + * Traces without an OTel browser span send no queries. The queries never hold + * the waterfall, and a failed one changes nothing. + */ +export function useBrowserTraceEvents({ + traceRows, + logRows, + logSource, + traceId, + highlightedRowWhere, + initialRowHighlightHint, + foldTimingRows, + enabled, +}: { + traceRows: readonly TraceRow[]; + logRows: T[]; + logSource: TLogSource | null; + traceId: string; + highlightedRowWhere?: string | null; + initialRowHighlightHint?: RowHighlightHint; + /** Whether the dots are on screen to replace the rows. */ + foldTimingRows: boolean; + /** False while the trace rows fetch, so the anchor can't move mid-flight. */ + enabled: boolean; +}): { + logRows: T[]; + resourceTimingBySpanId: ReadonlyMap; + triggerRow: TraceTriggerRow | undefined; +} { + const context = useMemo(() => getBrowserTraceContext(traceRows), [traceRows]); + const source = + context != null && isBrowserEventLogSource(logSource) + ? logSource + : undefined; + + const timingQuery = useMemo( + () => + source != null && context != null + ? buildResourceTimingQuery({ logSource: source, context, traceId }) + : null, + [source, context, traceId], + ); + // Never stale, like the waterfall's own queries: another window is another + // key. Otherwise each trace refetch would rerun both. + const timing = useQueriedChartConfig(timingQuery ?? PLACEHOLDER_CONFIG, { + enabled: enabled && timingQuery != null, + queryKeyPrefix: 'TraceResourceTiming', + staleTime: Infinity, + }); + const timingResult = + timingQuery != null && !timing.isError ? timing.data : undefined; + const { markersBySpanId, drawnRowKeys } = useMemo( + () => + timingResult?.data.length + ? getResourceTimingMarkers(timingResult, traceRows) + : NO_RESOURCE_TIMING, + [timingResult, traceRows], + ); + + // The selected row and the row the panel opened from stay: folding them + // would leave the detail panel showing a row the waterfall lacks, and the + // hint would find nothing to select. + const keptLogRows = useMemo(() => { + if (!foldTimingRows || drawnRowKeys.size === 0) { + return logRows; + } + return logRows.filter( + row => + !drawnRowKeys.has(resourceTimingRowKey(row.SpanId, row.Timestamp)) || + row.id === highlightedRowWhere || + matchesRowHighlightHint(row, initialRowHighlightHint), + ); + }, [ + logRows, + foldTimingRows, + drawnRowKeys, + highlightedRowWhere, + initialRowHighlightHint, + ]); + + // Only the trigger query reads a single attribute, so only it needs the + // JSON column lookup. + const triggerSource = context?.sessionId != null ? source : undefined; + const { getFieldExpression } = useFieldExpressionGenerator(triggerSource); + // A string, not the generator: the generator is a new function each render. + const sessionIdExpression = + triggerSource && + getFieldExpression?.(triggerSource.eventAttributesExpression, 'session.id'); + const triggerQuery = useMemo( + () => + triggerSource != null && context?.sessionId != null && sessionIdExpression + ? buildTriggerClickQuery({ + logSource: triggerSource, + context, + sessionId: context.sessionId, + sessionIdExpression, + }) + : null, + [triggerSource, context, sessionIdExpression], + ); + const trigger = useQueriedChartConfig( + triggerQuery?.config ?? PLACEHOLDER_CONFIG, + { + enabled: enabled && triggerQuery != null, + queryKeyPrefix: 'TraceTriggerClick', + staleTime: Infinity, + }, + ); + const triggerResult = + triggerQuery != null && !trigger.isError ? trigger.data : undefined; + const getRowWhere = useRowWhere({ + meta: triggerResult?.meta, + aliasMap: triggerQuery?.aliasMap, + primaryKeyColumns: SESSION_LOG_EVENT_KEY_COLUMNS, + }); + const anchorMs = context?.anchorMs; + const anchorHidden = context?.anchorHidden ?? false; + const triggerRow = useMemo((): TraceTriggerRow | undefined => { + const picked = + anchorMs != null && triggerResult?.data.length + ? pickTriggerClick(triggerResult, anchorMs) + : undefined; + if (picked == null) { + return undefined; + } + // useRowWhere throws on a column without meta, which must not take down + // the waterfall. + let id: string; + try { + id = getRowWhere(picked.row).where; + } catch (e) { + console.error(e); + return undefined; + } + const { timelineText } = getBrowserEventLabel({ + eventName: String(picked.row.event_name ?? ''), + body: picked.row.body, + attributes: picked.row.attributes, + }); + return { + Timestamp: String(picked.row.timestamp), + Body: '', + SpanId: '', + type: SourceKind.Log, + id, + // The row id is made of raw expressions, so it needs no WITH clauses. + aliasWith: [], + __hdx_hidden: anchorHidden, + triggeredBy: `Triggered by: ${timelineText} · ${formatDurationMs(picked.gapMs)} before`, + }; + }, [triggerResult, anchorMs, anchorHidden, getRowWhere]); + + return { + logRows: keptLogRows, + resourceTimingBySpanId: markersBySpanId, + triggerRow, + }; +} diff --git a/packages/app/src/hooks/useRowHighlightHint.ts b/packages/app/src/hooks/useRowHighlightHint.ts index 3a10311636..b54e7bcc12 100644 --- a/packages/app/src/hooks/useRowHighlightHint.ts +++ b/packages/app/src/hooks/useRowHighlightHint.ts @@ -8,6 +8,18 @@ export type RowHighlightHint = { body: string; }; +export function matchesRowHighlightHint( + row: { Timestamp?: unknown; SpanId?: unknown; Body?: unknown }, + hint: RowHighlightHint | undefined, +): boolean { + return ( + hint != null && + row.Timestamp === hint.timestamp && + row.SpanId === hint.spanId && + row.Body === hint.body + ); +} + type HighlightRow = { id: string; type?: string; @@ -63,13 +75,9 @@ export function useRowHighlightHint({ return; } - const initialRowHighlightIndex = rows.findIndex(row => { - return ( - row.Timestamp === initialRowHighlightHint.timestamp && - row.SpanId === initialRowHighlightHint.spanId && - row.Body === initialRowHighlightHint.body - ); - }); + const initialRowHighlightIndex = rows.findIndex(row => + matchesRowHighlightHint(row, initialRowHighlightHint), + ); if (initialRowHighlightIndex !== -1) { appliedHighlightHintRef.current = hintKey; diff --git a/packages/app/src/hooks/useSessionLogEvents.ts b/packages/app/src/hooks/useSessionLogEvents.ts index 7247e2f610..6869fc787f 100644 --- a/packages/app/src/hooks/useSessionLogEvents.ts +++ b/packages/app/src/hooks/useSessionLogEvents.ts @@ -29,7 +29,7 @@ const NO_LOG_EVENTS: SessionLogEvent[] = []; // Twin of linkedSpans' usePlaceholderConfig, without a source because the log // source may not resolve. Never fetched: the query is disabled while it is used. -const PLACEHOLDER_CONFIG: BuilderChartConfigWithDateRange = { +export const PLACEHOLDER_CONFIG: BuilderChartConfigWithDateRange = { connection: '', from: { databaseName: '', tableName: '' }, select: [{ valueExpression: '1' }], diff --git a/packages/app/src/utils/__tests__/browserTraceContext.test.ts b/packages/app/src/utils/__tests__/browserTraceContext.test.ts new file mode 100644 index 0000000000..4a4608ab0c --- /dev/null +++ b/packages/app/src/utils/__tests__/browserTraceContext.test.ts @@ -0,0 +1,144 @@ +import { + browserSpan, + logSource, + PAGE_URL, + SPAN_START_MS, +} from '@/hooks/__fixtures__/browserTraceEvents'; +import { + getBrowserTraceContext, + hasSubSecondTimestamps, + isBrowserEventLogSource, +} from '@/utils/browserTraceContext'; + +const backendSpan = { + Timestamp: '2026-10-22T04:52:37.000000000Z', + Duration: 5, + ServiceName: 'api', + SpanAttributes: { 'http.route': '/api/checkout' }, +}; + +describe('getBrowserTraceContext', () => { + it.each([ + ['no rows', []], + ['backend spans', [backendSpan]], + [ + 'an AI span with a session id and no page URL', + [{ ...backendSpan, SpanAttributes: { 'session.id': 's1' } }], + ], + [ + 'an empty page URL', + [ + { + ...browserSpan, + SpanAttributes: { 'browser.document.url.full': '' }, + }, + ], + ], + [ + 'an unparsable timestamp', + [{ ...browserSpan, Timestamp: 'not-a-timestamp' }], + ], + ])('is undefined for %s', (_name, rows) => { + expect(getBrowserTraceContext(rows)).toBeUndefined(); + }); + + it('anchors on the earliest browser span, ignoring earlier backend spans', () => { + const laterSpan = { + ...browserSpan, + Timestamp: '2026-10-22T04:52:37.900000000Z', + Duration: 0.2, + ServiceName: 'web-worker', + SpanAttributes: { + 'browser.document.url.full': PAGE_URL, + 'session.id': 's2', + }, + }; + expect( + getBrowserTraceContext([laterSpan, backendSpan, browserSpan]), + ).toEqual({ + serviceNames: ['web', 'web-worker'], + anchorMs: SPAN_START_MS, + endMs: Date.parse('2026-10-22T04:52:38.100Z'), + anchorHidden: false, + sessionId: 's1', + serviceName: 'web', + }); + }); + + it('ends at most an hour after the anchor', () => { + expect( + getBrowserTraceContext([{ ...browserSpan, Duration: 86400 }])?.endMs, + ).toBe(SPAN_START_MS + 60 * 60 * 1000); + }); + + it('reads nested JSON attributes', () => { + const context = getBrowserTraceContext([ + { + ...browserSpan, + SpanAttributes: { + browser: { document: { url: { full: PAGE_URL } } }, + session: { id: 's1' }, + }, + }, + ]); + expect(context).toMatchObject({ + anchorMs: SPAN_START_MS, + sessionId: 's1', + }); + }); + + it('dedupes service names and keeps an unset session id unset', () => { + const context = getBrowserTraceContext([ + { + ...browserSpan, + SpanAttributes: { 'browser.document.url.full': PAGE_URL }, + }, + { ...browserSpan, Timestamp: '2026-10-22T04:52:37.830000000Z' }, + ]); + expect(context).toMatchObject({ + serviceNames: ['web'], + sessionId: undefined, + serviceName: 'web', + }); + }); + + it.each([ + [1, true], + [0, false], + ])('reports a hidden anchor for __hdx_hidden %p', (hidden, expected) => { + expect( + getBrowserTraceContext([{ ...browserSpan, __hdx_hidden: hidden }]) + ?.anchorHidden, + ).toBe(expected); + }); +}); + +describe('hasSubSecondTimestamps', () => { + it.each([ + ["Nullable(DateTime64(9, 'UTC'))", true], + ['DateTime64(0)', false], + ['DateTime', false], + ])('reads a %s timestamp column as %p', (type, expected) => { + expect(hasSubSecondTimestamps([{ name: 'timestamp', type }])).toBe( + expected, + ); + }); + + it('is false without a timestamp column', () => { + expect(hasSubSecondTimestamps(undefined)).toBe(false); + expect( + hasSubSecondTimestamps([{ name: 'ts', type: 'DateTime64(9)' }]), + ).toBe(false); + }); +}); + +describe('isBrowserEventLogSource', () => { + it.each([ + 'eventNameExpression', + 'eventAttributesExpression', + 'traceIdExpression', + 'spanIdExpression', + ] as const)('rejects a source without %s', field => { + expect(isBrowserEventLogSource({ ...logSource, [field]: '' })).toBe(false); + }); +}); diff --git a/packages/app/src/utils/__tests__/resourceTimingMarkers.test.ts b/packages/app/src/utils/__tests__/resourceTimingMarkers.test.ts new file mode 100644 index 0000000000..3d2085bc75 --- /dev/null +++ b/packages/app/src/utils/__tests__/resourceTimingMarkers.test.ts @@ -0,0 +1,278 @@ +import { + logSource, + SPAN_START, + SPAN_START_MS, + TIMING_TIMESTAMP, +} from '@/hooks/__fixtures__/browserTraceEvents'; +import { + buildResourceTimingQuery, + getResourceTimingMarkers, + resourceTimingRowKey, +} from '@/utils/resourceTimingMarkers'; + +const traceRows = [{ SpanId: 'span-1', Timestamp: SPAN_START }]; +const TIMESTAMP_META = [{ name: 'timestamp', type: 'DateTime64(9)' }]; + +const prefixed = (values: Record) => + Object.fromEntries( + Object.entries(values).map(([key, value]) => [ + `browser.resource_timing.${key}`, + value, + ]), + ); + +const sameOrigin = prefixed({ + fetch_start: '1000.5', + domain_lookup_start: '1001', + domain_lookup_end: '1001.25', + connect_start: '1001.5', + secure_connection_start: '0', + connect_end: '1002', + request_start: '1002', + response_start: '1009', + response_end: '1011.5', + redirect_start: '0', + duration: '11', + transfer_size: '558', + encoded_body_size: '1536', + decoded_body_size: '20480', + next_hop_protocol: 'http/1.1', + initiator_type: 'fetch', +}); + +const timingRow = (attributes: unknown, overrides: object = {}) => ({ + span_id: 'span-1', + timestamp: TIMING_TIMESTAMP, + attributes, + ...overrides, +}); + +const draw = ( + row: Record, + spans: Parameters[1] = traceRows, + meta = TIMESTAMP_META, +) => getResourceTimingMarkers({ data: [row], meta }, spans); + +describe('getResourceTimingMarkers', () => { + it('places dots in sdk-trace-web order relative to the span start', () => { + const { markersBySpanId, drawnRowKeys } = draw(timingRow(sameOrigin)); + + expect(markersBySpanId.get('span-1')).toEqual([ + { name: 'fetchStart', epochMs: SPAN_START_MS, attributes: {} }, + { + name: 'domainLookupStart', + epochMs: SPAN_START_MS + 0.5, + attributes: {}, + }, + { + name: 'domainLookupEnd', + epochMs: SPAN_START_MS + 0.75, + attributes: {}, + }, + { name: 'connectStart', epochMs: SPAN_START_MS + 1, attributes: {} }, + { name: 'connectEnd', epochMs: SPAN_START_MS + 1.5, attributes: {} }, + { name: 'requestStart', epochMs: SPAN_START_MS + 1.5, attributes: {} }, + { name: 'responseStart', epochMs: SPAN_START_MS + 8.5, attributes: {} }, + { + name: 'responseEnd', + epochMs: SPAN_START_MS + 11, + attributes: { + duration: '11ms', + transfer_size: '558 B', + encoded_body_size: '1.5 KB', + decoded_body_size: '20.0 KB', + next_hop_protocol: 'http/1.1', + }, + }, + ]); + expect([...drawnRowKeys]).toEqual([ + resourceTimingRowKey('span-1', TIMING_TIMESTAMP), + ]); + }); + + it('skips the phases and sizes a cross-origin request leaves at zero, and empty tooltip values', () => { + const crossOrigin = prefixed({ + fetch_start: '1000.5', + domain_lookup_start: '0', + connect_start: '0', + request_start: '0', + response_start: '0', + response_end: '1011.5', + duration: '11', + transfer_size: '0', + encoded_body_size: '0', + decoded_body_size: '0', + next_hop_protocol: '', + }); + + expect(draw(timingRow(crossOrigin)).markersBySpanId.get('span-1')).toEqual([ + { name: 'fetchStart', epochMs: SPAN_START_MS, attributes: {} }, + { + name: 'responseEnd', + epochMs: SPAN_START_MS + 11, + attributes: { duration: '11ms' }, + }, + ]); + }); + + it('keeps a zero transfer size next to a body size, as for a cache hit', () => { + const cached = prefixed({ + fetch_start: '1000.5', + response_end: '1011.5', + transfer_size: '0', + encoded_body_size: '221', + decoded_body_size: '221', + }); + + expect( + draw(timingRow(cached)).markersBySpanId.get('span-1')?.at(-1)?.attributes, + ).toEqual({ + transfer_size: '0 B', + encoded_body_size: '221 B', + decoded_body_size: '221 B', + }); + }); + + it('reads nested JSON numbers and quoted Int64 values', () => { + const json = { + browser: { + resource_timing: { + fetch_start: 1000.5, + response_end: 1011.5, + transfer_size: '558', + }, + }, + }; + + expect(draw(timingRow(json)).markersBySpanId.get('span-1')).toEqual([ + { name: 'fetchStart', epochMs: SPAN_START_MS, attributes: {} }, + { + name: 'responseEnd', + epochMs: SPAN_START_MS + 11, + attributes: { transfer_size: '558 B' }, + }, + ]); + }); + + it.each([ + ['without fetch_start', timingRow(prefixed({ response_end: '1011.5' }))], + ['with a zero fetch_start', timingRow(prefixed({ fetch_start: '0' }))], + [ + 'on a span outside the trace', + timingRow(sameOrigin, { span_id: 'other' }), + ], + ['without a span id', timingRow(sameOrigin, { span_id: '' })], + ['with attributes that are not a map', timingRow('not a map')], + ])('draws nothing and keeps the row for a log %s', (_name, row) => { + const { markersBySpanId, drawnRowKeys } = draw(row); + expect(markersBySpanId.size).toBe(0); + expect(drawnRowKeys.size).toBe(0); + }); + + it.each([ + [ + 'its span is hidden', + [{ ...traceRows[0], __hdx_hidden: true }], + TIMESTAMP_META, + ], + [ + 'the timestamp column is whole seconds', + traceRows, + [{ name: 'timestamp', type: 'DateTime' }], + ], + ])('draws a log but keeps its row when %s', (_name, spans, meta) => { + const { markersBySpanId, drawnRowKeys } = draw( + timingRow(sameOrigin), + spans, + meta, + ); + expect(markersBySpanId.get('span-1')).toHaveLength(8); + expect(drawnRowKeys.size).toBe(0); + }); +}); + +describe('buildResourceTimingQuery', () => { + const source = { + ...logSource, + timestampValueExpression: 'TimestampTime', + displayedTimestampValueExpression: 'Timestamp', + }; + const context = { + serviceNames: ['web', 'web-worker'], + anchorMs: SPAN_START_MS, + endMs: Date.parse('2026-10-22T04:52:38.100Z'), + anchorHidden: false, + sessionId: 's1', + serviceName: 'web', + }; + + it('selects the span id, displayed timestamp and attributes of the trace timing logs', () => { + expect( + buildResourceTimingQuery({ logSource: source, context, traceId: "t'1" }), + ).toEqual({ + source: 'logs', + connection: 'conn', + from: { databaseName: 'default', tableName: 'otel_logs' }, + timestampValueExpression: 'TimestampTime', + select: [ + { valueExpression: 'SpanId', alias: 'span_id' }, + { valueExpression: 'Timestamp', alias: 'timestamp' }, + { valueExpression: 'LogAttributes', alias: 'attributes' }, + ], + where: "TraceId = 't\\'1'", + whereLanguage: 'sql', + filters: [ + { + type: 'sql', + condition: "toString(EventName) = 'browser.resource_timing'", + }, + { + type: 'sql', + condition: "toString(ServiceName) IN ('web', 'web-worker')", + }, + ], + dateRange: [ + new Date('2026-10-22T04:52:37.000Z'), + new Date('2026-10-22T04:57:38.100Z'), + ], + limit: { limit: 1000 }, + }); + }); + + it('places a JSON path service name inside toString', () => { + const query = buildResourceTimingQuery({ + logSource: { + ...source, + serviceNameExpression: 'ResourceAttributes.service.name', + }, + context, + traceId: 't1', + }); + expect(query.filters?.[1]).toEqual({ + type: 'sql', + condition: + "toString(ResourceAttributes.service.name) IN ('web', 'web-worker')", + }); + }); + + it.each([ + [ + 'the source has no service name', + { ...source, serviceNameExpression: undefined }, + context, + ], + [ + 'the spans have no service name', + source, + { ...context, serviceNames: [] }, + ], + ])('leaves out the service filter when %s', (_name, querySource, ctx) => { + expect( + buildResourceTimingQuery({ + logSource: querySource, + context: ctx, + traceId: 't1', + }).filters, + ).toHaveLength(1); + }); +}); diff --git a/packages/app/src/utils/__tests__/traceTriggerClick.test.ts b/packages/app/src/utils/__tests__/traceTriggerClick.test.ts new file mode 100644 index 0000000000..b05eb0347e --- /dev/null +++ b/packages/app/src/utils/__tests__/traceTriggerClick.test.ts @@ -0,0 +1,152 @@ +import { + logSource, + SPAN_START, + SPAN_START_MS, +} from '@/hooks/__fixtures__/browserTraceEvents'; +import type { BrowserTraceContext } from '@/utils/browserTraceContext'; +import { + buildTriggerClickQuery, + pickTriggerClick, +} from '@/utils/traceTriggerClick'; + +const context: BrowserTraceContext = { + serviceNames: ['web'], + anchorMs: SPAN_START_MS, + endMs: SPAN_START_MS + 12, + anchorHidden: false, + sessionId: 's1', + serviceName: 'web', +}; + +const args = { + logSource: { + ...logSource, + timestampValueExpression: 'TimestampTime, Timestamp', + displayedTimestampValueExpression: 'Timestamp', + }, + context, + sessionId: 's1', + sessionIdExpression: "LogAttributes['session.id']", +}; + +const click = (timestamp: string, attributes: object = {}) => ({ + timestamp, + event_name: 'browser.user_action.click', + body: '', + attributes: { 'browser.tag_name': 'BUTTON', ...attributes }, +}); + +const clicks = (...data: ReturnType[]) => ({ + data, + meta: [{ name: 'timestamp', type: 'DateTime64(9)' }], +}); + +describe('buildTriggerClickQuery', () => { + it("looks up the latest clicks of the anchor span's session and service", () => { + const { config, aliasMap } = buildTriggerClickQuery(args); + + expect(aliasMap).toEqual({ + timestamp: 'Timestamp', + timestamp_key: 'TimestampTime', + event_name: 'toString(EventName)', + session_id: "LogAttributes['session.id']", + body: 'Body', + attributes: 'LogAttributes', + }); + expect(config).toMatchObject({ + source: 'logs', + from: logSource.from, + connection: 'conn', + timestampValueExpression: 'TimestampTime, Timestamp', + filters: [ + { type: 'lucene', condition: 'LogAttributes.session.id:"s1"' }, + { + type: 'sql', + condition: "toString(EventName) = 'browser.user_action.click'", + }, + { type: 'sql', condition: "ServiceName = 'web'" }, + ], + orderBy: 'Timestamp DESC', + limit: { limit: 10 }, + }); + }); + + it.each([ + [ + 'the lookback across a second boundary', + Date.parse('2026-10-22T04:52:38.100Z'), + ['2026-10-22T04:52:37.000Z', '2026-10-22T04:52:38.100Z'], + ], + [ + 'an anchor on a whole second', + Date.parse('2026-10-22T04:52:38.000Z'), + ['2026-10-22T04:52:37.000Z', '2026-10-22T04:52:38.000Z'], + ], + ])( + 'floors the window start to the second and ends at the anchor for %s', + (_case, anchorMs, range) => { + expect( + buildTriggerClickQuery({ ...args, context: { ...context, anchorMs } }) + .config.dateRange, + ).toEqual(range.map(iso => new Date(iso))); + }, + ); +}); + +describe('pickTriggerClick', () => { + it('picks the latest click at or before the anchor', () => { + const latest = click('2026-10-22T04:52:37.815000000Z'); + const rows = clicks( + click('2026-10-22T04:52:37.819000000Z'), + latest, + click('2026-10-22T04:52:37.700000000Z'), + ); + + expect(pickTriggerClick(rows, SPAN_START_MS)).toEqual({ + row: latest, + gapMs: 3, + }); + }); + + it.each([ + ['in the same millisecond as the anchor', SPAN_START, 0], + ['at the edge of the lookback', '2026-10-22T04:52:37.568000000Z', 250], + ])('takes a click %s', (_case, timestamp, gapMs) => { + const row = click(timestamp); + + expect(pickTriggerClick(clicks(row), SPAN_START_MS)).toEqual({ + row, + gapMs, + }); + }); + + it.each([ + ['after the anchor in the same second', '2026-10-22T04:52:37.900000000Z'], + ['older than the lookback', '2026-10-22T04:52:37.567000000Z'], + ['with an unparsable timestamp', 'not-a-timestamp'], + ])('ignores a click %s', (_case, timestamp) => { + expect( + pickTriggerClick(clicks(click(timestamp)), SPAN_START_MS), + ).toBeUndefined(); + }); + + it('ignores clicks in a whole-second timestamp column', () => { + expect( + pickTriggerClick( + { + data: [click('2026-10-22T04:52:37Z')], + meta: [{ name: 'timestamp', type: 'DateTime' }], + }, + Date.parse('2026-10-22T04:52:37.100Z'), + ), + ).toBeUndefined(); + }); + + it('matches a click recorded on another page URL', () => { + const row = click('2026-10-22T04:52:37.816000000Z', { + 'browser.document.url.full': 'http://localhost:5173/cart?tab=items', + }); + + expect(pickTriggerClick(clicks(row), SPAN_START_MS)?.row).toBe(row); + }); +}); diff --git a/packages/app/src/utils/browserEvents.ts b/packages/app/src/utils/browserEvents.ts index f60e6a6d27..6591d35d13 100644 --- a/packages/app/src/utils/browserEvents.ts +++ b/packages/app/src/utils/browserEvents.ts @@ -16,6 +16,7 @@ export const BROWSER_EVENT_NAMES = { NAVIGATION: 'browser.navigation', CONSOLE: 'browser.console', EXCEPTION: 'exception', + RESOURCE_TIMING: 'browser.resource_timing', } as const; export const CONSOLE_METHOD_ATTRIBUTE = 'browser.console.method'; diff --git a/packages/app/src/utils/browserTraceContext.ts b/packages/app/src/utils/browserTraceContext.ts new file mode 100644 index 0000000000..40c8cb2aba --- /dev/null +++ b/packages/app/src/utils/browserTraceContext.ts @@ -0,0 +1,140 @@ +import { get } from 'lodash'; +import type { ResponseJSON } from '@hyperdx/common-utils/dist/clickhouse'; +import { classifyTimestampType } from '@hyperdx/common-utils/dist/core/utils'; +import type { TLogSource } from '@hyperdx/common-utils/dist/types'; + +import { parseTimestampToMs } from '@/utils'; +import { + isSessionLogEventSource, + SessionLogEventSource, +} from '@/utils/sessionLogEvents'; +import { isSet } from '@/utils/spanAttributeReaders'; + +// The waterfall reads an hour either side of its focus. One long or broken +// span would otherwise stretch the timing query over its whole duration. +const MAX_TRACE_MS = 60 * 60 * 1000; + +export type BrowserTraceContext = { + serviceNames: string[]; + /** Earliest browser span start. */ + anchorMs: number; + /** Latest browser span end, at most an hour after the anchor. */ + endMs: number; + /** Whether the trace filter hid the anchor span. */ + anchorHidden: boolean; + /** Of the anchor span. */ + sessionId: string | undefined; + /** Of the anchor span. */ + serviceName: string | undefined; +}; + +export type BrowserTraceRow = { + Timestamp?: unknown; + Duration?: unknown; + ServiceName?: unknown; + SpanAttributes?: unknown; + __hdx_hidden?: unknown; +}; + +export type BrowserEventLogSource = SessionLogEventSource & + Required>; + +export function isBrowserEventLogSource( + source: TLogSource | null | undefined, +): source is BrowserEventLogSource { + return ( + isSessionLogEventSource(source) && + !!source.traceIdExpression && + !!source.spanIdExpression + ); +} + +/** + * Twin of the guard in the waterfall's traceExtent: timestamp-nano reads a + * non-date as a finite instant. + */ +export function parseRowTimeMs(timestamp: unknown): number | undefined { + if (typeof timestamp !== 'string' || Number.isNaN(Date.parse(timestamp))) { + return undefined; + } + try { + const ms = parseTimestampToMs(timestamp); + return Number.isFinite(ms) ? ms : undefined; + } catch { + return undefined; + } +} + +export type BrowserEventResult = Pick< + ResponseJSON>, + 'data' | 'meta' +>; + +export function hasSubSecondTimestamps( + meta: BrowserEventResult['meta'], +): boolean { + const type = meta?.find(column => column.name === 'timestamp')?.type; + return (classifyTimestampType(type)?.precision ?? 0) > 0; +} + +/** + * The start is floored to the second: a DateTime time column compares its + * truncated value and would otherwise lose the start's second. The end is + * inclusive, so a truncated value is never past it. + */ +export function getBrowserEventDateRange( + startMs: number, + endMs: number, +): [Date, Date] { + return [new Date(Math.floor(startMs / 1000) * 1000), new Date(endMs)]; +} + +function optionalString(value: unknown): string | undefined { + return isSet(value) ? String(value) : undefined; +} + +/** + * Undefined unless the trace has a span from an OTel browser SDK, which sets + * the page URL on every span. AI and backend spans can carry `session.id` + * too, and legacy SDK spans have neither. Never anchored on the trace's + * earliest span overall: backend spans run on another clock. + */ +export function getBrowserTraceContext( + traceRows: readonly BrowserTraceRow[], +): BrowserTraceContext | undefined { + let anchor: { row: BrowserTraceRow; startMs: number } | undefined; + let endMs = Number.NEGATIVE_INFINITY; + const serviceNames = new Set(); + for (const row of traceRows) { + if (!isSet(get(row.SpanAttributes, 'browser.document.url.full'))) { + continue; + } + const startMs = parseRowTimeMs(row.Timestamp); + if (startMs == null) { + continue; + } + const durationSec = Number(row.Duration); + endMs = Math.max( + endMs, + startMs + (Number.isFinite(durationSec) ? durationSec : 0) * 1000, + ); + const serviceName = optionalString(row.ServiceName); + if (serviceName != null) { + serviceNames.add(serviceName); + } + if (anchor == null || startMs < anchor.startMs) { + anchor = { row, startMs }; + } + } + if (anchor == null) { + return undefined; + } + return { + serviceNames: [...serviceNames].sort(), + anchorMs: anchor.startMs, + endMs: Math.min(endMs, anchor.startMs + MAX_TRACE_MS), + anchorHidden: !!anchor.row.__hdx_hidden, + sessionId: optionalString(get(anchor.row.SpanAttributes, 'session.id')), + serviceName: optionalString(anchor.row.ServiceName), + }; +} diff --git a/packages/app/src/utils/httpSpanAttributes.ts b/packages/app/src/utils/httpSpanAttributes.ts index ca1acc1b42..f183b03b30 100644 --- a/packages/app/src/utils/httpSpanAttributes.ts +++ b/packages/app/src/utils/httpSpanAttributes.ts @@ -133,7 +133,7 @@ export function getUserAgent(attributes: Attributes): string | undefined { // One decimal above 1 KB, so a body and total of 1536 and 1900 bytes don't // both round to "2 KB". -function formatBytes(bytes: number): string { +export function formatBytes(bytes: number): string { return formatNumber(bytes, { output: 'byte', mantissa: Math.abs(bytes) >= 1024 ? 1 : 0, diff --git a/packages/app/src/utils/resourceTimingMarkers.ts b/packages/app/src/utils/resourceTimingMarkers.ts new file mode 100644 index 0000000000..cbe93bcfed --- /dev/null +++ b/packages/app/src/utils/resourceTimingMarkers.ts @@ -0,0 +1,228 @@ +import { get } from 'lodash'; +import SqlString from 'sqlstring'; +import type { + BuilderChartConfigWithDateRange, + Filter, +} from '@hyperdx/common-utils/dist/types'; + +import type { TTimelineSpanEventMarker } from '@/components/TimelineChart/TimelineSpanEventMarker'; +import { getDisplayedTimestampValueExpression } from '@/source'; +import { formatDurationMs } from '@/utils'; +import { BROWSER_EVENT_NAMES } from '@/utils/browserEvents'; +import { + BrowserEventLogSource, + BrowserEventResult, + BrowserTraceContext, + getBrowserEventDateRange, + hasSubSecondTimestamps, + parseRowTimeMs, +} from '@/utils/browserTraceContext'; +import { formatBytes } from '@/utils/httpSpanAttributes'; +import { isSet, toFiniteNumber } from '@/utils/spanAttributeReaders'; + +const ATTRIBUTE_PREFIX = 'browser.resource_timing.'; + +// Same names and order as the network span events @opentelemetry/sdk-trace-web +// adds to fetch and XHR spans, which the legacy SDK drew as dots. +const PHASES = [ + ['fetch_start', 'fetchStart'], + ['domain_lookup_start', 'domainLookupStart'], + ['domain_lookup_end', 'domainLookupEnd'], + ['connect_start', 'connectStart'], + ['secure_connection_start', 'secureConnectionStart'], + ['connect_end', 'connectEnd'], + ['request_start', 'requestStart'], + ['response_start', 'responseStart'], + ['response_end', 'responseEnd'], +] as const; + +// Five keys with duration and next_hop_protocol: the marker tooltip's limit. +// New SDK spans carry no response size, and the dots replace the timing row. +const SIZE_ATTRIBUTES = [ + 'transfer_size', + 'encoded_body_size', + 'decoded_body_size', +] as const; +const PROTOCOL_ATTRIBUTE = 'next_hop_protocol'; + +// A timing log's timestamp is its emit time, after the request ends. The SDK +// flushes within 1 s; the margin covers slow exports. +const EMIT_LAG_MS = 5 * 60 * 1000; +const RESOURCE_TIMING_LIMIT = 1000; + +export type ResourceTimingMarker = Omit< + TTimelineSpanEventMarker, + 'timestamp' +> & { + attributes: Record; +}; + +/** + * Matches a timing log to its waterfall log row. Both queries select the same + * timestamp expression, and another log on the span has another timestamp. + */ +export function resourceTimingRowKey(spanId: unknown, timestamp: unknown) { + return `${String(spanId)}|${String(timestamp)}`; +} + +export function buildResourceTimingQuery({ + logSource, + context, + traceId, +}: { + logSource: BrowserEventLogSource; + context: BrowserTraceContext; + traceId: string; +}): BuilderChartConfigWithDateRange { + // toString: a JSON path is Dynamic, which IN rejects. + const filters: Filter[] = [ + { + type: 'sql', + condition: SqlString.format('? = ?', [ + SqlString.raw(`toString(${logSource.eventNameExpression})`), + BROWSER_EVENT_NAMES.RESOURCE_TIMING, + ]), + }, + ]; + if (logSource.serviceNameExpression && context.serviceNames.length > 0) { + filters.push({ + type: 'sql', + condition: SqlString.format('? IN (?)', [ + SqlString.raw(`toString(${logSource.serviceNameExpression})`), + context.serviceNames, + ]), + }); + } + return { + source: logSource.id, + connection: logSource.connection, + from: logSource.from, + timestampValueExpression: logSource.timestampValueExpression, + select: [ + { valueExpression: logSource.spanIdExpression, alias: 'span_id' }, + { + valueExpression: getDisplayedTimestampValueExpression(logSource), + alias: 'timestamp', + }, + // The whole map: a single key would need a JSON metadata lookup first. + { + valueExpression: logSource.eventAttributesExpression, + alias: 'attributes', + }, + ], + where: `${logSource.traceIdExpression} = ${SqlString.escape(traceId)}`, + whereLanguage: 'sql', + filters, + dateRange: getBrowserEventDateRange( + context.anchorMs, + context.endMs + EMIT_LAG_MS, + ), + limit: { limit: RESOURCE_TIMING_LIMIT }, + }; +} + +function readNumber(attributes: unknown, key: string): number | undefined { + // lodash get reads both a flat Map key and a nested JSON path. Map values + // are strings, and JSON Int64 values come quoted. + return toFiniteNumber(get(attributes, `${ATTRIBUTE_PREFIX}${key}`)); +} + +function getTooltipAttributes(attributes: unknown): Record { + const result: Record = {}; + const duration = readNumber(attributes, 'duration'); + if (duration != null) { + result.duration = formatDurationMs(duration); + } + // A cross-origin response without Timing-Allow-Origin reports every size as + // 0, which isn't its size. A lone 0 transfer size is a cache hit and stays. + const sizes = SIZE_ATTRIBUTES.map( + key => [key, readNumber(attributes, key)] as const, + ); + if (sizes.some(([, size]) => size)) { + for (const [key, size] of sizes) { + if (size != null) { + result[key] = formatBytes(size); + } + } + } + const protocol: unknown = get( + attributes, + `${ATTRIBUTE_PREFIX}${PROTOCOL_ATTRIBUTE}`, + ); + if (isSet(protocol)) { + result[PROTOCOL_ATTRIBUTE] = String(protocol); + } + return result; +} + +/** + * Phases are milliseconds from the page's time origin, and the log timestamp + * is its emit time, so dots are placed relative to the span start. Zero + * phases weren't measured (a cross-origin request without + * Timing-Allow-Origin) and are skipped, as sdk-trace-web does. + */ +function toMarkers( + attributes: unknown, + spanStartMs: number, + fetchStart: number, +): ResourceTimingMarker[] { + const markers = PHASES.flatMap(([key, name]) => { + const phase = readNumber(attributes, key); + return phase != null && phase !== 0 + ? [{ epochMs: spanStartMs + (phase - fetchStart), name, attributes: {} }] + : []; + }); + markers[markers.length - 1].attributes = getTooltipAttributes(attributes); + return markers; +} + +/** + * A log on a span outside the trace isn't drawn, so its row stays. A drawn + * log's row stays too when the trace filter hides its span, since the dots + * don't show, or when the timestamp column is whole seconds, since the key + * would match every log on the span in that second. + */ +export function getResourceTimingMarkers( + { data, meta }: BrowserEventResult, + traceRows: readonly { + SpanId?: unknown; + Timestamp?: unknown; + __hdx_hidden?: unknown; + }[], +): { + markersBySpanId: ReadonlyMap; + drawnRowKeys: ReadonlySet; +} { + const spanStarts = new Map(); + const shownSpanIds = new Set(); + for (const row of traceRows) { + const startMs = parseRowTimeMs(row.Timestamp); + if (isSet(row.SpanId) && startMs != null) { + const spanId = String(row.SpanId); + spanStarts.set(spanId, startMs); + if (!row.__hdx_hidden) { + shownSpanIds.add(spanId); + } + } + } + + const foldable = hasSubSecondTimestamps(meta); + const markersBySpanId = new Map(); + const drawnRowKeys = new Set(); + for (const row of data) { + const spanId = isSet(row.span_id) ? String(row.span_id) : undefined; + const spanStartMs = spanId != null ? spanStarts.get(spanId) : undefined; + const fetchStart = readNumber(row.attributes, 'fetch_start'); + if (spanId == null || spanStartMs == null || !fetchStart) { + continue; + } + markersBySpanId.set(spanId, [ + ...(markersBySpanId.get(spanId) ?? []), + ...toMarkers(row.attributes, spanStartMs, fetchStart), + ]); + if (foldable && shownSpanIds.has(spanId)) { + drawnRowKeys.add(resourceTimingRowKey(spanId, row.timestamp)); + } + } + return { markersBySpanId, drawnRowKeys }; +} diff --git a/packages/app/src/utils/sessionLogEvents.ts b/packages/app/src/utils/sessionLogEvents.ts index 0d557c1a00..3050b686e0 100644 --- a/packages/app/src/utils/sessionLogEvents.ts +++ b/packages/app/src/utils/sessionLogEvents.ts @@ -4,6 +4,7 @@ import SqlString from 'sqlstring'; import type { BuilderChartConfigWithDateRange, Filter, + SelectList, TLogSource, } from '@hyperdx/common-utils/dist/types'; @@ -91,6 +92,86 @@ function eventNameCondition( ]); } +/** A log source with the fields every session log event query reads. */ +export type SessionLogEventSource = TLogSource & + Required< + Pick + >; + +export function isSessionLogEventSource( + source: TLogSource | null | undefined, +): source is SessionLogEventSource { + return !!source?.eventNameExpression && !!source.eventAttributesExpression; +} + +/** The select and filters every session log event query shares. */ +export function getSessionLogEventQueryParts({ + logSource, + sessionId, + serviceName, + sessionIdExpression, +}: { + logSource: SessionLogEventSource; + sessionId: string; + serviceName: string | undefined; + sessionIdExpression: string; +}): { + aliasMap: Record; + select: SelectList; + sessionFilter: Filter; + serviceFilters: Filter[]; +} { + const attrs = logSource.eventAttributesExpression; + // toString: a JSON path is Dynamic, which IN rejects. + const eventName = `toString(${logSource.eventNameExpression})`; + const timestamp = getDisplayedTimestampValueExpression(logSource); + const timestampKey = getFirstTimestampValueExpression( + logSource.timestampValueExpression, + ); + const body = getEventBody(logSource); + const aliasMap: Record = { + timestamp, + ...(timestampKey !== timestamp ? { timestamp_key: timestampKey } : {}), + event_name: eventName, + session_id: sessionIdExpression, + ...(body ? { body } : {}), + attributes: attrs, + }; + return { + aliasMap, + select: Object.entries(aliasMap).map(([alias, valueExpression]) => ({ + valueExpression, + alias, + })), + sessionFilter: { + type: 'lucene', + condition: sessionIdFilter( + { + resource: + logSource.resourceAttributesExpression ?? 'ResourceAttributes', + attrs, + }, + sessionId, + 'session.id', + ), + }, + // Matches the replay query, and keeps backend exceptions that carry a + // propagated session.id off the browser timeline. + serviceFilters: + logSource.serviceNameExpression && serviceName + ? [ + { + type: 'sql', + condition: SqlString.format('? = ?', [ + SqlString.raw(logSource.serviceNameExpression), + serviceName, + ]), + }, + ] + : [], + }; +} + /** Null when the session has no browser log events to query. */ export function buildSessionLogEventsQuery({ logSource, @@ -116,83 +197,48 @@ export function buildSessionLogEventsQuery({ config: BuilderChartConfigWithDateRange; aliasMap: Record; } | null { - const attrs = logSource?.eventAttributesExpression; // Only OTel browser SDKs write these events, and the search box is written // against trace fields. if ( sessionIdKey !== 'session.id' || searchedQuery !== '' || - !logSource?.eventNameExpression || - !attrs || + !isSessionLogEventSource(logSource) || !sessionIdExpression || !consoleMethodExpression ) { return null; } - // toString: a JSON path is Dynamic, which IN rejects. - const eventName = `toString(${logSource.eventNameExpression})`; - const timestamp = getDisplayedTimestampValueExpression(logSource); - const timestampKey = getFirstTimestampValueExpression( - logSource.timestampValueExpression, - ); - const body = getEventBody(logSource); - const aliasMap: Record = { - timestamp, - ...(timestampKey !== timestamp ? { timestamp_key: timestampKey } : {}), - event_name: eventName, - session_id: sessionIdExpression, - ...(body ? { body } : {}), - attributes: attrs, - }; - const filters: Filter[] = [ - { - type: 'lucene', - condition: sessionIdFilter( - { - resource: - logSource.resourceAttributesExpression ?? 'ResourceAttributes', - attrs, - }, - sessionId, - 'session.id', - ), - }, - { - type: 'sql', - condition: eventNameCondition( - eventName, - consoleMethodExpression, - tab === 'highlighted', - ), - }, - ]; - // Matches the replay query, and keeps backend exceptions that carry a - // propagated session.id off the browser timeline. - if (logSource.serviceNameExpression && serviceName) { - filters.push({ - type: 'sql', - condition: SqlString.format('? = ?', [ - SqlString.raw(logSource.serviceNameExpression), - serviceName, - ]), + const { aliasMap, select, sessionFilter, serviceFilters } = + getSessionLogEventQueryParts({ + logSource, + sessionId, + serviceName, + sessionIdExpression, }); - } return { aliasMap, config: { source: logSource.id, - select: Object.entries(aliasMap).map(([alias, valueExpression]) => ({ - valueExpression, - alias, - })), + select, from: logSource.from, connection: logSource.connection, timestampValueExpression: logSource.timestampValueExpression, dateRange, where: '', whereLanguage: 'sql', - filters, - orderBy: `${timestamp} ASC`, + filters: [ + sessionFilter, + { + type: 'sql', + condition: eventNameCondition( + aliasMap.event_name, + consoleMethodExpression, + tab === 'highlighted', + ), + }, + ...serviceFilters, + ], + orderBy: `${aliasMap.timestamp} ASC`, limit: { limit: 4000, offset: 0 }, }, }; diff --git a/packages/app/src/utils/traceTriggerClick.ts b/packages/app/src/utils/traceTriggerClick.ts new file mode 100644 index 0000000000..c7bfe717c0 --- /dev/null +++ b/packages/app/src/utils/traceTriggerClick.ts @@ -0,0 +1,103 @@ +import SqlString from 'sqlstring'; +import type { BuilderChartConfigWithDateRange } from '@hyperdx/common-utils/dist/types'; + +import { BROWSER_EVENT_NAMES } from '@/utils/browserEvents'; +import { + BrowserEventLogSource, + BrowserEventResult, + BrowserTraceContext, + getBrowserEventDateRange, + hasSubSecondTimestamps, + parseRowTimeMs, +} from '@/utils/browserTraceContext'; +import { getSessionLogEventQueryParts } from '@/utils/sessionLogEvents'; + +// Clicks land 0-5 ms before the request they start; the click before that is +// usually several hundred ms earlier. +const TRIGGER_LOOKBACK_MS = 250; +// The floored window holds at most about 2 s of one session's clicks. +const TRIGGER_CLICK_LIMIT = 10; + +export function buildTriggerClickQuery({ + logSource, + context, + sessionId, + sessionIdExpression, +}: { + logSource: BrowserEventLogSource; + context: BrowserTraceContext; + sessionId: string; + sessionIdExpression: string; +}): { + config: BuilderChartConfigWithDateRange; + aliasMap: Record; +} { + const { aliasMap, select, sessionFilter, serviceFilters } = + getSessionLogEventQueryParts({ + logSource, + sessionId, + serviceName: context.serviceName, + sessionIdExpression, + }); + return { + aliasMap, + config: { + source: logSource.id, + select, + from: logSource.from, + connection: logSource.connection, + timestampValueExpression: logSource.timestampValueExpression, + // pickTriggerClick clips to the exact window. + dateRange: getBrowserEventDateRange( + context.anchorMs - TRIGGER_LOOKBACK_MS, + context.anchorMs, + ), + where: '', + whereLanguage: 'sql', + filters: [ + sessionFilter, + { + type: 'sql', + condition: SqlString.format('? = ?', [ + SqlString.raw(aliasMap.event_name), + BROWSER_EVENT_NAMES.CLICK, + ]), + }, + ...serviceFilters, + ], + orderBy: `${aliasMap.timestamp} DESC`, + limit: { limit: TRIGGER_CLICK_LIMIT }, + }, + }; +} + +/** + * The latest click in the lookback before the anchor. The page URL isn't + * compared: the SDK records a click's URL before the app's handler runs, and + * the request's after, so a click that changes the route or query string + * would never match. Clicks in a whole-second timestamp column can't be + * placed within the lookback, so none match. + */ +export function pickTriggerClick( + { data, meta }: BrowserEventResult, + anchorMs: number, +): { row: Record; gapMs: number } | undefined { + if (!hasSubSecondTimestamps(meta)) { + return undefined; + } + let latest: { row: Record; ms: number } | undefined; + for (const row of data) { + const ms = parseRowTimeMs(row.timestamp); + if ( + ms != null && + ms >= anchorMs - TRIGGER_LOOKBACK_MS && + ms <= anchorMs && + (latest == null || ms > latest.ms) + ) { + latest = { row, ms }; + } + } + return latest != null + ? { row: latest.row, gapMs: anchorMs - latest.ms } + : undefined; +} diff --git a/packages/app/tests/e2e/features/sessions.spec.ts b/packages/app/tests/e2e/features/sessions.spec.ts index 54f89ac6ce..6e84754f17 100644 --- a/packages/app/tests/e2e/features/sessions.spec.ts +++ b/packages/app/tests/e2e/features/sessions.spec.ts @@ -63,9 +63,29 @@ test.describe('Client Sessions Functionality', { tag: ['@sessions'] }, () => { await card.click(); await expect(sessionsPage.sessionSidePanel).toBeVisible(); - await expect( - sessionsPage.getSessionEventRows().filter({ hasText: '500 GET' }), - ).toBeVisible({ timeout: 15000 }); + const span = sessionsPage + .getSessionEventRows() + .filter({ hasText: '500 GET' }); + await expect(span).toBeVisible({ timeout: 15000 }); + + await test.step('Its trace shows the triggering click and the request timings', async () => { + await span.click(); + const trace = page.getByTestId('side-panel-tab-trace'); + const trigger = trace.getByText( + 'Triggered by: Clicked testid=checkout · 3ms before', + ); + await expect(trigger).toBeVisible({ timeout: 15000 }); + await expect(trace.getByTestId('span-event-marker')).toHaveCount(4); + // The timing log is drawn as the dots, so it isn't counted as a log. + await expect(trace.getByText(/^1 span, 1 error/)).toBeVisible(); + + await trigger.click(); + await expect( + trace + .getByText('#root > main > button.checkout', { exact: true }) + .first(), + ).toBeVisible(); + }); }); test('shows browser log events from the OpenTelemetry SDK and opens them', async ({ diff --git a/packages/app/tests/e2e/seed-otel-sessions.ts b/packages/app/tests/e2e/seed-otel-sessions.ts index c1c6a0da15..74ede603f4 100644 --- a/packages/app/tests/e2e/seed-otel-sessions.ts +++ b/packages/app/tests/e2e/seed-otel-sessions.ts @@ -61,16 +61,35 @@ export function generateOtelSessionSpans(seedRef: number): string { ].join(',\n'); } -/** Browser events the OTel SDK records as log events, after the +500 ms span. */ +// Four dots inside the 12 ms span. +const RESOURCE_TIMING = { + fetch_start: '1000.5', + request_start: '1002', + response_start: '1009', + response_end: '1011.5', + duration: '11', + transfer_size: '558', + next_hop_protocol: 'http/1.1', +}; + +/** + * OTel SDK log events around the +500 ms span: the click 3 ms before it that + * triggers its trace, its request timing, and a console error. + */ export function generateOtelSessionLogEvents(seedRef: number): string { const ns = (offsetMs: number) => (seedRef - 5 * 60 * 1000 + offsetMs) * 1_000_000; const resource = `{'service.name':'${SERVICE}'}`; + const { newSdk, bothKeys } = OTEL_SESSIONS; const click = (sessionId: string) => - `('${ns(600)}', '', '', 0, '', 9, '${SERVICE}', '', '', ${resource}, '', '', '', {}, {'session.id':'${sessionId}','browser.tag_name':'BUTTON','browser.css_selector':'#root > main > button.checkout','browser.document.url.full':'${PAGE_URL}','browser.element.attributes.testid':'checkout'}, 'browser.user_action.click')`; + `('${ns(497)}', '', '', 0, '', 9, '${SERVICE}', '', '', ${resource}, '', '', '', {}, {'session.id':'${sessionId}','browser.tag_name':'BUTTON','browser.css_selector':'#root > main > button.checkout','browser.document.url.full':'${PAGE_URL}','browser.element.attributes.testid':'checkout'}, 'browser.user_action.click')`; + const timing = Object.entries(RESOURCE_TIMING) + .map(([key, value]) => `'browser.resource_timing.${key}':'${value}'`) + .join(','); return [ - click(OTEL_SESSIONS.newSdk), - `('${ns(800)}', '', '', 0, 'error', 17, '${SERVICE}', 'Error: checkout failed', '', ${resource}, '', '', '', {}, {'session.id':'${OTEL_SESSIONS.newSdk}','browser.console.method':'error','browser.document.url.full':'${PAGE_URL}'}, 'browser.console')`, - click(OTEL_SESSIONS.bothKeys), + click(newSdk), + `('${ns(520)}', '${newSdk}-trace', '${newSdk}-span', 0, '', 9, '${SERVICE}', '', '', ${resource}, '', '@opentelemetry/browser-instrumentation/resource-timing', '', {}, {'session.id':'${newSdk}','browser.document.url.full':'${PAGE_URL}','url.full':'${PAGE_URL}api/error',${timing}}, 'browser.resource_timing')`, + `('${ns(800)}', '', '', 0, 'error', 17, '${SERVICE}', 'Error: checkout failed', '', ${resource}, '', '', '', {}, {'session.id':'${newSdk}','browser.console.method':'error','browser.document.url.full':'${PAGE_URL}'}, 'browser.console')`, + click(bothKeys), ].join(',\n'); } From d83a5bbff27439374a04895bf4e81b4a627098a8 Mon Sep 17 00:00:00 2001 From: Spencer Torres Date: Tue, 3 Nov 2026 07:47:02 -0800 Subject: [PATCH 2/2] fix: prevent logs from disappearing --- .../src/components/DBTraceWaterfallChart.tsx | 7 ++- .../__tests__/DBTraceWaterfallChart.test.tsx | 43 +++++++++++++ .../__tests__/useBrowserTraceEvents.test.tsx | 13 ++++ .../app/src/hooks/useBrowserTraceEvents.ts | 15 +++-- .../__tests__/resourceTimingMarkers.test.ts | 62 ++++++++++++++++--- .../app/src/utils/resourceTimingMarkers.ts | 36 ++++++++--- 6 files changed, 155 insertions(+), 21 deletions(-) diff --git a/packages/app/src/components/DBTraceWaterfallChart.tsx b/packages/app/src/components/DBTraceWaterfallChart.tsx index ce11723dd1..21c03d3428 100644 --- a/packages/app/src/components/DBTraceWaterfallChart.tsx +++ b/packages/app/src/components/DBTraceWaterfallChart.tsx @@ -793,6 +793,7 @@ export function DBTraceWaterfallChartContainer({ meta: logRowsMeta, filterError: logFilterError, fatalError: logFatalError, + isTruncated: logIsTruncated, } = useFilteredEventsAroundFocus({ // search data if logTableModel exist // search invalid date range if no logTableModel(react hook need execute no matter what) @@ -834,8 +835,10 @@ export function DBTraceWaterfallChartContainer({ traceId, highlightedRowWhere, initialRowHighlightHint, - // Only while the dots show. A log filter asks for the rows it matches. - foldTimingRows: showSpans && showSpanEvents && !logWhere, + // Only while the dots show. A log filter asks for the rows it matches. A + // capped list can keep a log that shares a timing log's key and drop the + // timing log, and the fold would then hide that other log. + foldTimingRows: showSpans && showSpanEvents && !logWhere && !logIsTruncated, enabled: !traceIsFetching, }); diff --git a/packages/app/src/components/__tests__/DBTraceWaterfallChart.test.tsx b/packages/app/src/components/__tests__/DBTraceWaterfallChart.test.tsx index 7d12ca2585..693b61f0e1 100644 --- a/packages/app/src/components/__tests__/DBTraceWaterfallChart.test.tsx +++ b/packages/app/src/components/__tests__/DBTraceWaterfallChart.test.tsx @@ -1263,6 +1263,49 @@ describe('DBTraceWaterfallChartContainer', () => { expect(lastFold()).toBe(false); }); + it('keeps the timing rows when the log list is capped', async () => { + setupQueryMocks({ + traceData: mockTraceData, + logData: { + data: Array.from( + { length: TRACE_WATERFALL_ROW_LIMIT + 1 }, + () => mockLogData.data[0], + ), + meta: [{ totalCount: TRACE_WATERFALL_ROW_LIMIT + 1 }], + }, + }); + renderComponent(); + await waitForLoading(); + + expect(lastFold()).toBe(false); + }); + + it('sends the same log queries whether or not the source has browser event fields', () => { + const logQueries = (logSource: TLogSource) => { + mockUseOffsetPaginatedQuery.mockClear(); + renderComponent(logSource).unmount(); + return mockUseOffsetPaginatedQuery.mock.calls + .filter(([query]) => query?.from?.tableName === 'log_table') + .map(([query, opts]) => [query, opts?.enabled]); + }; + setupQueryMocks({ traceData: mockTraceData, logData: mockLogData }); + const correlatedSource = { + ...mockLogTableSource, + traceIdExpression: 'TraceId', + spanIdExpression: 'SpanId', + }; + + const withEventFields = logQueries({ + ...correlatedSource, + eventNameExpression: 'EventName', + eventAttributesExpression: 'LogAttributes', + }); + + expect(withEventFields.some(([, enabled]) => enabled)).toBe(true); + expect(withEventFields).toEqual(logQueries(correlatedSource)); + expect(JSON.stringify(withEventFields)).not.toContain('EventName'); + }); + describe('triggered-by row', () => { const triggeredBy = 'Triggered by: Clicked testid=checkout · 3ms before'; const triggerRow: TraceTriggerRow = { diff --git a/packages/app/src/hooks/__tests__/useBrowserTraceEvents.test.tsx b/packages/app/src/hooks/__tests__/useBrowserTraceEvents.test.tsx index 4f8f25de34..2a4874a62f 100644 --- a/packages/app/src/hooks/__tests__/useBrowserTraceEvents.test.tsx +++ b/packages/app/src/hooks/__tests__/useBrowserTraceEvents.test.tsx @@ -213,6 +213,19 @@ describe('useBrowserTraceEvents', () => { expect(result.current.logRows).toEqual([consoleLogRow]); }); + it("keeps a log in the timing log's millisecond on its span, and the timing row", () => { + const errorRow = { + ...consoleLogRow, + id: 'error-row', + Timestamp: TIMING_TIMESTAMP, + Body: '', + }; + const { result } = setup({ logRows: [...logRows, errorRow] }); + + expect(result.current.resourceTimingBySpanId.has('span-1')).toBe(true); + expect(result.current.logRows).toEqual([...logRows, errorRow]); + }); + it('keeps the timing row while its dots are off screen', () => { const { result, rerender, initialProps } = setup({ foldTimingRows: false, diff --git a/packages/app/src/hooks/useBrowserTraceEvents.ts b/packages/app/src/hooks/useBrowserTraceEvents.ts index 21b29cda80..0f72b6c293 100644 --- a/packages/app/src/hooks/useBrowserTraceEvents.ts +++ b/packages/app/src/hooks/useBrowserTraceEvents.ts @@ -18,6 +18,7 @@ import { } from '@/utils/browserTraceContext'; import { buildResourceTimingQuery, + getFoldedRowKeys, getResourceTimingMarkers, ResourceTimingMarker, resourceTimingRowKey, @@ -52,7 +53,7 @@ export type TraceTriggerRow = { // Stable, so the waterfall's row memos don't rerun while there is nothing. const NO_RESOURCE_TIMING: ReturnType = { markersBySpanId: new Map(), - drawnRowKeys: new Set(), + drawnRowCounts: new Map(), }; /** @@ -106,7 +107,7 @@ export function useBrowserTraceEvents({ }); const timingResult = timingQuery != null && !timing.isError ? timing.data : undefined; - const { markersBySpanId, drawnRowKeys } = useMemo( + const { markersBySpanId, drawnRowCounts } = useMemo( () => timingResult?.data.length ? getResourceTimingMarkers(timingResult, traceRows) @@ -118,19 +119,23 @@ export function useBrowserTraceEvents({ // would leave the detail panel showing a row the waterfall lacks, and the // hint would find nothing to select. const keptLogRows = useMemo(() => { - if (!foldTimingRows || drawnRowKeys.size === 0) { + if (!foldTimingRows || drawnRowCounts.size === 0) { + return logRows; + } + const foldedRowKeys = getFoldedRowKeys(logRows, drawnRowCounts); + if (foldedRowKeys.size === 0) { return logRows; } return logRows.filter( row => - !drawnRowKeys.has(resourceTimingRowKey(row.SpanId, row.Timestamp)) || + !foldedRowKeys.has(resourceTimingRowKey(row.SpanId, row.Timestamp)) || row.id === highlightedRowWhere || matchesRowHighlightHint(row, initialRowHighlightHint), ); }, [ logRows, foldTimingRows, - drawnRowKeys, + drawnRowCounts, highlightedRowWhere, initialRowHighlightHint, ]); diff --git a/packages/app/src/utils/__tests__/resourceTimingMarkers.test.ts b/packages/app/src/utils/__tests__/resourceTimingMarkers.test.ts index 3d2085bc75..28d9e2890d 100644 --- a/packages/app/src/utils/__tests__/resourceTimingMarkers.test.ts +++ b/packages/app/src/utils/__tests__/resourceTimingMarkers.test.ts @@ -6,6 +6,7 @@ import { } from '@/hooks/__fixtures__/browserTraceEvents'; import { buildResourceTimingQuery, + getFoldedRowKeys, getResourceTimingMarkers, resourceTimingRowKey, } from '@/utils/resourceTimingMarkers'; @@ -55,7 +56,7 @@ const draw = ( describe('getResourceTimingMarkers', () => { it('places dots in sdk-trace-web order relative to the span start', () => { - const { markersBySpanId, drawnRowKeys } = draw(timingRow(sameOrigin)); + const { markersBySpanId, drawnRowCounts } = draw(timingRow(sameOrigin)); expect(markersBySpanId.get('span-1')).toEqual([ { name: 'fetchStart', epochMs: SPAN_START_MS, attributes: {} }, @@ -85,8 +86,8 @@ describe('getResourceTimingMarkers', () => { }, }, ]); - expect([...drawnRowKeys]).toEqual([ - resourceTimingRowKey('span-1', TIMING_TIMESTAMP), + expect([...drawnRowCounts]).toEqual([ + [resourceTimingRowKey('span-1', TIMING_TIMESTAMP), 1], ]); }); @@ -164,9 +165,9 @@ describe('getResourceTimingMarkers', () => { ['without a span id', timingRow(sameOrigin, { span_id: '' })], ['with attributes that are not a map', timingRow('not a map')], ])('draws nothing and keeps the row for a log %s', (_name, row) => { - const { markersBySpanId, drawnRowKeys } = draw(row); + const { markersBySpanId, drawnRowCounts } = draw(row); expect(markersBySpanId.size).toBe(0); - expect(drawnRowKeys.size).toBe(0); + expect(drawnRowCounts.size).toBe(0); }); it.each([ @@ -181,13 +182,60 @@ describe('getResourceTimingMarkers', () => { [{ name: 'timestamp', type: 'DateTime' }], ], ])('draws a log but keeps its row when %s', (_name, spans, meta) => { - const { markersBySpanId, drawnRowKeys } = draw( + const { markersBySpanId, drawnRowCounts } = draw( timingRow(sameOrigin), spans, meta, ); expect(markersBySpanId.get('span-1')).toHaveLength(8); - expect(drawnRowKeys.size).toBe(0); + expect(drawnRowCounts.size).toBe(0); + }); + + it('counts a timing log ingested twice once per copy', () => { + const row = timingRow(sameOrigin); + const { drawnRowCounts } = getResourceTimingMarkers( + { data: [row, row], meta: TIMESTAMP_META }, + traceRows, + ); + expect([...drawnRowCounts]).toEqual([ + [resourceTimingRowKey('span-1', TIMING_TIMESTAMP), 2], + ]); + }); +}); + +describe('getFoldedRowKeys', () => { + const key = resourceTimingRowKey('span-1', TIMING_TIMESTAMP); + const timingLogRow = { SpanId: 'span-1', Timestamp: TIMING_TIMESTAMP }; + const otherLogRow = { + SpanId: 'span-1', + Timestamp: '2026-10-22T04:52:37.825000000Z', + }; + + it.each([ + ['folds the timing row alone', [timingLogRow, otherLogRow], 1, [key]], + [ + 'keeps an exception in the same millisecond and the timing row', + [timingLogRow, { ...timingLogRow, Body: '', SeverityNumber: 17 }], + 1, + [], + ], + [ + 'keeps a console error in the same millisecond and the timing row', + [timingLogRow, { ...timingLogRow, Body: 'boom', SeverityText: 'error' }], + 1, + [], + ], + [ + 'folds two copies of a timing log drawn twice', + [timingLogRow, timingLogRow], + 2, + [key], + ], + ['ignores rows on other keys', [otherLogRow], 1, []], + ])('%s', (_name, logRows, drawn, expected) => { + expect([...getFoldedRowKeys(logRows, new Map([[key, drawn]]))]).toEqual( + expected, + ); }); }); diff --git a/packages/app/src/utils/resourceTimingMarkers.ts b/packages/app/src/utils/resourceTimingMarkers.ts index cbe93bcfed..89c6955388 100644 --- a/packages/app/src/utils/resourceTimingMarkers.ts +++ b/packages/app/src/utils/resourceTimingMarkers.ts @@ -1,4 +1,4 @@ -import { get } from 'lodash'; +import { countBy, get } from 'lodash'; import SqlString from 'sqlstring'; import type { BuilderChartConfigWithDateRange, @@ -58,13 +58,34 @@ export type ResourceTimingMarker = Omit< }; /** - * Matches a timing log to its waterfall log row. Both queries select the same - * timestamp expression, and another log on the span has another timestamp. + * Matches a timing log to its waterfall log row: both queries select the same + * timestamp expression. Another log on the span can share the key, so the + * fold goes through getFoldedRowKeys. */ export function resourceTimingRowKey(spanId: unknown, timestamp: unknown) { return `${String(spanId)}|${String(timestamp)}`; } +/** + * Log rows carry no event name, and an exception or console error on the span + * in the same millisecond has the timing log's key. A key folds only when the + * dots query drew a timing log for each log row with it. All rows with a key + * share one timestamp, so an uncapped log list holds all of them or none. + */ +export function getFoldedRowKeys( + logRows: readonly { SpanId?: unknown; Timestamp?: unknown }[], + drawnRowCounts: ReadonlyMap, +): ReadonlySet { + const rowCounts = countBy(logRows, row => + resourceTimingRowKey(row.SpanId, row.Timestamp), + ); + return new Set( + [...drawnRowCounts] + .filter(([key, drawn]) => rowCounts[key] <= drawn) + .map(([key]) => key), + ); +} + export function buildResourceTimingQuery({ logSource, context, @@ -191,7 +212,7 @@ export function getResourceTimingMarkers( }[], ): { markersBySpanId: ReadonlyMap; - drawnRowKeys: ReadonlySet; + drawnRowCounts: ReadonlyMap; } { const spanStarts = new Map(); const shownSpanIds = new Set(); @@ -208,7 +229,7 @@ export function getResourceTimingMarkers( const foldable = hasSubSecondTimestamps(meta); const markersBySpanId = new Map(); - const drawnRowKeys = new Set(); + const drawnRowCounts = new Map(); for (const row of data) { const spanId = isSet(row.span_id) ? String(row.span_id) : undefined; const spanStartMs = spanId != null ? spanStarts.get(spanId) : undefined; @@ -221,8 +242,9 @@ export function getResourceTimingMarkers( ...toMarkers(row.attributes, spanStartMs, fetchStart), ]); if (foldable && shownSpanIds.has(spanId)) { - drawnRowKeys.add(resourceTimingRowKey(spanId, row.timestamp)); + const key = resourceTimingRowKey(spanId, row.timestamp); + drawnRowCounts.set(key, (drawnRowCounts.get(key) ?? 0) + 1); } } - return { markersBySpanId, drawnRowKeys }; + return { markersBySpanId, drawnRowCounts }; }