From c00de0df3defcf84eba709a139aac2c534f83382 Mon Sep 17 00:00:00 2001 From: Renan Castro Date: Fri, 3 May 2024 21:09:14 -0300 Subject: [PATCH] fix: waited on time should not include wait time --- lib/models/methods.js | 4 ++-- lib/models/pubsub.js | 5 +++-- lib/utils.js | 5 ++++- lib/wait_time_builder.js | 4 ++-- tests/models/methods.js | 37 ++++++++++++++++++++++++++++++++++++- tests/models/pubsub.js | 38 ++++++++++++++++++++++++++++++++++++++ 6 files changed, 85 insertions(+), 8 deletions(-) diff --git a/lib/models/methods.js b/lib/models/methods.js index f78203e3..93d5fbf4 100644 --- a/lib/models/methods.js +++ b/lib/models/methods.js @@ -120,12 +120,12 @@ MethodsModel.prototype.trackMsgSize = function (method, size) { methodMetrics.sentMsgSize += size; }; -MethodsModel.prototype.trackWaitedOn = function (method, messageQueue) { +MethodsModel.prototype.trackWaitedOn = function (method, messageQueue, started) { const timestamp = Ntp._now(); const dateId = this._getDateId(timestamp); let methodMetrics = this._getMetrics(dateId, method); - methodMetrics.waitedOn += calculateWaitedOnTime(messageQueue); + methodMetrics.waitedOn += calculateWaitedOnTime(messageQueue, started); }; /* diff --git a/lib/models/pubsub.js b/lib/models/pubsub.js index b1d94e98..9f6e2c6d 100644 --- a/lib/models/pubsub.js +++ b/lib/models/pubsub.js @@ -396,12 +396,13 @@ PubsubModel.prototype.trackMsgSize = function (name, type, size) { } }; -PubsubModel.prototype.trackWaitedOn = function (name, messageQueue) { +PubsubModel.prototype.trackWaitedOn = function (name, messageQueue, started) { let timestamp = Ntp._now(); let publicationName = this._getPublicationName(name); + let metrics = this._getMetrics(timestamp, publicationName); - metrics.waitedOn += calculateWaitedOnTime(messageQueue); + metrics.waitedOn += calculateWaitedOnTime(messageQueue, started); }; PubsubModel.prototype.trackWaitTime = function (msg) { let subscriptionState = this.subscriptions[msg.id]; diff --git a/lib/utils.js b/lib/utils.js index 2c2c0ec7..3def329a 100644 --- a/lib/utils.js +++ b/lib/utils.js @@ -115,7 +115,7 @@ export function pick (obj, keys) { }, {}); } -export function calculateWaitedOnTime (messageQueue) { +export function calculateWaitedOnTime (messageQueue, startedTime) { let waitedOnTime = 0; const now = Ntp._now(); @@ -124,6 +124,9 @@ export function calculateWaitedOnTime (messageQueue) { messageQueue.toArray().forEach(function (msg) { if (msg._waitEventId) { waitedOnTime += now - msg._waitEventId.at; + if(msg._waitEventId.at < startedTime) { + waitedOnTime -= startedTime - msg._waitEventId.at + } } }); diff --git a/lib/wait_time_builder.js b/lib/wait_time_builder.js index 7af8012e..a421babb 100644 --- a/lib/wait_time_builder.js +++ b/lib/wait_time_builder.js @@ -102,9 +102,9 @@ export class WaitTimeBuilder { unblocked = true; if (msg.msg === 'method') { - Kadira.models.methods.trackWaitedOn(msg.method, session.inQueue); + Kadira.models.methods.trackWaitedOn(msg.method, session.inQueue, started); } else if (msg.msg === 'sub') { - Kadira.models.pubsub.trackWaitedOn(msg.name, session.inQueue); + Kadira.models.pubsub.trackWaitedOn(msg.name, session.inQueue, started); } unblock(); diff --git a/tests/models/methods.js b/tests/models/methods.js index 432d6d11..c6173350 100644 --- a/tests/models/methods.js +++ b/tests/models/methods.js @@ -1,7 +1,7 @@ import { EJSON } from 'meteor/ejson'; import { MethodsModel } from '../../lib/models/methods'; import { TestData } from '../_helpers/globals'; -import { CleanTestData, GetMeteorClient, RegisterMethod, Wait, WithDocCacheGetSize, findMetricsForMethod } from '../_helpers/helpers'; +import { CleanTestData, CloseClient, GetMeteorClient, RegisterMethod, Wait, WithDocCacheGetSize, findMetricsForMethod, waitForConnection } from '../_helpers/helpers'; import { Meteor } from 'meteor/meteor'; Tinytest.add( @@ -211,6 +211,41 @@ Tinytest.addAsync('Models - Method - Waited On - track wait time of queued messa done(); }); + +Tinytest.addAsync('Models - Method - Waited On - track waitedOn without wait time', async (test, done) => { + CleanTestData(); + + let slowMethod = RegisterMethod(function () { + console.log('slow method start'); + Meteor._sleepForMs(100); + console.log('slow method end'); + }); + let unblockedMethod = RegisterMethod(function () { + this.unblock() + Meteor._sleepForMs(100); + console.log('slow method end'); + }); + let fastMethod = RegisterMethod(function () { + console.log('fastMethod'); + }); + + + let client = GetMeteorClient(); + + // subscriptions and method calls made before connected are not run in order + waitForConnection(client); + + client.call(slowMethod, () => {}); + client.call(unblockedMethod, () => {}); + await new Promise(r => client.call(fastMethod, () => r())); + + const metrics = findMetricsForMethod(unblockedMethod); + + test.isTrue(metrics.waitedOn < 10, `${metrics.waitedOn} should be less than 10`); + CloseClient(client); + + done(); +}); Tinytest.addAsync('Models - Method - Waited On - check unblock time', async (test, done) => { let methodId = RegisterMethod( function (id) { this.unblock(); diff --git a/tests/models/pubsub.js b/tests/models/pubsub.js index 6918cd45..5466748c 100644 --- a/tests/models/pubsub.js +++ b/tests/models/pubsub.js @@ -779,6 +779,44 @@ Tinytest.addAsync('Models - PubSub - Waited On - track wait time of queued messa done(); }); +Meteor.publish('tinytest-unblock-fast', function () { + console.log('unblock-fast-pub') + this.unblock(); + Meteor._sleepForMs(100); + this.ready(); +}); + +Tinytest.addAsync('Models - PubSub - Waited On - track waitedOn without wait time', async (test, done) => { + CleanTestData(); + + let slowMethod = RegisterMethod(function () { + console.log('slow method start'); + Meteor._sleepForMs(100); + console.log('slow method end'); + }); + let fastMethod = RegisterMethod(function () { + console.log('fastMethod'); + }); + + + let client = GetMeteorClient(); + + // subscriptions and method calls made before connected are not run in order + waitForConnection(client); + + const pubName = 'tinytest-unblock-fast'; + client.call(slowMethod, () => {}); + client.subscribe(pubName); + await new Promise(r => client.call(fastMethod, () => r())); + + const metrics = FindMetricsForPub(pubName); + + test.isTrue(metrics.waitedOn < 10 && metrics.waitedOn >= 0, `${metrics.waitedOn} should be less than 10`); + CloseClient(client); + + done(); +}); + Tinytest.addAsync('Models - PubSub - Waited On - track waited on time of next message', async (test, done) => { CleanTestData(); let fastMethod = RegisterMethod(function () {