From 83fa4dbcacead8c460a321271786374bd6800d19 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?S=C3=B8ren=20Louv-Jansen?= Date: Mon, 29 Oct 2018 15:50:30 +0100 Subject: [PATCH] [APM] Clock skew fix Only skew child spans from the same service Take parent skew into account when finding diff # Conflicts: # x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/__snapshots__/waterfall_helpers.test.ts.snap # x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.test.ts # x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.ts --- .../Waterfall/WaterfallItem.tsx | 2 +- .../waterfall_helpers.test.ts.snap | 5 + .../waterfall_helpers.test.ts | 167 +++++++++--------- .../waterfall_helpers/waterfall_helpers.ts | 53 +++++- 4 files changed, 142 insertions(+), 85 deletions(-) diff --git a/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/WaterfallItem.tsx b/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/WaterfallItem.tsx index db0f48ab6b2ae..55af00e143fc6 100644 --- a/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/WaterfallItem.tsx +++ b/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/WaterfallItem.tsx @@ -116,7 +116,7 @@ export function WaterfallItem({ } const width = (item.duration / totalDuration) * 100; - const left = (item.offset / totalDuration) * 100; + const left = ((item.offset + item.skew) / totalDuration) * 100; const Label = item.docType === 'transaction' ? TransactionLabel : SpanLabel; return ( diff --git a/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/__snapshots__/waterfall_helpers.test.ts.snap b/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/__snapshots__/waterfall_helpers.test.ts.snap index b2c2895f5b54e..9fd18e285d0d4 100644 --- a/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/__snapshots__/waterfall_helpers.test.ts.snap +++ b/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/__snapshots__/waterfall_helpers.test.ts.snap @@ -13,6 +13,7 @@ Array [ "name": "APIRestController#products", "offset": 0, "serviceName": "opbeans-java", + "skew": 0, "timestamp": 1536763736366000, "transaction": Object {}, }, @@ -25,6 +26,7 @@ Array [ "offset": 1000, "parentId": "a", "serviceName": "opbeans-java", + "skew": 0, "span": Object { "transaction": Object { "id": "a", @@ -43,6 +45,7 @@ Array [ "offset": 2000, "parentId": "a", "serviceName": "opbeans-java", + "skew": 0, "span": Object { "transaction": Object { "id": "a", @@ -61,6 +64,7 @@ Array [ "offset": 3000, "parentId": "b", "serviceName": "opbeans-java", + "skew": 0, "timestamp": 1536763736369000, "transaction": Object {}, }, @@ -73,6 +77,7 @@ Array [ "offset": 5000, "parentId": "c", "serviceName": "opbeans-java", + "skew": 0, "span": Object { "transaction": Object { "id": "c", diff --git a/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.test.ts b/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.test.ts index e040e39c81163..3669f6a378a7c 100644 --- a/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.test.ts +++ b/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.test.ts @@ -4,92 +4,101 @@ * you may not use this file except in compliance with the Elastic License. */ +import { groupBy, indexBy } from 'lodash'; import { Span } from 'x-pack/plugins/apm/typings/Span'; import { Transaction } from 'x-pack/plugins/apm/typings/Transaction'; -import { getWaterfallItems, IWaterfallGroup } from './waterfall_helpers'; +import { + getWaterfallItems, + IWaterfallIndex, + IWaterfallItem +} from './waterfall_helpers'; describe('waterfall_helpers', () => { describe('getWaterfallItems', () => { it('should order items correctly', () => { - const items: IWaterfallGroup = { - a: [ - { - id: 'b', - parentId: 'a', - serviceName: 'opbeans-java', - name: 'GET [0:0:0:0:0:0:0:1]', - duration: 4694, - timestamp: 1536763736368000, - offset: 0, - docType: 'span', - span: { - transaction: { - id: 'a' - } - } as Span - }, - { - id: 'b2', - parentId: 'a', - serviceName: 'opbeans-java', - name: 'GET [0:0:0:0:0:0:0:1]', - duration: 4694, - timestamp: 1536763736367000, - offset: 0, - docType: 'span', - span: { - transaction: { - id: 'a' - } - } as Span - } - ], - b: [ - { - id: 'c', - parentId: 'b', - serviceName: 'opbeans-java', - name: 'APIRestController#productsRemote', - duration: 3581, - timestamp: 1536763736369000, - offset: 0, - docType: 'transaction', - transaction: {} as Transaction - } - ], - c: [ - { - id: 'd', - parentId: 'c', - serviceName: 'opbeans-java', - name: 'SELECT', - duration: 210, - timestamp: 1536763736371000, - offset: 0, - docType: 'span', - span: { - transaction: { - id: 'c' - } - } as Span - } - ], - root: [ - { - id: 'a', - serviceName: 'opbeans-java', - name: 'APIRestController#products', - duration: 9480, - timestamp: 1536763736366000, - offset: 0, - docType: 'transaction', - transaction: {} as Transaction - } - ] - }; + const items: IWaterfallItem[] = [ + { + id: 'd', + parentId: 'c', + serviceName: 'opbeans-java', + name: 'SELECT', + duration: 210, + timestamp: 1536763736371000, + offset: 0, + skew: 0, + docType: 'span', + span: { + transaction: { + id: 'c' + } + } as Span + }, + { + id: 'b', + parentId: 'a', + serviceName: 'opbeans-java', + name: 'GET [0:0:0:0:0:0:0:1]', + duration: 4694, + timestamp: 1536763736368000, + offset: 0, + skew: 0, + docType: 'span', + span: { + transaction: { + id: 'a' + } + } as Span + }, + { + id: 'b2', + parentId: 'a', + serviceName: 'opbeans-java', + name: 'GET [0:0:0:0:0:0:0:1]', + duration: 4694, + timestamp: 1536763736367000, + offset: 0, + skew: 0, + docType: 'span', + span: { + transaction: { + id: 'a' + } + } as Span + }, + { + id: 'c', + parentId: 'b', + serviceName: 'opbeans-java', + name: 'APIRestController#productsRemote', + duration: 3581, + timestamp: 1536763736369000, + offset: 0, + skew: 0, + docType: 'transaction', + transaction: {} as Transaction + }, + { + id: 'a', + serviceName: 'opbeans-java', + name: 'APIRestController#products', + duration: 9480, + timestamp: 1536763736366000, + offset: 0, + skew: 0, + docType: 'transaction', + transaction: {} as Transaction + } + ]; - const entryTransactionItem = items.root[0]; - expect(getWaterfallItems(items, entryTransactionItem)).toMatchSnapshot(); + const childrenByParentId = groupBy( + items, + hit => (hit.parentId ? hit.parentId : 'root') + ); + const itemsById: IWaterfallIndex = indexBy(items, 'id'); + const entryTransactionItem = childrenByParentId.root[0]; + expect( + getWaterfallItems(childrenByParentId, itemsById, entryTransactionItem) + ).toMatchSnapshot(); }); }); }); diff --git a/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.ts b/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.ts index b8f169ff1635f..2dd3553dac4a3 100644 --- a/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.ts +++ b/x-pack/plugins/apm/public/components/app/TransactionDetails/Transaction/WaterfallContainer/Waterfall/waterfall_helpers/waterfall_helpers.ts @@ -42,6 +42,7 @@ interface IWaterfallItemBase { duration: number; timestamp: number; offset: number; + skew: number; childIds?: Array; } @@ -68,6 +69,7 @@ function getTransactionItem( duration: transaction.transaction.duration.us, timestamp: new Date(transaction['@timestamp']).getTime() * 1000, offset: 0, + skew: 0, docType: 'transaction', transaction }; @@ -81,6 +83,7 @@ function getTransactionItem( duration: transaction.transaction.duration.us, timestamp: transaction.timestamp.us, offset: 0, + skew: 0, docType: 'transaction', transaction }; @@ -97,6 +100,7 @@ function getSpanItem(span: Span): IWaterfallItemSpan { timestamp: new Date(span['@timestamp']).getTime() * 1000 + span.span.start.us, offset: 0, + skew: 0, docType: 'span', span }; @@ -110,26 +114,61 @@ function getSpanItem(span: Span): IWaterfallItemSpan { duration: span.span.duration.us, timestamp: span.timestamp.us, offset: 0, + skew: 0, docType: 'span', span }; } +function getClockSkew( + item: IWaterfallItem, + itemsById: IWaterfallIndex, + parentTransactionSkew: number +) { + // calculate clock skew for transactions with parents + if (item.docType === 'transaction' && item.parentId) { + const parentItem = itemsById[item.parentId]; + + // determine if child starts before the parent, and in that case how much + const diff = parentItem.timestamp + parentItem.skew - item.timestamp; + + // If child transaction starts after parent span there is no clock skew + if (diff < 0) { + return 0; + } + + // latency can only be calculated if parent duration is larger than child duration + const latency = Math.max(parentItem.duration - item.duration, 0); + const skew = diff + latency / 2; + return skew; + } + + return parentTransactionSkew; +} + export function getWaterfallItems( childrenByParentId: IWaterfallGroup, + itemsById: IWaterfallIndex, entryTransactionItem: IWaterfallItem ) { - function getSortedChildren(item: IWaterfallItem): IWaterfallItem[] { + function getSortedChildren( + item: IWaterfallItem, + parentTransactionSkew: number + ): IWaterfallItem[] { + const skew = getClockSkew(item, itemsById, parentTransactionSkew); const children = sortBy(childrenByParentId[item.id] || [], 'timestamp'); item.childIds = children.map(child => child.id); item.offset = item.timestamp - entryTransactionItem.timestamp; + item.skew = skew; - const deepChildren = flatten(children.map(getSortedChildren)); + const deepChildren = flatten( + children.map(child => getSortedChildren(child, skew)) + ); return [item, ...deepChildren]; } - return getSortedChildren(entryTransactionItem); + return getSortedChildren(entryTransactionItem, 0); } function getTraceRoot(childrenByParentId: IWaterfallGroup) { @@ -179,9 +218,13 @@ export function getWaterfall( hit => (hit.parentId ? hit.parentId : 'root') ); const entryTransactionItem = getTransactionItem(entryTransaction); - const items = getWaterfallItems(childrenByParentId, entryTransactionItem); + const itemsById: IWaterfallIndex = indexBy(filteredHits, 'id'); + const items = getWaterfallItems( + childrenByParentId, + itemsById, + entryTransactionItem + ); const traceRoot = getTraceRoot(childrenByParentId); - const itemsById: IWaterfallIndex = indexBy(items, 'id'); const getTransactionById = (id?: IWaterfallItem['id']) => { if (!id) {