Merge pull request #3 from sqren/fix-clock-skew

[APM] Clock skew fix

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 (

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",

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();
     });
   });
 });

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<IWaterfallItemBase['id']>;
 }
 
@@ -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) {