From 149bfe6db5c609e2eaaa2e16765729cd32496676 Mon Sep 17 00:00:00 2001 From: Kerry Gallagher Date: Thu, 10 Dec 2020 19:18:52 +0000 Subject: [PATCH] Use timings directly from the Agent: https://github.com/elastic/synthetics/pull/168 --- .../common/runtime_types/network_events.ts | 28 ++- .../waterfall/data_formatting.test.ts | 128 +------------- .../step_detail/waterfall/data_formatting.ts | 166 +++--------------- .../synthetics/step_detail/waterfall/types.ts | 6 +- .../server/lib/requests/get_network_events.ts | 2 +- 5 files changed, 38 insertions(+), 292 deletions(-) diff --git a/x-pack/plugins/uptime/common/runtime_types/network_events.ts b/x-pack/plugins/uptime/common/runtime_types/network_events.ts index 392bd08d75771..6104758f28fd8 100644 --- a/x-pack/plugins/uptime/common/runtime_types/network_events.ts +++ b/x-pack/plugins/uptime/common/runtime_types/network_events.ts @@ -7,24 +7,16 @@ import * as t from 'io-ts'; const NetworkTimingsType = t.type({ - dns_start: t.number, - push_end: t.number, - worker_fetch_start: t.number, - worker_respond_with_settled: t.number, - proxy_end: t.number, - worker_start: t.number, - worker_ready: t.number, - send_end: t.number, - connect_end: t.number, - connect_start: t.number, - send_start: t.number, - proxy_start: t.number, - push_start: t.number, - ssl_end: t.number, - receive_headers_end: t.number, - ssl_start: t.number, - request_time: t.number, - dns_end: t.number, + queueing: t.number, + connect: t.number, + total: t.number, + send: t.number, + blocked: t.number, + receive: t.number, + wait: t.number, + dns: t.number, + proxy: t.number, + ssl: t.number, }); export type NetworkTimings = t.TypeOf; diff --git a/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/data_formatting.test.ts b/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/data_formatting.test.ts index 03e025bf54190..fff14376667b2 100644 --- a/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/data_formatting.test.ts +++ b/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/data_formatting.test.ts @@ -4,133 +4,7 @@ * you may not use this file except in compliance with the Elastic License. */ -import { colourPalette, getTimings, getSeriesAndDomain, extractItems } from './data_formatting'; - -const networkEvent = { - timestamp: '2020-12-06T19:55:01.273Z', - method: 'GET', - url: 'https://www.some-fake-url.css', - status: 200, - mimeType: 'text/css', - requestSentTime: 1723033619.631, - requestStartTime: 1723033621.036, - loadEndTime: 1723033729.635, - timings: { - ssl_start: 32.875, - proxy_end: -1, - send_start: 69.738, - send_end: 69.923, - connect_start: 0.591, - receive_headers_end: 106.076, - dns_end: 0.591, - connect_end: 69.557, - worker_fetch_start: -1, - worker_ready: -1, - push_start: 0, - dns_start: 0.539, - ssl_end: 69.542, - request_time: 1723033.621036, - worker_respond_with_settled: -1, - worker_start: -1, - push_end: 0, - proxy_start: -1, - }, -}; - -describe('getTimings', () => { - it('Calculates timings for network events correctly', () => { - const timings = getTimings( - networkEvent.timings, - networkEvent.requestSentTime, - networkEvent.loadEndTime - ); - expect(timings).toEqual({ - blocked: 1.9439999713897707, - connect: 32.480000000000004, - dns: 0.051999999999999935, - receive: 2.5230000019073486, - send: 0.18500000000000227, - ssl: 36.667, - wait: 36.15299999999999, - }); - }); -}); - -describe('getSeriesAndDomain', () => { - let seriesAndDomain: any; - let NetworkItems: any; - - beforeAll(() => { - NetworkItems = extractItems([networkEvent]); - seriesAndDomain = getSeriesAndDomain(NetworkItems); - }); - - it('Correctly calculates the domain', () => { - expect(seriesAndDomain.domain).toEqual({ max: 110.00399997329711, min: 0 }); - }); - - it('Correctly calculates the series', () => { - expect(seriesAndDomain.series).toEqual([ - { - config: { - colour: '#b9a888', - tooltipProps: { colour: '#b9a888', value: 'Queued / Blocked: 1.944ms' }, - }, - x: 0, - y: 1.9439999713897707, - y0: 0, - }, - { - config: { colour: '#54b399', tooltipProps: { colour: '#54b399', value: 'DNS: 0.052ms' } }, - x: 0, - y: 1.9959999713897707, - y0: 1.9439999713897707, - }, - { - config: { - colour: '#da8b45', - tooltipProps: { colour: '#da8b45', value: 'Connecting: 32.480ms' }, - }, - x: 0, - y: 34.475999971389776, - y0: 1.9959999713897707, - }, - { - config: { colour: '#edc5a2', tooltipProps: { colour: '#edc5a2', value: 'SSL: 36.667ms' } }, - x: 0, - y: 71.14299997138977, - y0: 34.475999971389776, - }, - { - config: { - colour: '#d36086', - tooltipProps: { colour: '#d36086', value: 'Sending request: 0.185ms' }, - }, - x: 0, - y: 71.32799997138977, - y0: 71.14299997138977, - }, - { - config: { - colour: '#b0c9e0', - tooltipProps: { colour: '#b0c9e0', value: 'Waiting (TTFB): 36.153ms' }, - }, - x: 0, - y: 107.48099997138976, - y0: 71.32799997138977, - }, - { - config: { - colour: '#ca8eae', - tooltipProps: { colour: '#ca8eae', value: 'Content downloading: 2.523ms' }, - }, - x: 0, - y: 110.00399997329711, - y0: 107.48099997138976, - }, - ]); - }); -}); +import { colourPalette } from './data_formatting'; describe('Palettes', () => { it('A colour palette comprising timing and mime type colours is correctly generated', () => { diff --git a/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/data_formatting.ts b/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/data_formatting.ts index 5badee09e9371..94dd8e33e9e91 100644 --- a/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/data_formatting.ts +++ b/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/data_formatting.ts @@ -7,8 +7,6 @@ import { euiPaletteColorBlind } from '@elastic/eui'; import { - PayloadTimings, - CalculatedTimings, NetworkItems, NetworkItem, FriendlyTimingLabels, @@ -23,112 +21,10 @@ import { import { WaterfallData } from '../../waterfall'; import { NetworkEvent } from '../../../../../../common/runtime_types'; -const microToMillis = (micro: number): number => (micro === -1 ? -1 : micro * 1000); - -// The timing calculations here are based off several sources: -// https://github.com/ChromeDevTools/devtools-frontend/blob/2fe91adefb2921b4deb2b4b125370ef9ccdb8d1b/front_end/sdk/HARLog.js#L307 -// and -// https://chromium.googlesource.com/chromium/blink.git/+/master/Source/devtools/front_end/sdk/HAREntry.js#131 -// and -// https://github.com/cyrus-and/chrome-har-capturer/blob/master/lib/har.js#L195 -// and -// https://github.com/sitespeedio/chrome-har/blob/4586d2961fe8752982120c3f613b8da42cf3648b/lib/finalizeEntry.js#L7 -// Order of events: request_start = 0, [proxy], [dns], [connect [ssl]], [send], receive_headers_end - -export const getTimings = ( - timings: NetworkEvent['timings'], - requestSentTime: NetworkEvent['requestSentTime'], - loadEndTime: NetworkEvent['loadEndTime'] -): CalculatedTimings => { - if (!timings) return { blocked: -1, dns: -1, connect: -1, send: 0, wait: 0, receive: 0, ssl: -1 }; - - const getLeastNonNegative = (values: number[]) => - values.reduce((best, value) => (value >= 0 && value < best ? value : best), Infinity); - const getOptionalTiming = (_timings: PayloadTimings, key: keyof PayloadTimings) => - _timings[key] >= 0 ? _timings[key] : -1; - - // NOTE: Request sent and request start can differ due to queue times - const requestStartTime = microToMillis(timings.request_time); - - // Queued - const queuedTime = requestSentTime < requestStartTime ? requestStartTime - requestSentTime : -1; - - // Blocked - // "blocked" represents both queued time + blocked/stalled time + proxy time (ie: anything before the request was actually started). - let blocked = queuedTime; - - const blockedStart = getLeastNonNegative([ - timings.dns_start, - timings.connect_start, - timings.send_start, - ]); - - if (blockedStart !== Infinity) { - blocked += blockedStart; - } - - // Proxy - // Proxy is part of blocked, but it can be quirky in that blocked can be -1 even though there are proxy timings. This can happen with - // protocols like Quic. - if (timings.proxy_end !== -1) { - const blockedProxy = timings.proxy_end - timings.proxy_start; - - if (blockedProxy && blockedProxy > blocked) { - blocked = blockedProxy; - } - } - - // DNS - const dnsStart = timings.dns_end >= 0 ? blockedStart : 0; - const dnsEnd = getOptionalTiming(timings, 'dns_end'); - const dns = dnsEnd - dnsStart; - - // SSL - const sslStart = getOptionalTiming(timings, 'ssl_start'); - const sslEnd = getOptionalTiming(timings, 'ssl_end'); - let ssl; - - if (sslStart >= 0 && sslEnd >= 0) { - ssl = timings.ssl_end - timings.ssl_start; - } - - // Connect - let connect = -1; - if (timings.connect_start >= 0) { - connect = timings.send_start - timings.connect_start; - } - - // Send - const send = timings.send_end - timings.send_start; - - // Wait - const waitStart = timings.send_end; - const waitEnd = timings.receive_headers_end; - const wait = waitEnd - waitStart; - - const receive = loadEndTime - (requestStartTime + timings.receive_headers_end); - - // SSL connection is a part of the overall connection time - if (connect && ssl) { - connect = connect - ssl; - } - - return { blocked, dns, connect, send, wait, receive, ssl }; -}; - export const extractItems = (data: NetworkEvent[]): NetworkItems => { - return data - .map((entry) => { - return { - ...entry, - timings: entry.timings - ? getTimings(entry.timings, entry.requestSentTime, entry.loadEndTime) - : undefined, - }; - }) - .sort((a: NetworkItem, b: NetworkItem) => { - return a.requestSentTime - b.requestSentTime; - }); + return data.sort((a: NetworkItem, b: NetworkItem) => { + return a.requestSentTime - b.requestSentTime; + }); }; const formatValueForDisplay = (value: number, points: number = 3) => { @@ -141,50 +37,36 @@ const getColourForMimeType = (mimeType?: string) => { }; export const getSeriesAndDomain = (items: NetworkItems) => { + const getValueForOffset = (item: NetworkItem) => { + return item.requestSentTime; + }; + // The earliest point in time a request is sent or started. This will become our notion of "0". const zeroOffset = items.reduce((acc, item) => { - const { requestSentTime } = item; - return requestSentTime < acc ? requestSentTime : acc; + const offsetValue = getValueForOffset(item); + return offsetValue < acc ? offsetValue : acc; }, Infinity); - const series = items.reduce((acc, item, index) => { - const { requestSentTime } = item; + const getValue = (timings: NetworkEvent['timings'], timing: Timings) => { + if (!timings) return; - // Entries without timings should be handled differently: - // https://github.com/ChromeDevTools/devtools-frontend/blob/ed2a064ac194bfae4e25c4748a9fa3513b3e9f7d/front_end/network/RequestTimingView.js#L140 - // If there are no concrete timings just plot one block via request start and response end - if (!item.timings || item.timings === null) { - const duration = item.loadEndTime - item.requestSentTime; - const colour = getColourForMimeType(item.mimeType); - return [ - ...acc, - { - x: index, - y0: item.requestSentTime - zeroOffset, - // NOTE: The loadEndTime can sometimes be "0" - y: - item.loadEndTime && item.loadEndTime > 0 - ? item.loadEndTime - zeroOffset - : item.requestSentTime - zeroOffset, - config: { - colour, - tooltipProps: { - // NOTE: The loadEndTime can sometimes be "0" - value: - item.loadEndTime && item.loadEndTime > 0 - ? `${formatValueForDisplay(duration)}ms` - : "Response time couldn't be determined", - colour, - }, - }, - }, - ]; + // SSL is a part of the connect timing + if (timing === Timings.Connect && timings.ssl > 0) { + return timings.connect - timings.ssl; + } else { + return timings[timing]; } + }; + + const series = items.reduce((acc, item, index) => { + if (!item.timings) return acc; + + const offsetValue = getValueForOffset(item); - let currentOffset = requestSentTime - zeroOffset; + let currentOffset = offsetValue - zeroOffset; TIMING_ORDER.forEach((timing) => { - const value = item.timings![timing]; + const value = getValue(item.timings, timing); const colour = timing === Timings.Receive ? getColourForMimeType(item.mimeType) : colourPalette[timing]; if (value && value >= 0) { diff --git a/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/types.ts b/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/types.ts index 708aca4531513..738929741ddaf 100644 --- a/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/types.ts +++ b/x-pack/plugins/uptime/public/components/monitor/synthetics/step_detail/waterfall/types.ts @@ -34,7 +34,7 @@ export const FriendlyTimingLabels = { } ), [Timings.Ssl]: i18n.translate('xpack.uptime.synthetics.waterfallChart.labels.timings.ssl', { - defaultMessage: 'SSL', + defaultMessage: 'TLS', }), [Timings.Send]: i18n.translate('xpack.uptime.synthetics.waterfallChart.labels.timings.send', { defaultMessage: 'Sending request', @@ -145,9 +145,7 @@ export const MimeTypesMap: Record = { 'application/font-sfnt': MimeType.Font, }; -export type NetworkItem = Omit & { - timings?: CalculatedTimings; -}; +export type NetworkItem = NetworkEvent; export type NetworkItems = NetworkItem[]; // NOTE: A number will always be present if the property exists, but that number might be -1, which represents no value. diff --git a/x-pack/plugins/uptime/server/lib/requests/get_network_events.ts b/x-pack/plugins/uptime/server/lib/requests/get_network_events.ts index 17c50cf15a38a..81ef6bb65a3df 100644 --- a/x-pack/plugins/uptime/server/lib/requests/get_network_events.ts +++ b/x-pack/plugins/uptime/server/lib/requests/get_network_events.ts @@ -50,7 +50,7 @@ export const getNetworkEvents: UMElasticsearchQueryFn< requestSentTime, requestStartTime, loadEndTime, - timings: event._source.synthetics.payload.response?.timing, + timings: event._source.synthetics.payload.timings, }; }); };