|
1 | | -import type { Page, Route } from '@playwright/test'; |
| 1 | +import type { Page, Request, Route } from '@playwright/test'; |
2 | 2 | import { expect } from '@playwright/test'; |
| 3 | +import type { Envelope } from '@sentry/core'; |
3 | 4 | import { sentryTest } from '../../../../utils/fixtures'; |
4 | | -import { envelopeRequestParser, shouldSkipTracingTest, waitForTransactionRequest } from '../../../../utils/helpers'; |
| 5 | +import { |
| 6 | + properFullEnvelopeRequestParser, |
| 7 | + shouldSkipMetricsTest, |
| 8 | + shouldSkipTracingTest, |
| 9 | +} from '../../../../utils/helpers'; |
| 10 | + |
| 11 | +type MetricItem = Record<string, unknown> & { |
| 12 | + name: string; |
| 13 | + type: string; |
| 14 | + value: number; |
| 15 | + unit?: string; |
| 16 | + attributes: Record<string, { value: string | number; type: string }>; |
| 17 | +}; |
| 18 | + |
| 19 | +function extractMetricsFromRequest(req: Request): MetricItem[] { |
| 20 | + try { |
| 21 | + const envelope = properFullEnvelopeRequestParser<Envelope>(req); |
| 22 | + const items = envelope[1]; |
| 23 | + const metrics: MetricItem[] = []; |
| 24 | + for (const item of items) { |
| 25 | + const [header] = item; |
| 26 | + if (header.type === 'trace_metric') { |
| 27 | + const payload = item[1] as { items?: MetricItem[] }; |
| 28 | + if (payload.items) { |
| 29 | + metrics.push(...payload.items); |
| 30 | + } |
| 31 | + } |
| 32 | + } |
| 33 | + return metrics; |
| 34 | + } catch { |
| 35 | + return []; |
| 36 | + } |
| 37 | +} |
| 38 | + |
| 39 | +/** |
| 40 | + * Collects element timing metrics from envelope requests on the page. |
| 41 | + * Returns a function to get all collected metrics so far and a function |
| 42 | + * that waits until all expected identifiers have been seen in render_time metrics. |
| 43 | + */ |
| 44 | +function createMetricCollector(page: Page) { |
| 45 | + const collectedRequests: Request[] = []; |
| 46 | + |
| 47 | + page.on('request', req => { |
| 48 | + if (!req.url().includes('/api/1337/envelope/')) return; |
| 49 | + const metrics = extractMetricsFromRequest(req); |
| 50 | + if (metrics.some(m => m.name.startsWith('ui.element.'))) { |
| 51 | + collectedRequests.push(req); |
| 52 | + } |
| 53 | + }); |
| 54 | + |
| 55 | + function getAll(): MetricItem[] { |
| 56 | + return collectedRequests.flatMap(req => extractMetricsFromRequest(req)); |
| 57 | + } |
| 58 | + |
| 59 | + async function waitForIdentifiers(identifiers: string[], timeout = 30_000): Promise<void> { |
| 60 | + const deadline = Date.now() + timeout; |
| 61 | + while (Date.now() < deadline) { |
| 62 | + const all = getAll().filter(m => m.name === 'ui.element.render_time'); |
| 63 | + const seen = new Set(all.map(m => m.attributes['ui.element.identifier']?.value)); |
| 64 | + if (identifiers.every(id => seen.has(id))) { |
| 65 | + return; |
| 66 | + } |
| 67 | + await page.waitForTimeout(500); |
| 68 | + } |
| 69 | + // Final check with assertion for clear error message |
| 70 | + const all = getAll().filter(m => m.name === 'ui.element.render_time'); |
| 71 | + const seen = all.map(m => m.attributes['ui.element.identifier']?.value); |
| 72 | + for (const id of identifiers) { |
| 73 | + expect(seen).toContain(id); |
| 74 | + } |
| 75 | + } |
| 76 | + |
| 77 | + function reset(): void { |
| 78 | + collectedRequests.length = 0; |
| 79 | + } |
| 80 | + |
| 81 | + return { getAll, waitForIdentifiers, reset }; |
| 82 | +} |
5 | 83 |
|
6 | 84 | sentryTest( |
7 | | - 'adds element timing spans to pageload span tree for elements rendered during pageload', |
| 85 | + 'emits element timing metrics for elements rendered during pageload', |
8 | 86 | async ({ getLocalTestUrl, page, browserName }) => { |
9 | | - if (shouldSkipTracingTest() || browserName === 'webkit') { |
| 87 | + if (shouldSkipTracingTest() || shouldSkipMetricsTest() || browserName === 'webkit') { |
10 | 88 | sentryTest.skip(); |
11 | 89 | } |
12 | 90 |
|
13 | | - const pageloadEventPromise = waitForTransactionRequest(page, evt => evt.contexts?.trace?.op === 'pageload'); |
14 | | - |
15 | 91 | serveAssets(page); |
16 | 92 |
|
17 | 93 | const url = await getLocalTestUrl({ testDir: __dirname }); |
| 94 | + const collector = createMetricCollector(page); |
18 | 95 |
|
19 | 96 | await page.goto(url); |
20 | 97 |
|
21 | | - const eventData = envelopeRequestParser(await pageloadEventPromise); |
22 | | - |
23 | | - const elementTimingSpans = eventData.spans?.filter(({ op }) => op === 'ui.elementtiming'); |
24 | | - |
25 | | - expect(elementTimingSpans?.length).toEqual(8); |
26 | | - |
27 | | - // Check image-fast span (this is served with a 100ms delay) |
28 | | - const imageFastSpan = elementTimingSpans?.find(({ description }) => description === 'element[image-fast]'); |
29 | | - const imageFastRenderTime = imageFastSpan?.data['element.render_time']; |
30 | | - const imageFastLoadTime = imageFastSpan?.data['element.load_time']; |
31 | | - const duration = imageFastSpan!.timestamp! - imageFastSpan!.start_timestamp; |
32 | | - |
33 | | - expect(imageFastSpan).toBeDefined(); |
34 | | - expect(imageFastSpan?.data).toEqual({ |
35 | | - 'sentry.op': 'ui.elementtiming', |
36 | | - 'sentry.origin': 'auto.ui.browser.elementtiming', |
37 | | - 'sentry.source': 'component', |
38 | | - 'sentry.span_start_time_source': 'load-time', |
39 | | - 'element.id': 'image-fast-id', |
40 | | - 'element.identifier': 'image-fast', |
41 | | - 'element.type': 'img', |
42 | | - 'element.size': '600x179', |
43 | | - 'element.url': 'https://sentry-test-site.example/path/to/image-fast.png', |
44 | | - 'element.render_time': expect.any(Number), |
45 | | - 'element.load_time': expect.any(Number), |
46 | | - 'element.paint_type': 'image-paint', |
47 | | - 'sentry.transaction_name': '/index.html', |
48 | | - }); |
49 | | - expect(imageFastRenderTime).toBeGreaterThan(90); |
50 | | - expect(imageFastRenderTime).toBeLessThan(400); |
51 | | - expect(imageFastLoadTime).toBeGreaterThan(90); |
52 | | - expect(imageFastLoadTime).toBeLessThan(400); |
53 | | - expect(imageFastRenderTime).toBeGreaterThan(imageFastLoadTime as number); |
54 | | - expect(duration).toBeGreaterThan(0); |
55 | | - expect(duration).toBeLessThan(20); |
56 | | - |
57 | | - // Check text1 span |
58 | | - const text1Span = elementTimingSpans?.find(({ data }) => data?.['element.identifier'] === 'text1'); |
59 | | - const text1RenderTime = text1Span?.data['element.render_time']; |
60 | | - const text1LoadTime = text1Span?.data['element.load_time']; |
61 | | - const text1Duration = text1Span!.timestamp! - text1Span!.start_timestamp; |
62 | | - expect(text1Span).toBeDefined(); |
63 | | - expect(text1Span?.data).toEqual({ |
64 | | - 'sentry.op': 'ui.elementtiming', |
65 | | - 'sentry.origin': 'auto.ui.browser.elementtiming', |
66 | | - 'sentry.source': 'component', |
67 | | - 'sentry.span_start_time_source': 'render-time', |
68 | | - 'element.id': 'text1-id', |
69 | | - 'element.identifier': 'text1', |
70 | | - 'element.type': 'p', |
71 | | - 'element.render_time': expect.any(Number), |
72 | | - 'element.load_time': expect.any(Number), |
73 | | - 'element.paint_type': 'text-paint', |
74 | | - 'sentry.transaction_name': '/index.html', |
75 | | - }); |
76 | | - expect(text1RenderTime).toBeGreaterThan(0); |
77 | | - expect(text1RenderTime).toBeLessThan(300); |
78 | | - expect(text1LoadTime).toBe(0); |
79 | | - expect(text1RenderTime).toBeGreaterThan(text1LoadTime as number); |
80 | | - expect(text1Duration).toBe(0); |
81 | | - |
82 | | - // Check button1 span (no need for a full assertion) |
83 | | - const button1Span = elementTimingSpans?.find(({ data }) => data?.['element.identifier'] === 'button1'); |
84 | | - expect(button1Span).toBeDefined(); |
85 | | - expect(button1Span?.data).toMatchObject({ |
86 | | - 'element.identifier': 'button1', |
87 | | - 'element.type': 'button', |
88 | | - 'element.paint_type': 'text-paint', |
89 | | - 'sentry.transaction_name': '/index.html', |
| 98 | + // Wait until all expected element identifiers have been flushed as metrics |
| 99 | + await collector.waitForIdentifiers(['image-fast', 'text1', 'button1', 'image-slow', 'lazy-image', 'lazy-text']); |
| 100 | + |
| 101 | + const allMetrics = collector.getAll().filter(m => m.name.startsWith('ui.element.')); |
| 102 | + const renderTimeMetrics = allMetrics.filter(m => m.name === 'ui.element.render_time'); |
| 103 | + const loadTimeMetrics = allMetrics.filter(m => m.name === 'ui.element.load_time'); |
| 104 | + |
| 105 | + const renderIdentifiers = renderTimeMetrics.map(m => m.attributes['ui.element.identifier']?.value); |
| 106 | + const loadIdentifiers = loadTimeMetrics.map(m => m.attributes['ui.element.identifier']?.value); |
| 107 | + |
| 108 | + // All text and image elements should have render_time |
| 109 | + expect(renderIdentifiers).toContain('image-fast'); |
| 110 | + expect(renderIdentifiers).toContain('text1'); |
| 111 | + expect(renderIdentifiers).toContain('button1'); |
| 112 | + expect(renderIdentifiers).toContain('image-slow'); |
| 113 | + expect(renderIdentifiers).toContain('lazy-image'); |
| 114 | + expect(renderIdentifiers).toContain('lazy-text'); |
| 115 | + |
| 116 | + // Image elements should also have load_time |
| 117 | + expect(loadIdentifiers).toContain('image-fast'); |
| 118 | + expect(loadIdentifiers).toContain('image-slow'); |
| 119 | + expect(loadIdentifiers).toContain('lazy-image'); |
| 120 | + |
| 121 | + // Text elements should NOT have load_time (loadTime is 0 for text-paint) |
| 122 | + expect(loadIdentifiers).not.toContain('text1'); |
| 123 | + expect(loadIdentifiers).not.toContain('button1'); |
| 124 | + expect(loadIdentifiers).not.toContain('lazy-text'); |
| 125 | + |
| 126 | + // Validate metric structure for image-fast |
| 127 | + const imageFastRender = renderTimeMetrics.find(m => m.attributes['ui.element.identifier']?.value === 'image-fast'); |
| 128 | + expect(imageFastRender).toMatchObject({ |
| 129 | + name: 'ui.element.render_time', |
| 130 | + type: 'distribution', |
| 131 | + unit: 'millisecond', |
| 132 | + value: expect.any(Number), |
90 | 133 | }); |
| 134 | + expect(imageFastRender!.attributes['ui.element.paint_type']?.value).toBe('image-paint'); |
91 | 135 |
|
92 | | - // Check image-slow span |
93 | | - const imageSlowSpan = elementTimingSpans?.find(({ data }) => data?.['element.identifier'] === 'image-slow'); |
94 | | - expect(imageSlowSpan).toBeDefined(); |
95 | | - expect(imageSlowSpan?.data).toEqual({ |
96 | | - 'element.id': '', |
97 | | - 'element.identifier': 'image-slow', |
98 | | - 'element.type': 'img', |
99 | | - 'element.size': '600x179', |
100 | | - 'element.url': 'https://sentry-test-site.example/path/to/image-slow.png', |
101 | | - 'element.paint_type': 'image-paint', |
102 | | - 'element.render_time': expect.any(Number), |
103 | | - 'element.load_time': expect.any(Number), |
104 | | - 'sentry.op': 'ui.elementtiming', |
105 | | - 'sentry.origin': 'auto.ui.browser.elementtiming', |
106 | | - 'sentry.source': 'component', |
107 | | - 'sentry.span_start_time_source': 'load-time', |
108 | | - 'sentry.transaction_name': '/index.html', |
109 | | - }); |
110 | | - const imageSlowRenderTime = imageSlowSpan?.data['element.render_time']; |
111 | | - const imageSlowLoadTime = imageSlowSpan?.data['element.load_time']; |
112 | | - const imageSlowDuration = imageSlowSpan!.timestamp! - imageSlowSpan!.start_timestamp; |
113 | | - expect(imageSlowRenderTime).toBeGreaterThan(1400); |
114 | | - expect(imageSlowRenderTime).toBeLessThan(2000); |
115 | | - expect(imageSlowLoadTime).toBeGreaterThan(1400); |
116 | | - expect(imageSlowLoadTime).toBeLessThan(2000); |
117 | | - expect(imageSlowDuration).toBeGreaterThan(0); |
118 | | - expect(imageSlowDuration).toBeLessThan(20); |
119 | | - |
120 | | - // Check lazy-image span |
121 | | - const lazyImageSpan = elementTimingSpans?.find(({ data }) => data?.['element.identifier'] === 'lazy-image'); |
122 | | - expect(lazyImageSpan).toBeDefined(); |
123 | | - expect(lazyImageSpan?.data).toEqual({ |
124 | | - 'element.id': '', |
125 | | - 'element.identifier': 'lazy-image', |
126 | | - 'element.type': 'img', |
127 | | - 'element.size': '600x179', |
128 | | - 'element.url': 'https://sentry-test-site.example/path/to/image-lazy.png', |
129 | | - 'element.paint_type': 'image-paint', |
130 | | - 'element.render_time': expect.any(Number), |
131 | | - 'element.load_time': expect.any(Number), |
132 | | - 'sentry.op': 'ui.elementtiming', |
133 | | - 'sentry.origin': 'auto.ui.browser.elementtiming', |
134 | | - 'sentry.source': 'component', |
135 | | - 'sentry.span_start_time_source': 'load-time', |
136 | | - 'sentry.transaction_name': '/index.html', |
137 | | - }); |
138 | | - const lazyImageRenderTime = lazyImageSpan?.data['element.render_time']; |
139 | | - const lazyImageLoadTime = lazyImageSpan?.data['element.load_time']; |
140 | | - const lazyImageDuration = lazyImageSpan!.timestamp! - lazyImageSpan!.start_timestamp; |
141 | | - expect(lazyImageRenderTime).toBeGreaterThan(1000); |
142 | | - expect(lazyImageRenderTime).toBeLessThan(1500); |
143 | | - expect(lazyImageLoadTime).toBeGreaterThan(1000); |
144 | | - expect(lazyImageLoadTime).toBeLessThan(1500); |
145 | | - expect(lazyImageDuration).toBeGreaterThan(0); |
146 | | - expect(lazyImageDuration).toBeLessThan(20); |
147 | | - |
148 | | - // Check lazy-text span |
149 | | - const lazyTextSpan = elementTimingSpans?.find(({ data }) => data?.['element.identifier'] === 'lazy-text'); |
150 | | - expect(lazyTextSpan?.data).toMatchObject({ |
151 | | - 'element.id': '', |
152 | | - 'element.identifier': 'lazy-text', |
153 | | - 'element.type': 'p', |
154 | | - 'sentry.transaction_name': '/index.html', |
155 | | - }); |
156 | | - const lazyTextRenderTime = lazyTextSpan?.data['element.render_time']; |
157 | | - const lazyTextLoadTime = lazyTextSpan?.data['element.load_time']; |
158 | | - const lazyTextDuration = lazyTextSpan!.timestamp! - lazyTextSpan!.start_timestamp; |
159 | | - expect(lazyTextRenderTime).toBeGreaterThan(1000); |
160 | | - expect(lazyTextRenderTime).toBeLessThan(1500); |
161 | | - expect(lazyTextLoadTime).toBe(0); |
162 | | - expect(lazyTextDuration).toBe(0); |
163 | | - |
164 | | - // the div1 entry does not emit an elementTiming entry because it's neither a text nor an image |
165 | | - expect(elementTimingSpans?.find(({ description }) => description === 'element[div1]')).toBeUndefined(); |
| 136 | + // Validate text-paint metric |
| 137 | + const text1Render = renderTimeMetrics.find(m => m.attributes['ui.element.identifier']?.value === 'text1'); |
| 138 | + expect(text1Render!.attributes['ui.element.paint_type']?.value).toBe('text-paint'); |
166 | 139 | }, |
167 | 140 | ); |
168 | 141 |
|
169 | | -sentryTest('emits element timing spans on navigation', async ({ getLocalTestUrl, page, browserName }) => { |
170 | | - if (shouldSkipTracingTest() || browserName === 'webkit') { |
| 142 | +sentryTest('emits element timing metrics after navigation', async ({ getLocalTestUrl, page, browserName }) => { |
| 143 | + if (shouldSkipTracingTest() || shouldSkipMetricsTest() || browserName === 'webkit') { |
171 | 144 | sentryTest.skip(); |
172 | 145 | } |
173 | 146 |
|
174 | 147 | serveAssets(page); |
175 | 148 |
|
176 | 149 | const url = await getLocalTestUrl({ testDir: __dirname }); |
| 150 | + const collector = createMetricCollector(page); |
177 | 151 |
|
178 | 152 | await page.goto(url); |
179 | 153 |
|
180 | | - const pageloadEventPromise = waitForTransactionRequest(page, evt => evt.contexts?.trace?.op === 'pageload'); |
181 | | - |
182 | | - const navigationEventPromise = waitForTransactionRequest(page, evt => evt.contexts?.trace?.op === 'navigation'); |
| 154 | + // Wait for pageload element timing metrics to arrive before navigating |
| 155 | + await collector.waitForIdentifiers(['image-fast', 'text1']); |
183 | 156 |
|
184 | | - await pageloadEventPromise; |
| 157 | + // Reset so we only capture post-navigation metrics |
| 158 | + collector.reset(); |
185 | 159 |
|
| 160 | + // Trigger navigation |
186 | 161 | await page.locator('#button1').click(); |
187 | 162 |
|
188 | | - const navigationTransactionEvent = envelopeRequestParser(await navigationEventPromise); |
189 | | - const pageloadTransactionEvent = envelopeRequestParser(await pageloadEventPromise); |
190 | | - |
191 | | - const navigationElementTimingSpans = navigationTransactionEvent.spans?.filter(({ op }) => op === 'ui.elementtiming'); |
192 | | - |
193 | | - expect(navigationElementTimingSpans?.length).toEqual(2); |
194 | | - |
195 | | - const navigationStartTime = navigationTransactionEvent.start_timestamp!; |
196 | | - const pageloadStartTime = pageloadTransactionEvent.start_timestamp!; |
197 | | - |
198 | | - const imageSpan = navigationElementTimingSpans?.find( |
199 | | - ({ description }) => description === 'element[navigation-image]', |
200 | | - ); |
201 | | - const textSpan = navigationElementTimingSpans?.find(({ description }) => description === 'element[navigation-text]'); |
| 163 | + // Wait for navigation element timing metrics |
| 164 | + await collector.waitForIdentifiers(['navigation-image', 'navigation-text']); |
202 | 165 |
|
203 | | - // Image started loading after navigation, but render-time and load-time still start from the time origin |
204 | | - // of the pageload. This is somewhat a limitation (though by design according to the ElementTiming spec) |
205 | | - expect((imageSpan!.data['element.render_time']! as number) / 1000 + pageloadStartTime).toBeGreaterThan( |
206 | | - navigationStartTime, |
207 | | - ); |
208 | | - expect((imageSpan!.data['element.load_time']! as number) / 1000 + pageloadStartTime).toBeGreaterThan( |
209 | | - navigationStartTime, |
210 | | - ); |
| 166 | + const allMetrics = collector.getAll(); |
| 167 | + const renderTimeMetrics = allMetrics.filter(m => m.name === 'ui.element.render_time'); |
| 168 | + const renderIdentifiers = renderTimeMetrics.map(m => m.attributes['ui.element.identifier']?.value); |
211 | 169 |
|
212 | | - expect(textSpan?.data['element.load_time']).toBe(0); |
213 | | - expect((textSpan!.data['element.render_time']! as number) / 1000 + pageloadStartTime).toBeGreaterThan( |
214 | | - navigationStartTime, |
215 | | - ); |
| 170 | + expect(renderIdentifiers).toContain('navigation-image'); |
| 171 | + expect(renderIdentifiers).toContain('navigation-text'); |
216 | 172 | }); |
217 | 173 |
|
218 | 174 | function serveAssets(page: Page) { |
|
0 commit comments