Skip to content

Commit

Permalink
simplify compute and async metric calculation
Browse files Browse the repository at this point in the history
  • Loading branch information
@leonardoventurini
leonardoventurini committed Nov 9, 2023
1 parent a352455 commit 24e90bd
Show file tree
Hide file tree
Showing 4 changed files with 31 additions and 234 deletions.
73 changes: 17 additions & 56 deletions lib/tracer/tracer.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,6 @@ import { objectHasData } from '../common/utils';
import { cleanTrailingNilValues, CreateUserStack, DefaultUniqueId, last, pick } from '../utils';
import { Ntp } from '../ntp';
import { EventType, MaxAsyncLevel } from '../constants';
import { getTotalDuration, mergeIntervals, setEventDuration, subtractIntervals } from '../utils/time';
import { getActiveEvent, getInfo, getStore, MontiAsyncStorage } from '../async/als';
import { executionAsyncId, triggerAsyncId } from 'async_hooks';
import util from 'util';
Expand Down Expand Up @@ -250,23 +249,13 @@ Tracer.prototype._hasUsefulNested = function (event) {
!event.nested.every(e => e.type === 'async');
};

Tracer.prototype.calculateAsync = function (traceInfo, metrics) {
const withoutWork = subtractIntervals(metrics.asyncIntervalsMerged, metrics.workIntervalsMerged);

return getTotalDuration(withoutWork);
};

Tracer.prototype.calculateCompute = function (traceInfo, metrics) {
const total = [[traceInfo.at, traceInfo.endAt]];

const withoutWork = subtractIntervals(total, metrics.workIntervalsMerged);

const withoutAsync = subtractIntervals(withoutWork, metrics.asyncIntervalsMerged);

return getTotalDuration(withoutAsync);
};

Tracer.prototype.buildTrace = function (traceInfo) {
let metrics = {
compute: 0,
async: 0,
totalNonCompute: 0,
};

let firstEvent = traceInfo.events[0];
let lastEvent = last(traceInfo.events);

Expand All @@ -278,38 +267,18 @@ Tracer.prototype.buildTrace = function (traceInfo) {
return null;
}

const processedEvents = this.optimizeEvents(traceInfo.events, metrics);

// build the metrics
traceInfo.errored = lastEvent.type === EventType.Error;
traceInfo.at = firstEvent.at;
traceInfo.endAt = lastEvent.endAt || lastEvent.at;

const asyncIntervals = traceInfo.events
.filter(({ type }) => type === EventType.Async)
.map(({ at, end }) => [at, end ?? traceInfo.endAt]);

let metrics = {
total: traceInfo.endAt - firstEvent.at,
compute: 0,
async: 0,
workIntervals: [],
asyncIntervals,
workIntervalsMerged: [],
asyncIntervalsMerged: [],
};

const processedEvents = this.optimizeEvents(traceInfo.events, metrics);

metrics.workIntervalsMerged = mergeIntervals(metrics.workIntervals);
metrics.asyncIntervalsMerged = mergeIntervals(metrics.asyncIntervals);

metrics.async = this.calculateAsync(traceInfo, metrics);
metrics.compute = this.calculateCompute(traceInfo, metrics);
metrics.total = traceInfo.endAt - firstEvent.at;
metrics.compute = metrics.total - metrics.totalNonCompute;

// Remove temporary fields
delete metrics.workIntervals;
delete metrics.workIntervalsMerged;
delete metrics.asyncIntervals;
delete metrics.asyncIntervalsMerged;
delete metrics.totalNonCompute;

traceInfo.metrics = metrics;
traceInfo.events = processedEvents;
Expand Down Expand Up @@ -351,14 +320,13 @@ Tracer.prototype.optimizeEvent = function (objectEvent, metrics) {
};

if (![EventType.Complete, EventType.Start].includes(type)) {
setEventDuration(objectEvent);

if (!endAt) {
endAt = Ntp._now();
objectEvent.duration = endAt - at;
extraInfo.forcedEnd = true;
}

objectEvent.duration = endAt - at;

const {duration} = objectEvent;

// We need this info as events are not always in order or in series.
Expand All @@ -372,17 +340,10 @@ Tracer.prototype.optimizeEvent = function (objectEvent, metrics) {
extraInfo.stack = objectEvent.stack;
}

if (metrics && duration > 0) {
const isAsyncAndRootOrOther = type === EventType.Async && level === 0 || type !== EventType.Async;

if (isAsyncAndRootOrOther) {
metrics[type] = metrics[type] || 0;
metrics[type] += duration;
}

if (level === 0) {
metrics.workIntervals.push([at, endAt]);
}
if (metrics && duration > 0 && level === 0) {
metrics[type] = metrics[type] || 0;
metrics[type] += duration;
metrics.totalNonCompute += duration;
}

// Start and end events do not have duration.
Expand Down
80 changes: 0 additions & 80 deletions lib/utils/time.js
View file

This file was deleted.

24 changes: 12 additions & 12 deletions tests/models/methods.js
View file
Original file line number Diff line number Diff line change
@@ -1,8 +1,8 @@
import { EJSON } from 'meteor/ejson';
import { MethodsModel } from '../../lib/models/methods';
import { TestData } from '../_helpers/globals';
import { addAsyncTest, callAsync, clientCallAsync, registerMethod, withDocCacheGetSize } from '../_helpers/helpers';
import { sleep } from '../../lib/utils';
import { Ntp } from '../../lib/ntp';

addAsyncTest(
'Models - Method - buildPayload simple',
Expand Down Expand Up @@ -48,11 +48,9 @@ addAsyncTest(
methodRequests: []
};

let startTime = expected.methodMetrics[0].startTime;
expected.methodMetrics[0].startTime = Kadira.syncedDate.syncTime(startTime);
expected.methodMetrics[0].startTime = payload.methodMetrics[0].startTime;

// TODO comparing without parsing and stringifing fails
test.equal(EJSON.parse(EJSON.stringify(payload)), EJSON.parse(EJSON.stringify(expected)));
test.stableEqual(payload, expected);
}
);

Expand Down Expand Up @@ -91,9 +89,8 @@ addAsyncTest(
}
}
}];
// TODO comparing without stringify fails
expected[0].startTime = Kadira.syncedDate.syncTime(expected[0].startTime);
test.equal(EJSON.parse(EJSON.stringify(payload.methodMetrics)), EJSON.parse(EJSON.stringify(expected)));
expected[0].startTime = payload.methodMetrics[0].startTime;
test.stableEqual(payload.methodMetrics,expected);
}
);

Expand Down Expand Up @@ -191,17 +188,20 @@ export const model = new MethodsModel();
function createMethodCompleted (sessionName, methodName, methodId, startTime, methodDelay) {
methodDelay = methodDelay || 5;
let method = {session: sessionName, name: methodName, id: methodId, events: []};
method.events.push({type: 'start', at: startTime});
method.events.push({type: 'complete', at: startTime + methodDelay});
method.events.push({type: 'start', at: Ntp._now() - startTime});
method.events.push({type: 'complete', at: Ntp._now() - startTime + methodDelay});
method = Kadira.tracer.buildTrace(method);
model.processMethod(method);
}

function createMethodErrored (sessionName, methodName, methodId, errorMessage, startTime, methodDelay) {
methodDelay = methodDelay || 5;
let method = {session: sessionName, name: methodName, id: methodId, events: []};
method.events.push({type: 'start', at: startTime});
method.events.push({type: 'error', at: startTime + methodDelay, data: {error: errorMessage}});
method.events.push({type: 'start', at: Ntp._now() - startTime});
method.events.push({type: 'error',
at: Ntp._now() - startTime + methodDelay,
endAt: Ntp._now() - startTime + methodDelay,
data: {error: errorMessage}});
method = Kadira.tracer.buildTrace(method);
model.processMethod(method);
}
88 changes: 2 additions & 86 deletions tests/tracer/tracer.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,10 +11,10 @@ import {
import { sleep } from '../../lib/utils';
import { TestData } from '../_helpers/globals';
import { getInfo } from '../../lib/async/als';
import { mergeIntervals, subtractIntervals } from '../../lib/utils/time';
import { EventType } from '../../lib/constants';
import { Meteor } from 'meteor/meteor';
import { Random } from 'meteor/random';
import { Ntp } from '../../lib/ntp';

let eventDefaults = {
endAt: 0,
Expand Down Expand Up @@ -260,7 +260,7 @@ addAsyncTest(
addAsyncTest(
'Tracer - Build Trace - simple',
async function (test) {
let now = new Date().getTime();
let now = Ntp._now();

let traceInfo = {
events: [
Expand Down Expand Up @@ -629,90 +629,6 @@ addAsyncTest('Tracer - Build Trace - the correct number of async events are capt
test.equal(asyncEvents.length,1);
});

addAsyncTest('Tracer - Time - Subtract Intervals', async function (test) {
function testSubtractIntervals (arr1, arr2, expected) {
const result = subtractIntervals(arr1, arr2);
test.stableEqual(result, expected);
}

testSubtractIntervals([
[0, 10],
[20, 30],
[40, 50],
],[
[5, 15],
[25, 35],
[35, 45],
],[
[0, 5],
[20, 25],
[45, 50],
]);

testSubtractIntervals(
[
[0, 10],
[20, 30],
[40, 50],
],
[[0, 50]],
[]
);

testSubtractIntervals(
[
[0, 100],
],
[
[0, 50],
],
[
[50, 100],
]
);
});

addAsyncTest('Tracer- Time - Merge Parallel Intervals', async function (test) {
function testMergeParallelIntervals (arr, expected) {
const result = mergeIntervals(arr);
test.stableEqual(result, expected);
}

testMergeParallelIntervals([
[0, 10],
[20, 30],
[40, 50],
],[
[0, 10],
[20, 30],
[40, 50],
]);

testMergeParallelIntervals([
[0, 10],
[5, 15],
[20, 30],
[25, 35],
[40, 50],
[35, 45],
],[
[0, 15],
[20, 50],
]);

testMergeParallelIntervals([
[0, 10],
[5, 15],
[20, 30],
[25, 35],
[40, 50],
[35, 45],
[0, 50],
],[
[0, 50],
]);
});

function startTrace () {
const ddpMessage = {
id: 'the-id',
Expand Down

0 comments on commit 24e90bd

Please sign in to comment.