From 146e5afa4118cd1cfa7eef3340fc9244143401ed Mon Sep 17 00:00:00 2001 From: italo jose Date: Wed, 1 Oct 2025 11:23:37 -0300 Subject: [PATCH 1/4] add DDP client and stress test configuration --- .gitignore | 2 +- artillery/reactive-multi-stress-server.yml | 15 + package.json | 4 +- tests/server-load-helpers.js | 404 +++++++++++++++++++++ 4 files changed, 423 insertions(+), 2 deletions(-) create mode 100644 artillery/reactive-multi-stress-server.yml create mode 100644 tests/server-load-helpers.js diff --git a/.gitignore b/.gitignore index 827b821..faa6159 100644 --- a/.gitignore +++ b/.gitignore @@ -4,5 +4,5 @@ node_modules/ /playwright-report/ /blob-report/ /playwright/.cache/ -/logs* +# /logs* .env* diff --git a/artillery/reactive-multi-stress-server.yml b/artillery/reactive-multi-stress-server.yml new file mode 100644 index 0000000..6b3935f --- /dev/null +++ b/artillery/reactive-multi-stress-server.yml @@ -0,0 +1,15 @@ +config: + target: ws://localhost:3000/websocket + phases: + - duration: 60 + arrivalRate: 5 + ensure: + maxErrorRate: 1 + max: 500 + processor: '../tests/server-load-helpers.js' +scenarios: + - name: Reactive Multi Pub/Sub DDP + flow: + - function: 'beforeScenario' + - function: 'reactiveMultiPubSubTasksDdp' + - function: 'afterScenario' diff --git a/package.json b/package.json index bb09fdc..0597d58 100644 --- a/package.json +++ b/package.json @@ -2,7 +2,9 @@ "name": "performance", "version": "1.0.0", "main": "index.js", - "scripts": {}, + "scripts": { + "stress:ddp": "NODE_OPTIONS=\"--no-deprecation\" artillery run artillery/reactive-multi-stress-server.yml" + }, "author": "", "license": "ISC", "description": "", diff --git a/tests/server-load-helpers.js b/tests/server-load-helpers.js new file mode 100644 index 0000000..f6856d7 --- /dev/null +++ b/tests/server-load-helpers.js @@ -0,0 +1,404 @@ +const WebSocket = require('ws'); +const { randomUUID } = require('crypto'); + +const DEFAULT_HTTP_ENDPOINT = process.env.REMOTE_URL || 'http://localhost:3000'; +const DEFAULT_DDP_ENDPOINT = process.env.DDP_URL || toWebsocket(DEFAULT_HTTP_ENDPOINT); +const CONNECT_TIMEOUT_MS = parseInt(process.env.DDP_CONNECT_TIMEOUT_MS || '15000', 10); +const METHOD_TIMEOUT_MS = parseInt(process.env.DDP_METHOD_TIMEOUT_MS || '60000', 10); +const SUB_TIMEOUT_MS = parseInt(process.env.DDP_SUB_TIMEOUT_MS || '15000', 10); + +function toWebsocket(httpUrl) { + const trimmed = httpUrl.endsWith('/') ? httpUrl.slice(0, -1) : httpUrl; + if (trimmed.startsWith('ws')) { + return trimmed.endsWith('/websocket') ? trimmed : `${trimmed}/websocket`; + } + const converted = trimmed.replace(/^http/i, 'ws'); + return `${converted}/websocket`; +} + +class DdpClient { + constructor({ endpoint = DEFAULT_DDP_ENDPOINT, connectTimeout = CONNECT_TIMEOUT_MS, methodTimeout = METHOD_TIMEOUT_MS, subTimeout = SUB_TIMEOUT_MS } = {}) { + this.endpoint = endpoint; + this.connectTimeout = connectTimeout; + this.methodTimeout = methodTimeout; + this.subTimeout = subTimeout; + this.ws = null; + this.session = null; + this.methodId = 0; + this.subId = 0; + this.pendingMethods = new Map(); + this.pendingSubs = new Map(); + this.connectingPromise = null; + this._boundHandleMessage = this._handleMessage.bind(this); + } + + async connect() { + if (this.ws && this.ws.readyState === WebSocket.OPEN) { + return this.session; + } + if (this.connectingPromise) { + return this.connectingPromise; + } + this.connectingPromise = new Promise((resolve, reject) => { + const ws = new WebSocket(this.endpoint, { handshakeTimeout: this.connectTimeout }); + let settled = false; + + const cleanup = () => { + ws.off('open', onOpen); + ws.off('message', onMessage); + ws.off('error', onError); + ws.off('close', onClose); + }; + + const onOpen = () => { + ws.send(JSON.stringify({ + msg: 'connect', + version: '1', + support: ['1', 'pre2', 'pre1'], + })); + }; + + const onMessage = (data) => { + try { + const payload = JSON.parse(data.toString()); + if (payload.msg === 'connected') { + this.session = payload.session; + ws.off('message', onMessage); + ws.on('message', this._boundHandleMessage); + settled = true; + cleanup(); + resolve(this.session); + return; + } + if (payload.msg === 'failed') { + settled = true; + cleanup(); + reject(new Error(`DDP connection failed: ${payload.reason || payload.version || 'unknown reason'}`)); + return; + } + this._dispatch(payload); + } catch (err) { + // Ignore malformed payloads but ensure connection eventually closes + console.warn('DDP message parse error', err); + } + }; + + const onError = (err) => { + if (!settled) { + settled = true; + cleanup(); + reject(err); + } + }; + + const onClose = () => { + ws.off('message', this._boundHandleMessage); + this._rejectAllPending(new Error('DDP connection closed')); + if (!settled) { + settled = true; + cleanup(); + reject(new Error('DDP connection closed before handshake')); + } + }; + + ws.on('open', onOpen); + ws.on('message', onMessage); + ws.on('error', onError); + ws.on('close', onClose); + + this.ws = ws; + }); + + try { + await this.connectingPromise; + return this.session; + } finally { + this.connectingPromise = null; + } + } + + async disconnect() { + if (this.ws) { + this.ws.off('message', this._boundHandleMessage); + if (this.ws.readyState === WebSocket.OPEN || this.ws.readyState === WebSocket.CONNECTING) { + this.ws.close(); + } + } + this._rejectAllPending(new Error('DDP client disconnected')); + this.ws = null; + this.session = null; + } + + _handleMessage(data) { + try { + const payload = JSON.parse(data.toString()); + this._dispatch(payload); + } catch (err) { + console.warn('DDP message parse error', err); + } + } + + async call(method, params = {}) { + await this.connect(); + const id = (this.methodId += 1).toString(); + + const payload = { + msg: 'method', + method, + params: [params], + id, + }; + + const pendingPromise = new Promise((resolve, reject) => { + const timeoutHandle = setTimeout(() => { + this.pendingMethods.delete(id); + reject(new Error(`Method ${method} timed out after ${this.methodTimeout}ms`)); + }, this.methodTimeout); + + this.pendingMethods.set(id, { resolve, reject, timeoutHandle }); + }); + + this.ws.send(JSON.stringify(payload)); + return pendingPromise; + } + + async subscribe(name, params = []) { + await this.connect(); + const id = (this.subId += 1).toString(); + + const payload = { + msg: 'sub', + id, + name, + params, + }; + + const pendingPromise = new Promise((resolve, reject) => { + const timeoutHandle = setTimeout(() => { + this.pendingSubs.delete(id); + reject(new Error(`Subscription ${name} timed out after ${this.subTimeout}ms`)); + }, this.subTimeout); + + this.pendingSubs.set(id, { resolve, reject, timeoutHandle }); + }); + + this.ws.send(JSON.stringify(payload)); + return pendingPromise; + } + + async unsubscribe(id) { + if (!this.ws || this.ws.readyState !== WebSocket.OPEN) { + return; + } + this.ws.send(JSON.stringify({ msg: 'unsub', id })); + } + + _dispatch(message) { + switch (message.msg) { + case 'result': { + const pending = this.pendingMethods.get(message.id); + if (pending) { + clearTimeout(pending.timeoutHandle); + this.pendingMethods.delete(message.id); + if (message.error) { + pending.reject(new Error(message.error.reason || message.error.message || 'DDP method error')); + } else { + pending.resolve(message.result); + } + } + break; + } + case 'updated': { + // No-op: method updated notifications are not required for this client + break; + } + case 'ready': { + if (!Array.isArray(message.subs)) { + break; + } + message.subs.forEach((subId) => { + const pending = this.pendingSubs.get(subId); + if (pending) { + clearTimeout(pending.timeoutHandle); + this.pendingSubs.delete(subId); + pending.resolve(subId); + } + }); + break; + } + case 'nosub': { + const pending = this.pendingSubs.get(message.id); + if (pending) { + clearTimeout(pending.timeoutHandle); + this.pendingSubs.delete(message.id); + if (message.error) { + pending.reject(new Error(message.error.reason || message.error.message || 'DDP nosub error')); + } else { + pending.reject(new Error('Subscription cancelled by server')); + } + } + break; + } + case 'ping': { + const payload = { msg: 'pong' }; + if (message.id) { + payload.id = message.id; + } + if (this.ws && this.ws.readyState === WebSocket.OPEN) { + this.ws.send(JSON.stringify(payload)); + } + break; + } + default: { + // DDP will stream document diffs as added/changed/removed messages. For this stress + // client we do not hydrate a minimongo cache, so consuming the payloads would be work + // with no benefit. Discarding them keeps the client lightweight while still forcing + // the server to produce the same workload it would for a real UI. + break; + } + } + } + + _rejectAllPending(err) { + this.pendingMethods.forEach(({ reject, timeoutHandle }) => { + clearTimeout(timeoutHandle); + reject(err); + }); + this.pendingMethods.clear(); + + this.pendingSubs.forEach(({ reject, timeoutHandle }) => { + clearTimeout(timeoutHandle); + reject(err); + }); + this.pendingSubs.clear(); + } +} + +async function addAndRemoveTasks({ client, reactive = true, taskCount, manageSubscription = true }) { + const count = Number.isFinite(taskCount) ? taskCount : parseInt(process.env.TASK_COUNT || '20', 10); + const sessionId = randomUUID(); + const createdTaskIds = []; + const managedSubscriptionIds = []; + + if (reactive && manageSubscription) { + try { + const subscriptionId = await client.subscribe('fetchTasks'); + if (subscriptionId) { + managedSubscriptionIds.push(subscriptionId); + } + } catch (err) { + console.warn('Failed to subscribe to fetchTasks publication', err); + } + } + + await client.call('removeAllTasks', { sessionId }); + + for (let index = 1; index <= count; index += 1) { + const description = `New Task ${index}`; + const taskId = await client.call('insertTask', { sessionId, description }); + if (taskId) { + createdTaskIds.push(taskId); + } + if (!reactive) { + await client.call('fetchTasks'); + } + } + + while (createdTaskIds.length) { + const nextTaskId = createdTaskIds.shift(); + await client.call('removeTask', { taskId: nextTaskId }); + if (!reactive) { + await client.call('fetchTasks'); + } + } + + await client.call('removeAllTasks', { sessionId }); + + if (reactive && manageSubscription && managedSubscriptionIds.length) { + await Promise.all(managedSubscriptionIds.map(async (id) => { + try { + await client.unsubscribe(id); + } catch (err) { + console.warn(`Failed to unsubscribe fetchTasks (${id})`, err); + } + })); + } +} + +async function beforeScenario(context) { + context.vars = context.vars || {}; + const existingClient = context?.vars?.ddpClient; + if (existingClient) { + try { + await existingClient.connect(); + return; + } catch (err) { + console.warn('Existing DDP client unusable, creating a new one', err); + } + } + + const client = new DdpClient({ endpoint: DEFAULT_DDP_ENDPOINT }); + await client.connect(); + context.vars.ddpClient = client; +} + +async function afterScenario(context) { + if (!context?.vars) { + return; + } + const { ddpClient } = context.vars; + if (ddpClient) { + await ddpClient.disconnect(); + context.vars.ddpClient = null; + } +} + +async function reactiveMultiPubSubTasksDdp(context) { + const { ddpClient } = context.vars; + const subsPerClient = Math.max(1, parseInt(process.env.SUBSCRIPTIONS_PER_CLIENT || '5', 10)); + const reactiveRounds = Math.max(1, parseInt(process.env.o || '1', 10)); + const includeNonReactive = (process.env.INCLUDE_NON_REACTIVE || 'true').toLowerCase() !== 'false'; + const nonReactiveRounds = Math.max(1, parseInt(process.env.NON_REACTIVE_ROUNDS || '1', 10)); + const managedSubscriptions = []; + + for (let index = 0; index < subsPerClient; index += 1) { + try { + const subId = await ddpClient.subscribe('fetchTasks'); + if (subId) { + managedSubscriptions.push(subId); + } + } catch (err) { + console.warn(`Failed to establish subscription ${index + 1}/${subsPerClient}`, err); + } + } + + try { + for (let round = 0; round < reactiveRounds; round += 1) { + await addAndRemoveTasks({ client: ddpClient, reactive: true, manageSubscription: false }); + } + + if (includeNonReactive) { + for (let round = 0; round < nonReactiveRounds; round += 1) { + await addAndRemoveTasks({ client: ddpClient, reactive: false }); + } + } + } finally { + if (managedSubscriptions.length) { + await Promise.all(managedSubscriptions.map(async (subId) => { + try { + await ddpClient.unsubscribe(subId); + } catch (err) { + console.warn(`Failed to clean up subscription ${subId}`, err); + } + })); + } + } +} + +module.exports = { + beforeScenario, + afterScenario, + reactiveMultiPubSubTasksDdp, + addAndRemoveTasks, + DdpClient, +}; From 79c70832b789fb8f4d7cb1772e95f40e479a54b1 Mon Sep 17 00:00:00 2001 From: italo jose Date: Wed, 1 Oct 2025 16:46:53 -0300 Subject: [PATCH 2/4] add reactive stress test configuration and update scripts --- artillery/reactive-stress-server.yml | 15 +++++++++++++++ artillery/reactive-stress.yml | 7 ++++--- package.json | 5 +++-- tests/server-load-helpers.js | 8 ++++---- 4 files changed, 26 insertions(+), 9 deletions(-) create mode 100644 artillery/reactive-stress-server.yml diff --git a/artillery/reactive-stress-server.yml b/artillery/reactive-stress-server.yml new file mode 100644 index 0000000..72480d6 --- /dev/null +++ b/artillery/reactive-stress-server.yml @@ -0,0 +1,15 @@ +config: + target: ws://localhost:3000/websocket + phases: + - duration: 60 + arrivalRate: 5 + ensure: + maxErrorRate: 1 + max: 500 + processor: '../tests/server-load-helpers.js' +scenarios: + - name: Measure Task Latency (3.x) + flow: + - function: 'beforeScenario' + - function: 'reactivePubSubTasksDdp' + - function: 'afterScenario' diff --git a/artillery/reactive-stress.yml b/artillery/reactive-stress.yml index 9dbf333..7376223 100644 --- a/artillery/reactive-stress.yml +++ b/artillery/reactive-stress.yml @@ -1,8 +1,8 @@ config: target: http://localhost:3000 phases: - - duration: 60 - arrivalRate: 4 + - duration: 30 + arrivalRate: 2 name: Warm up ensure: maxErrorRate: 1 @@ -10,6 +10,7 @@ config: # Load the Playwright engine: engines: playwright: + headless: true globalTimeout: 240000 launchOptions: slowMo: 500 @@ -17,4 +18,4 @@ config: processor: '../tests/test-helpers.js' scenarios: - engine: playwright - testFunction: 'reactiveAddAndRemoveTasks' + testFunction: 'reactiveAddAndRemoveTasksWithCleanup' diff --git a/package.json b/package.json index 0597d58..fc37206 100644 --- a/package.json +++ b/package.json @@ -3,7 +3,7 @@ "version": "1.0.0", "main": "index.js", "scripts": { - "stress:ddp": "NODE_OPTIONS=\"--no-deprecation\" artillery run artillery/reactive-multi-stress-server.yml" + "stress:ddp": "NODE_OPTIONS=\"--no-deprecation\" artillery run artillery/reactive-stress-server.yml" }, "author": "", "license": "ISC", @@ -18,7 +18,8 @@ "artillery": "^2.0.17", "m": "^1.9.0", "minimist": "^1.2.8", - "pidusage": "^3.0.2" + "pidusage": "^3.0.2", + "mongodb": "^6.8.0" }, "volta": { "node": "20.16.0" diff --git a/tests/server-load-helpers.js b/tests/server-load-helpers.js index f6856d7..e9e8e01 100644 --- a/tests/server-load-helpers.js +++ b/tests/server-load-helpers.js @@ -353,11 +353,11 @@ async function afterScenario(context) { } } -async function reactiveMultiPubSubTasksDdp(context) { +async function reactivePubSubTasksDdp(context) { const { ddpClient } = context.vars; const subsPerClient = Math.max(1, parseInt(process.env.SUBSCRIPTIONS_PER_CLIENT || '5', 10)); const reactiveRounds = Math.max(1, parseInt(process.env.o || '1', 10)); - const includeNonReactive = (process.env.INCLUDE_NON_REACTIVE || 'true').toLowerCase() !== 'false'; + const includeNonReactive = (process.env.INCLUDE_NON_REACTIVE || 'false').toLowerCase() !== 'false'; const nonReactiveRounds = Math.max(1, parseInt(process.env.NON_REACTIVE_ROUNDS || '1', 10)); const managedSubscriptions = []; @@ -398,7 +398,7 @@ async function reactiveMultiPubSubTasksDdp(context) { module.exports = { beforeScenario, afterScenario, - reactiveMultiPubSubTasksDdp, + reactivePubSubTasksDdp, addAndRemoveTasks, DdpClient, -}; +}; \ No newline at end of file From 6e44c4ce30b38a6ed64a63af39173eb0492bff40 Mon Sep 17 00:00:00 2001 From: italo jose Date: Wed, 1 Oct 2025 17:39:46 -0300 Subject: [PATCH 3/4] add database cleanup functionality and refactor reactive task handling --- artillery/reactive-multi-stress-server.yml | 15 -------- tests/test-helpers.js | 44 ++++++++++++++++++++++ 2 files changed, 44 insertions(+), 15 deletions(-) delete mode 100644 artillery/reactive-multi-stress-server.yml diff --git a/artillery/reactive-multi-stress-server.yml b/artillery/reactive-multi-stress-server.yml deleted file mode 100644 index 6b3935f..0000000 --- a/artillery/reactive-multi-stress-server.yml +++ /dev/null @@ -1,15 +0,0 @@ -config: - target: ws://localhost:3000/websocket - phases: - - duration: 60 - arrivalRate: 5 - ensure: - maxErrorRate: 1 - max: 500 - processor: '../tests/server-load-helpers.js' -scenarios: - - name: Reactive Multi Pub/Sub DDP - flow: - - function: 'beforeScenario' - - function: 'reactiveMultiPubSubTasksDdp' - - function: 'afterScenario' diff --git a/tests/test-helpers.js b/tests/test-helpers.js index e88d35e..de9fba6 100644 --- a/tests/test-helpers.js +++ b/tests/test-helpers.js @@ -1,4 +1,37 @@ const timeout = 120000; +let _mongoClient = null; +let _mongoDb = null; + +async function getMongoDb() { + if (_mongoDb) return _mongoDb; + const { MongoClient } = require('mongodb'); + const url = process.env.MONGO_URL || 'mongodb://127.0.0.1:3001/meteor'; + // Meteor default db name is the path part of the URL (meteor) if not specified + // We let driver parse it. + _mongoClient = new MongoClient(url, { maxPoolSize: 2 }); + await _mongoClient.connect(); + _mongoDb = _mongoClient.db(); + return _mongoDb; +} + +async function cleanDatabase({ collectionName = 'taskCollection', maxRetries = 3 } = {}) { + let attempt = 0; + const db = await getMongoDb(); + while (attempt < maxRetries) { + attempt += 1; + try { + const col = db.collection(collectionName); + await col.deleteMany({}); + return true; + } catch (err) { + if (attempt >= maxRetries) { + console.warn(`Failed to clean collection ${collectionName} after ${attempt} attempts`, err); + return false; + } + await new Promise(r => setTimeout(r, 250 * attempt)); + } + } +} const addAndRemoveTasks = async ({ page, reactive, taskCount }) => { page.setDefaultTimeout(timeout); @@ -32,6 +65,15 @@ async function reactiveAddAndRemoveTasks(page) { await addAndRemoveTasks({ page, reactive: true, taskCount }); } +async function reactiveAddAndRemoveTasksWithCleanup(page) { + try { + await cleanDatabase(); + } catch (err) { + console.warn('Database cleanup encountered an error (continuing with test)', err); + } + await reactiveAddAndRemoveTasks(page); +} + async function nonReactiveAddAndRemoveTasks(page) { const taskCount = parseFloat(process.env.TASK_COUNT || 20); await addAndRemoveTasks({ page, reactive: false, taskCount }); @@ -41,4 +83,6 @@ module.exports = { reactiveAddAndRemoveTasks, nonReactiveAddAndRemoveTasks, addAndRemoveTasks, + reactiveAddAndRemoveTasksWithCleanup, + cleanDatabase, } From 46117a3868b6a376f0f20612f4dc9dae5ff051ed Mon Sep 17 00:00:00 2001 From: italo jose Date: Thu, 2 Oct 2025 16:50:33 -0300 Subject: [PATCH 4/4] Add performance monitoring scripts and logs for MongoDB replica sets - Created `monitor-replicaset.sh` script to manage and monitor Meteor app and MongoDB replica sets. - Added logging for CPU and memory usage of the app and replicas. - Implemented environment variable loading and logging for better configuration management. - Introduced `pooling.log` to capture detailed performance metrics during load testing. - Added `summary.md` to summarize CPU and memory usage results for different scenarios. --- apps/tasks-3.x/settings.json | 12 + artillery/reactive-stress-server.yml | 2 +- logs/changeStreams.log | 325 ++++++++++++++++++++++ logs/events.log | 325 ++++++++++++++++++++++ logs/oplog.log | 325 ++++++++++++++++++++++ logs/pooling.log | 325 ++++++++++++++++++++++ logs/summary.md | 42 +++ scripts/monitor-replicaset.sh | 394 +++++++++++++++++++++++++++ 8 files changed, 1749 insertions(+), 1 deletion(-) create mode 100644 apps/tasks-3.x/settings.json create mode 100644 logs/changeStreams.log create mode 100644 logs/events.log create mode 100644 logs/oplog.log create mode 100644 logs/pooling.log create mode 100644 logs/summary.md create mode 100755 scripts/monitor-replicaset.sh diff --git a/apps/tasks-3.x/settings.json b/apps/tasks-3.x/settings.json new file mode 100644 index 0000000..44e92c6 --- /dev/null +++ b/apps/tasks-3.x/settings.json @@ -0,0 +1,12 @@ +{ + "packages": { + "mongo": { + "reactivity": { + "eventEmitter": false, + "changeStreams": false, + "oplog": false, + "pooling": true + } + } + } +} \ No newline at end of file diff --git a/artillery/reactive-stress-server.yml b/artillery/reactive-stress-server.yml index 72480d6..096b68a 100644 --- a/artillery/reactive-stress-server.yml +++ b/artillery/reactive-stress-server.yml @@ -2,7 +2,7 @@ config: target: ws://localhost:3000/websocket phases: - duration: 60 - arrivalRate: 5 + arrivalRate: 15 ensure: maxErrorRate: 1 max: 500 diff --git a/logs/changeStreams.log b/logs/changeStreams.log new file mode 100644 index 0000000..8da4239 --- /dev/null +++ b/logs/changeStreams.log @@ -0,0 +1,325 @@ +=============================== + Artillery Configuration - Thu Oct 2 15:52:45 -03 2025 +=============================== +config: + target: ws://localhost:3000/websocket + phases: + - duration: 60 + arrivalRate: 15 + ensure: + maxErrorRate: 1 + max: 500 + processor: '../tests/server-load-helpers.js' +scenarios: + - name: Measure Task Latency (3.x) + flow: + - function: 'beforeScenario' + - function: 'reactivePubSubTasksDdp' + - function: 'afterScenario' +=============================== +=============================== + Environment Variables - Thu Oct 2 15:52:45 -03 2025 +=============================== +MONGO_URL = mongodb://localhost:27017,localhost:27018,localhost:27019/?replicaSet=rs0 +MONGO_OPLOG_URL = mongodb://localhost:27017,localhost:27018,localhost:27019/local?replicaSet=rs0 +MONTI_APP_ID = Z6A9yDhJQeaCYbjrg +MONTI_APP_SECRET = b2427f56-45b6-40ae-9eba-c9c2fa079dd0 +ENABLE_APM = 1 +METEOR_CHECKOUT_PATH = /Users/italojose/dev/meteor-dev/meteor +SKIP_KILL_CONTAINERS = +GALAXY_API_KEY = +GALAXY_TOKEN = +=============================== +Dropping 'test' database before running benchmarks... +'test' database dropped successfully. + +Changes to your project's package version selections: + +apm-agent added, version 0.0.1 +montiapm:agent+ added, version 3.0.0-beta.16 +montiapm:agent-binary-deps added, version 3.0.0 +montiapm:meteorx added, version 2.3.1 +montiapm:profiler+ added, version 1.7.0-beta.3 +zodern:meteor-package-versions added, version 0.2.2 +zodern:types added, version 1.0.13 + + ++ In order to resolve constraints, we had to use experimental versions of +these +packages. + +apm-agent +=============================== + Meteor checkout version - 3c7c7c6c3a2ee19c00047beeedf494898b6d6939 +=============================== +=> Running Meteor from a checkout -- overrides project version (Meteor 3.0.2) +[[[[[ ~/dev/meteor-dev/performance/apps/tasks-3.x ]]]]] + +=> Started proxy. +=> Started HMR server. + +Changes to your project's package version selections: + +allow-deny upgraded from 2.0.0 to 2.1.0 +autoupdate upgraded from 2.0.0 to 2.0.1 +babel-compiler upgraded from 7.11.0 to 7.12.2 +blaze-tools removed from your project +boilerplate-generator upgraded from 2.0.0 to 2.0.2 +caching-compiler upgraded from 2.0.0 to 2.0.1 +caching-html-compiler removed from your project +callback-hook upgraded from 1.6.0 to 1.6.1 +check upgraded from 1.4.2 to 1.4.4 +ddp-client upgraded from 3.0.1 to 3.1.1 +ddp-server upgraded from 3.0.1 to 3.1.2 +ecmascript upgraded from 0.16.9 to 0.16.13 +ecmascript-runtime upgraded from 0.8.2 to 0.8.3 +ecmascript-runtime-client upgraded from 0.12.2 to 0.12.3 +ejson upgraded from 1.1.4 to 1.1.5 +fetch upgraded from 0.1.5 to 0.1.6 +html-tools removed from your project +htmljs removed from your project +logging upgraded from 1.3.5 to 1.3.6 +meteor upgraded from 2.0.1 to 2.1.1 +minifier-css upgraded from 2.0.0 to 2.0.1 +minifier-js upgraded from 3.0.0 to 3.0.4 +minimongo upgraded from 2.0.1 to 2.0.4 +modern-browsers upgraded from 0.1.11 to 0.2.3 +modules upgraded from 0.20.1 to 0.20.3 +mongo upgraded from 2.0.1 to 2.1.4 +mongo-decimal upgraded from 0.1.4-beta300.7 to 0.2.0 +npm-mongo* upgraded from 4.17.4 to 6.16.1 +shell-server upgraded from 0.6.0 to 0.6.2 +socket-stream-client upgraded from 0.5.3 to 0.6.1 +spacebars-compiler removed from your project +standard-minifier-js upgraded from 3.0.0 to 3.1.1 +static-html upgraded from 1.3.3 to 1.4.0 +static-html-tools added, version 1.0.0 +templating-tools removed from your project +typescript upgraded from 5.4.3 to 5.6.6 +webapp upgraded from 2.0.1 to 2.0.7 + + +* These packages have been updated to new versions that are not backwards +compatible. +W20251002-15:53:08.603(-3)? (STDERR) Deprecation warnings are hidden but crucial to address for future Meteor updates. +W20251002-15:53:08.608(-3)? (STDERR) Remove the `METEOR_NO_DEPRECATION` env var to reveal them, then report or fix the issues. +I20251002-15:53:08.713(-3)? ✅ Using PollingObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_K4yghiJKTAyXjD3en","selector":{},"options":{"transform":null}} +I20251002-15:53:08.716(-3)? ✅ Using PollingObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_K4yghiJKTAyXjD3en","selector":{},"options":{"transform":null,"limit":20,"_disableOplog":true}} +I20251002-15:53:08.718(-3)? ✅ Using ChangeStreamObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_K4yghiJKTAyXjD3en","selector":{},"options":{"transform":null}} +=> Started your app. + +=> App running at: http://localhost:3000/ +APP PID: 8941 +Replica node localhost:27017 PID: 49803 +I20251002-15:53:08.931(-3)? Monti APM: Connected +Replica node localhost:27018 PID: 49806 +Replica node localhost:27019 PID: 49817 +Replica PIDs: 49803 49806 49817 +Monitor CpuRam APP Pid 8980 +Monitor CpuRam REPLICA_localhost_27017 Pid 8986 +Monitor CpuRam REPLICA_localhost_27018 Pid 8987 +Monitor CpuRam REPLICA_localhost_27019 Pid 8988 +Test run id: txw3e_w7nhrz8adtgbzeehdjh9j49gh8gr5_mhhy +REPLICA_localhost_27017 | Cpu 1.250859296426874 Memory 371818496 +REPLICA_localhost_27019 | Cpu 1.3933576480990273 Memory 355287040 +APP | Cpu 40.5 Memory 175194112 +REPLICA_localhost_27018 | Cpu 1.2959295321669742 Memory 369524736 +Phase started: unnamed (index: 0, duration: 60s) 15:53:10(-0300) + +I20251002-15:53:11.321(-3)? ✅ Using ChangeStreamObserveDriver for {"ordered":false,"collectionName":"taskCollection","selector":{},"options":{"transform":null}} +APP | Cpu 52 Memory 402866176 +REPLICA_localhost_27018 | Cpu 19 Memory 367460352 +REPLICA_localhost_27019 | Cpu 36 Memory 387973120 +REPLICA_localhost_27017 | Cpu 18 Memory 369426432 +-------------------------------------- +Metrics for period to: 15:53:20(-0300) (width: 8.685s) +-------------------------------------- + +vusers.completed: .............................................................. 116 +vusers.created: ................................................................ 128 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 128 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 808.1 + max: ......................................................................... 2479.3 + mean: ........................................................................ 1081.2 + median: ...................................................................... 871.5 + p95: ......................................................................... 1863.5 + p99: ......................................................................... 2369 + + +APP | Cpu 42 Memory 449200128 +REPLICA_localhost_27018 | Cpu 17 Memory 375537664 +REPLICA_localhost_27019 | Cpu 30 Memory 387366912 +REPLICA_localhost_27017 | Cpu 16 Memory 369360896 +-------------------------------------- +Metrics for period to: 15:53:30(-0300) (width: 9.973s) +-------------------------------------- + +vusers.completed: .............................................................. 151 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 791.7 + max: ......................................................................... 1003.2 + mean: ........................................................................ 890.9 + median: ...................................................................... 889.1 + p95: ......................................................................... 982.6 + p99: ......................................................................... 1002.4 + + +REPLICA_localhost_27018 | Cpu 18 Memory 375324672 +APP | Cpu 43 Memory 448135168 +REPLICA_localhost_27019 | Cpu 35 Memory 386793472 +REPLICA_localhost_27017 | Cpu 18 Memory 370130944 +-------------------------------------- +Metrics for period to: 15:53:40(-0300) (width: 9.958s) +-------------------------------------- + +vusers.completed: .............................................................. 150 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 791.5 + max: ......................................................................... 947.7 + mean: ........................................................................ 846.7 + median: ...................................................................... 837.3 + p95: ......................................................................... 925.4 + p99: ......................................................................... 944 + + +APP | Cpu 50 Memory 447594496 +REPLICA_localhost_27018 | Cpu 19 Memory 376061952 +REPLICA_localhost_27019 | Cpu 39 Memory 387137536 +REPLICA_localhost_27017 | Cpu 18 Memory 370737152 +-------------------------------------- +Metrics for period to: 15:53:50(-0300) (width: 9.992s) +-------------------------------------- + +vusers.completed: .............................................................. 149 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 812.3 + max: ......................................................................... 905.8 + mean: ........................................................................ 857.5 + median: ...................................................................... 854.2 + p95: ......................................................................... 889.1 + p99: ......................................................................... 889.1 + + +REPLICA_localhost_27018 | Cpu 16 Memory 376160256 +APP | Cpu 42 Memory 447987712 +REPLICA_localhost_27019 | Cpu 36 Memory 388759552 +REPLICA_localhost_27017 | Cpu 15 Memory 370589696 +-------------------------------------- +Metrics for period to: 15:54:00(-0300) (width: 9.983s) +-------------------------------------- + +vusers.completed: .............................................................. 151 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 802.9 + max: ......................................................................... 966.1 + mean: ........................................................................ 868.8 + median: ...................................................................... 854.2 + p95: ......................................................................... 944 + p99: ......................................................................... 963.1 + + +APP | Cpu 46 Memory 448102400 +REPLICA_localhost_27019 | Cpu 35 Memory 389562368 +REPLICA_localhost_27018 | Cpu 17 Memory 377896960 +REPLICA_localhost_27017 | Cpu 16 Memory 370212864 +Phase completed: unnamed (index: 0, duration: 60s) 15:54:10(-0300) + +-------------------------------------- +Metrics for period to: 15:54:10(-0300) (width: 9.973s) +-------------------------------------- + +vusers.completed: .............................................................. 150 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 788.1 + max: ......................................................................... 907.5 + mean: ........................................................................ 845.4 + median: ...................................................................... 837.3 + p95: ......................................................................... 889.1 + p99: ......................................................................... 907 + + +-------------------------------------- +Metrics for period to: 15:54:20(-0300) (width: 2.031s) +-------------------------------------- + +vusers.completed: .............................................................. 33 +vusers.created: ................................................................ 22 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 22 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 725.6 + max: ......................................................................... 844.3 + mean: ........................................................................ 805.2 + median: ...................................................................... 804.5 + p95: ......................................................................... 837.3 + p99: ......................................................................... 837.3 + + +All VUs finished. Total time: 1 minute, 2 seconds + +-------------------------------- +Summary report @ 15:54:14(-0300) +-------------------------------- + +vusers.completed: .............................................................. 900 +vusers.created: ................................................................ 900 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 900 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 725.6 + max: ......................................................................... 2479.3 + mean: ........................................................................ 888.1 + median: ...................................................................... 854.2 + p95: ......................................................................... 982.6 + p99: ......................................................................... 1720.2 + +Changes to your project's package version selections: + +apm-agent removed from your project +montiapm:agent removed from your project +montiapm:agent-binary-deps removed from your project +montiapm:meteorx removed from your project +montiapm:profiler removed from your project +zodern:meteor-package-versions removed from your project +zodern:types removed from your project + +apm-agent: removed dependency +---------- +APP +Average CPU usage (%): 42.85 +Average Memory usage (bytes): 422 MB +---------- +---------- +REPLICA_localhost_27017 +Average CPU usage (%): 15.00 +Average Memory usage (bytes): 370 MB +---------- +---------- +REPLICA_localhost_27018 +Average CPU usage (%): 15.28 +Average Memory usage (bytes): 374 MB +---------- +---------- +REPLICA_localhost_27019 +Average CPU usage (%): 31.15 +Average Memory usage (bytes): 386 MB +---------- +Output is suitable for comparisons (logs/oplog-server-tasks-3.x-reactive-stress-server.yml.log) + Replicaset managed the configuration correctly. diff --git a/logs/events.log b/logs/events.log new file mode 100644 index 0000000..54f874d --- /dev/null +++ b/logs/events.log @@ -0,0 +1,325 @@ +=============================== + Artillery Configuration - Thu Oct 2 16:00:09 -03 2025 +=============================== +config: + target: ws://localhost:3000/websocket + phases: + - duration: 60 + arrivalRate: 15 + ensure: + maxErrorRate: 1 + max: 500 + processor: '../tests/server-load-helpers.js' +scenarios: + - name: Measure Task Latency (3.x) + flow: + - function: 'beforeScenario' + - function: 'reactivePubSubTasksDdp' + - function: 'afterScenario' +=============================== +=============================== + Environment Variables - Thu Oct 2 16:00:09 -03 2025 +=============================== +MONGO_URL = mongodb://localhost:27017,localhost:27018,localhost:27019/?replicaSet=rs0 +MONGO_OPLOG_URL = mongodb://localhost:27017,localhost:27018,localhost:27019/local?replicaSet=rs0 +MONTI_APP_ID = Z6A9yDhJQeaCYbjrg +MONTI_APP_SECRET = b2427f56-45b6-40ae-9eba-c9c2fa079dd0 +ENABLE_APM = 1 +METEOR_CHECKOUT_PATH = /Users/italojose/dev/meteor-dev/meteor +SKIP_KILL_CONTAINERS = +GALAXY_API_KEY = +GALAXY_TOKEN = +=============================== +Dropping 'test' database before running benchmarks... +'test' database dropped successfully. + +Changes to your project's package version selections: + +apm-agent added, version 0.0.1 +montiapm:agent+ added, version 3.0.0-beta.16 +montiapm:agent-binary-deps added, version 3.0.0 +montiapm:meteorx added, version 2.3.1 +montiapm:profiler+ added, version 1.7.0-beta.3 +zodern:meteor-package-versions added, version 0.2.2 +zodern:types added, version 1.0.13 + + ++ In order to resolve constraints, we had to use experimental versions of +these +packages. + +apm-agent +=============================== + Meteor checkout version - 3c7c7c6c3a2ee19c00047beeedf494898b6d6939 +=============================== +=> Running Meteor from a checkout -- overrides project version (Meteor 3.0.2) +[[[[[ ~/dev/meteor-dev/performance/apps/tasks-3.x ]]]]] + +=> Started proxy. +=> Started HMR server. + +Changes to your project's package version selections: + +allow-deny upgraded from 2.0.0 to 2.1.0 +autoupdate upgraded from 2.0.0 to 2.0.1 +babel-compiler upgraded from 7.11.0 to 7.12.2 +blaze-tools removed from your project +boilerplate-generator upgraded from 2.0.0 to 2.0.2 +caching-compiler upgraded from 2.0.0 to 2.0.1 +caching-html-compiler removed from your project +callback-hook upgraded from 1.6.0 to 1.6.1 +check upgraded from 1.4.2 to 1.4.4 +ddp-client upgraded from 3.0.1 to 3.1.1 +ddp-server upgraded from 3.0.1 to 3.1.2 +ecmascript upgraded from 0.16.9 to 0.16.13 +ecmascript-runtime upgraded from 0.8.2 to 0.8.3 +ecmascript-runtime-client upgraded from 0.12.2 to 0.12.3 +ejson upgraded from 1.1.4 to 1.1.5 +fetch upgraded from 0.1.5 to 0.1.6 +html-tools removed from your project +htmljs removed from your project +logging upgraded from 1.3.5 to 1.3.6 +meteor upgraded from 2.0.1 to 2.1.1 +minifier-css upgraded from 2.0.0 to 2.0.1 +minifier-js upgraded from 3.0.0 to 3.0.4 +minimongo upgraded from 2.0.1 to 2.0.4 +modern-browsers upgraded from 0.1.11 to 0.2.3 +modules upgraded from 0.20.1 to 0.20.3 +mongo upgraded from 2.0.1 to 2.1.4 +mongo-decimal upgraded from 0.1.4-beta300.7 to 0.2.0 +npm-mongo* upgraded from 4.17.4 to 6.16.1 +shell-server upgraded from 0.6.0 to 0.6.2 +socket-stream-client upgraded from 0.5.3 to 0.6.1 +spacebars-compiler removed from your project +standard-minifier-js upgraded from 3.0.0 to 3.1.1 +static-html upgraded from 1.3.3 to 1.4.0 +static-html-tools added, version 1.0.0 +templating-tools removed from your project +typescript upgraded from 5.4.3 to 5.6.6 +webapp upgraded from 2.0.1 to 2.0.7 + + +* These packages have been updated to new versions that are not backwards +compatible. +W20251002-16:00:31.893(-3)? (STDERR) Deprecation warnings are hidden but crucial to address for future Meteor updates. +W20251002-16:00:31.899(-3)? (STDERR) Remove the `METEOR_NO_DEPRECATION` env var to reveal them, then report or fix the issues. +I20251002-16:00:32.007(-3)? ✅ Using EventObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_TRtKvTf2TWxx5scfF","selector":{},"options":{"transform":null}} +I20251002-16:00:32.010(-3)? ✅ Using PollingObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_TRtKvTf2TWxx5scfF","selector":{},"options":{"transform":null,"limit":20,"_disableOplog":true}} +I20251002-16:00:32.011(-3)? ✅ Using EventObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_TRtKvTf2TWxx5scfF","selector":{},"options":{"transform":null}} +=> Started your app. + +=> App running at: http://localhost:3000/ +APP PID: 13121 +Replica node localhost:27017 PID: 49803 +Replica node localhost:27018 PID: 49806 +Replica node localhost:27019 PID: 49817 +Replica PIDs: 49803 49806 49817 +Monitor CpuRam APP Pid 13160 +Monitor CpuRam REPLICA_localhost_27017 Pid 13166 +Monitor CpuRam REPLICA_localhost_27018 Pid 13167 +Monitor CpuRam REPLICA_localhost_27019 Pid 13168 +I20251002-16:00:32.336(-3)? Monti APM: Connected +Test run id: tty6k_qgg488wp8dhnnhph4kn5rjqd7xbmc_k4cq +APP | Cpu 40 Memory 172277760 +REPLICA_localhost_27017 | Cpu 1.2609652017069202 Memory 375013376 +REPLICA_localhost_27018 | Cpu 1.3062227794641679 Memory 384581632 +REPLICA_localhost_27019 | Cpu 1.4194538235649945 Memory 394477568 +Phase started: unnamed (index: 0, duration: 60s) 16:00:33(-0300) + +I20251002-16:00:34.467(-3)? ✅ Using EventObserveDriver for {"ordered":false,"collectionName":"taskCollection","selector":{},"options":{"transform":null}} +APP | Cpu 56.00000000000001 Memory 324337664 +REPLICA_localhost_27018 | Cpu 25 Memory 386007040 +REPLICA_localhost_27017 | Cpu 25 Memory 376487936 +REPLICA_localhost_27019 | Cpu 45 Memory 399261696 +-------------------------------------- +Metrics for period to: 16:00:40(-0300) (width: 5.499s) +-------------------------------------- + +vusers.completed: .............................................................. 69 +vusers.created: ................................................................ 80 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 80 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 665.3 + max: ......................................................................... 827.9 + mean: ........................................................................ 748.4 + median: ...................................................................... 757.6 + p95: ......................................................................... 804.5 + p99: ......................................................................... 820.7 + + +APP | Cpu 48 Memory 404357120 +REPLICA_localhost_27017 | Cpu 24 Memory 377257984 +REPLICA_localhost_27018 | Cpu 25 Memory 386334720 +REPLICA_localhost_27019 | Cpu 45 Memory 401162240 +-------------------------------------- +Metrics for period to: 16:00:50(-0300) (width: 9.968s) +-------------------------------------- + +vusers.completed: .............................................................. 152 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 671.7 + max: ......................................................................... 826.6 + mean: ........................................................................ 730.2 + median: ...................................................................... 727.9 + p95: ......................................................................... 804.5 + p99: ......................................................................... 820.7 + + +APP | Cpu 44 Memory 403701760 +REPLICA_localhost_27017 | Cpu 22 Memory 377913344 +REPLICA_localhost_27018 | Cpu 22 Memory 386662400 +REPLICA_localhost_27019 | Cpu 40 Memory 401784832 +-------------------------------------- +Metrics for period to: 16:01:00(-0300) (width: 9.997s) +-------------------------------------- + +vusers.completed: .............................................................. 151 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 647.6 + max: ......................................................................... 821.2 + mean: ........................................................................ 714.7 + median: ...................................................................... 713.5 + p95: ......................................................................... 788.5 + p99: ......................................................................... 788.5 + + +APP | Cpu 44 Memory 403881984 +REPLICA_localhost_27018 | Cpu 24 Memory 387579904 +REPLICA_localhost_27017 | Cpu 24 Memory 379207680 +REPLICA_localhost_27019 | Cpu 42 Memory 402751488 +-------------------------------------- +Metrics for period to: 16:01:10(-0300) (width: 9.993s) +-------------------------------------- + +vusers.completed: .............................................................. 150 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 618.9 + max: ......................................................................... 737.7 + mean: ........................................................................ 666.2 + median: ...................................................................... 658.6 + p95: ......................................................................... 713.5 + p99: ......................................................................... 727.9 + + +APP | Cpu 43 Memory 404258816 +REPLICA_localhost_27018 | Cpu 22 Memory 388251648 +REPLICA_localhost_27017 | Cpu 21 Memory 379486208 +REPLICA_localhost_27019 | Cpu 42 Memory 403390464 +-------------------------------------- +Metrics for period to: 16:01:20(-0300) (width: 9.999s) +-------------------------------------- + +vusers.completed: .............................................................. 151 +vusers.created: ................................................................ 151 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 151 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 626.6 + max: ......................................................................... 750.7 + mean: ........................................................................ 678.3 + median: ...................................................................... 671.9 + p95: ......................................................................... 727.9 + p99: ......................................................................... 742.6 + + +APP | Cpu 44 Memory 404373504 +REPLICA_localhost_27018 | Cpu 23 Memory 389283840 +REPLICA_localhost_27017 | Cpu 23 Memory 380862464 +REPLICA_localhost_27019 | Cpu 46 Memory 404275200 +Phase completed: unnamed (index: 0, duration: 60s) 16:01:33(-0300) + +-------------------------------------- +Metrics for period to: 16:01:30(-0300) (width: 9.953s) +-------------------------------------- + +vusers.completed: .............................................................. 148 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 629.9 + max: ......................................................................... 732.6 + mean: ........................................................................ 669 + median: ...................................................................... 658.6 + p95: ......................................................................... 713.5 + p99: ......................................................................... 727.9 + + +-------------------------------------- +Metrics for period to: 16:01:40(-0300) (width: 5.06s) +-------------------------------------- + +vusers.completed: .............................................................. 79 +vusers.created: ................................................................ 69 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 69 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 607.5 + max: ......................................................................... 713.5 + mean: ........................................................................ 659.2 + median: ...................................................................... 658.6 + p95: ......................................................................... 699.4 + p99: ......................................................................... 699.4 + + +All VUs finished. Total time: 1 minute, 2 seconds + +-------------------------------- +Summary report @ 16:01:37(-0300) +-------------------------------- + +vusers.completed: .............................................................. 900 +vusers.created: ................................................................ 900 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 900 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 607.5 + max: ......................................................................... 827.9 + mean: ........................................................................ 693.3 + median: ...................................................................... 685.5 + p95: ......................................................................... 772.9 + p99: ......................................................................... 804.5 + +Changes to your project's package version selections: + +apm-agent removed from your project +montiapm:agent removed from your project +montiapm:agent-binary-deps removed from your project +montiapm:meteorx removed from your project +montiapm:profiler removed from your project +zodern:meteor-package-versions removed from your project +zodern:types removed from your project + +apm-agent: removed dependency +---------- +REPLICA_localhost_27017 +Average CPU usage (%): 20.42 +Average Memory usage (bytes): 378 MB +---------- +---------- +REPLICA_localhost_27018 +Average CPU usage (%): 20.58 +Average Memory usage (bytes): 387 MB +---------- +---------- +APP +Average CPU usage (%): 43.07 +Average Memory usage (bytes): 379 MB +---------- +---------- +REPLICA_localhost_27019 +Average CPU usage (%): 38.09 +Average Memory usage (bytes): 402 MB +---------- +Output is suitable for comparisons (logs/oplog-server-tasks-3.x-reactive-stress-server.yml.log) + Replicaset managed the configuration correctly. diff --git a/logs/oplog.log b/logs/oplog.log new file mode 100644 index 0000000..6b5394a --- /dev/null +++ b/logs/oplog.log @@ -0,0 +1,325 @@ +=============================== + Artillery Configuration - Thu Oct 2 15:49:05 -03 2025 +=============================== +config: + target: ws://localhost:3000/websocket + phases: + - duration: 60 + arrivalRate: 15 + ensure: + maxErrorRate: 1 + max: 500 + processor: '../tests/server-load-helpers.js' +scenarios: + - name: Measure Task Latency (3.x) + flow: + - function: 'beforeScenario' + - function: 'reactivePubSubTasksDdp' + - function: 'afterScenario' +=============================== +=============================== + Environment Variables - Thu Oct 2 15:49:05 -03 2025 +=============================== +MONGO_URL = mongodb://localhost:27017,localhost:27018,localhost:27019/?replicaSet=rs0 +MONGO_OPLOG_URL = mongodb://localhost:27017,localhost:27018,localhost:27019/local?replicaSet=rs0 +MONTI_APP_ID = Z6A9yDhJQeaCYbjrg +MONTI_APP_SECRET = b2427f56-45b6-40ae-9eba-c9c2fa079dd0 +ENABLE_APM = 1 +METEOR_CHECKOUT_PATH = /Users/italojose/dev/meteor-dev/meteor +SKIP_KILL_CONTAINERS = +GALAXY_API_KEY = +GALAXY_TOKEN = +=============================== +Dropping 'test' database before running benchmarks... +'test' database dropped successfully. + +Changes to your project's package version selections: + +apm-agent added, version 0.0.1 +montiapm:agent+ added, version 3.0.0-beta.16 +montiapm:agent-binary-deps added, version 3.0.0 +montiapm:meteorx added, version 2.3.1 +montiapm:profiler+ added, version 1.7.0-beta.3 +zodern:meteor-package-versions added, version 0.2.2 +zodern:types added, version 1.0.13 + + ++ In order to resolve constraints, we had to use experimental versions of +these +packages. + +apm-agent +=============================== + Meteor checkout version - 3c7c7c6c3a2ee19c00047beeedf494898b6d6939 +=============================== +=> Running Meteor from a checkout -- overrides project version (Meteor 3.0.2) +[[[[[ ~/dev/meteor-dev/performance/apps/tasks-3.x ]]]]] + +=> Started proxy. +=> Started HMR server. + +Changes to your project's package version selections: + +allow-deny upgraded from 2.0.0 to 2.1.0 +autoupdate upgraded from 2.0.0 to 2.0.1 +babel-compiler upgraded from 7.11.0 to 7.12.2 +blaze-tools removed from your project +boilerplate-generator upgraded from 2.0.0 to 2.0.2 +caching-compiler upgraded from 2.0.0 to 2.0.1 +caching-html-compiler removed from your project +callback-hook upgraded from 1.6.0 to 1.6.1 +check upgraded from 1.4.2 to 1.4.4 +ddp-client upgraded from 3.0.1 to 3.1.1 +ddp-server upgraded from 3.0.1 to 3.1.2 +ecmascript upgraded from 0.16.9 to 0.16.13 +ecmascript-runtime upgraded from 0.8.2 to 0.8.3 +ecmascript-runtime-client upgraded from 0.12.2 to 0.12.3 +ejson upgraded from 1.1.4 to 1.1.5 +fetch upgraded from 0.1.5 to 0.1.6 +html-tools removed from your project +htmljs removed from your project +logging upgraded from 1.3.5 to 1.3.6 +meteor upgraded from 2.0.1 to 2.1.1 +minifier-css upgraded from 2.0.0 to 2.0.1 +minifier-js upgraded from 3.0.0 to 3.0.4 +minimongo upgraded from 2.0.1 to 2.0.4 +modern-browsers upgraded from 0.1.11 to 0.2.3 +modules upgraded from 0.20.1 to 0.20.3 +mongo upgraded from 2.0.1 to 2.1.4 +mongo-decimal upgraded from 0.1.4-beta300.7 to 0.2.0 +npm-mongo* upgraded from 4.17.4 to 6.16.1 +shell-server upgraded from 0.6.0 to 0.6.2 +socket-stream-client upgraded from 0.5.3 to 0.6.1 +spacebars-compiler removed from your project +standard-minifier-js upgraded from 3.0.0 to 3.1.1 +static-html upgraded from 1.3.3 to 1.4.0 +static-html-tools added, version 1.0.0 +templating-tools removed from your project +typescript upgraded from 5.4.3 to 5.6.6 +webapp upgraded from 2.0.1 to 2.0.7 + + +* These packages have been updated to new versions that are not backwards +compatible. +W20251002-15:49:28.475(-3)? (STDERR) Deprecation warnings are hidden but crucial to address for future Meteor updates. +W20251002-15:49:28.479(-3)? (STDERR) Remove the `METEOR_NO_DEPRECATION` env var to reveal them, then report or fix the issues. +I20251002-15:49:28.587(-3)? ✅ Using OplogObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_vZ8CumuCegaikfKxR","selector":{},"options":{"transform":null}} +I20251002-15:49:28.593(-3)? ✅ Using PollingObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_vZ8CumuCegaikfKxR","selector":{},"options":{"transform":null,"limit":20,"_disableOplog":true}} +I20251002-15:49:28.594(-3)? ✅ Using OplogObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_vZ8CumuCegaikfKxR","selector":{},"options":{"transform":null}} +=> Started your app. + +=> App running at: http://localhost:3000/ +APP PID: 4713 +Replica node localhost:27017 PID: 49803 +Replica node localhost:27018 PID: 49806 +Replica node localhost:27019 PID: 49817 +Replica PIDs: 49803 49806 49817 +I20251002-15:49:28.818(-3)? Monti APM: Connected +Monitor CpuRam APP Pid 4753 +Monitor CpuRam REPLICA_localhost_27017 Pid 4759 +Monitor CpuRam REPLICA_localhost_27018 Pid 4760 +Monitor CpuRam REPLICA_localhost_27019 Pid 4761 +Test run id: tx8hx_gq8trre6wban6cqpq9m4mm5w9th5z_e4ay +APP | Cpu 80 Memory 175063040 +REPLICA_localhost_27019 | Cpu 1.3537264981885464 Memory 338984960 +REPLICA_localhost_27017 | Cpu 1.2287613560824286 Memory 338018304 +REPLICA_localhost_27018 | Cpu 1.2739087081763794 Memory 336887808 +Phase started: unnamed (index: 0, duration: 60s) 15:49:30(-0300) + +I20251002-15:49:31.238(-3)? ✅ Using OplogObserveDriver for {"ordered":false,"collectionName":"taskCollection","selector":{},"options":{"transform":null}} +APP | Cpu 64 Memory 371752960 +REPLICA_localhost_27019 | Cpu 56.99999999999999 Memory 331382784 +REPLICA_localhost_27018 | Cpu 35 Memory 332709888 +REPLICA_localhost_27017 | Cpu 35 Memory 329793536 +-------------------------------------- +Metrics for period to: 15:49:40(-0300) (width: 8.754s) +-------------------------------------- + +vusers.completed: .............................................................. 122 +vusers.created: ................................................................ 130 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 130 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 637.2 + max: ......................................................................... 841.9 + mean: ........................................................................ 727 + median: ...................................................................... 727.9 + p95: ......................................................................... 820.7 + p99: ......................................................................... 837.3 + + +REPLICA_localhost_27017 | Cpu 40 Memory 331366400 +APP | Cpu 69 Memory 373473280 +REPLICA_localhost_27019 | Cpu 69 Memory 332955648 +REPLICA_localhost_27018 | Cpu 40 Memory 334168064 +-------------------------------------- +Metrics for period to: 15:49:50(-0300) (width: 9.967s) +-------------------------------------- + +vusers.completed: .............................................................. 147 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 668.1 + max: ......................................................................... 909.7 + mean: ........................................................................ 759.2 + median: ...................................................................... 757.6 + p95: ......................................................................... 871.5 + p99: ......................................................................... 889.1 + + +REPLICA_localhost_27017 | Cpu 32 Memory 369115136 +REPLICA_localhost_27019 | Cpu 55.00000000000001 Memory 337346560 +REPLICA_localhost_27018 | Cpu 32 Memory 365346816 +APP | Cpu 54 Memory 375062528 +-------------------------------------- +Metrics for period to: 15:50:00(-0300) (width: 9.96s) +-------------------------------------- + +vusers.completed: .............................................................. 153 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 650.2 + max: ......................................................................... 832.9 + mean: ........................................................................ 714.6 + median: ...................................................................... 699.4 + p95: ......................................................................... 804.5 + p99: ......................................................................... 820.7 + + +REPLICA_localhost_27017 | Cpu 33 Memory 369229824 +REPLICA_localhost_27018 | Cpu 34 Memory 365412352 +REPLICA_localhost_27019 | Cpu 56.00000000000001 Memory 341147648 +APP | Cpu 54 Memory 374685696 +-------------------------------------- +Metrics for period to: 15:50:10(-0300) (width: 9.961s) +-------------------------------------- + +vusers.completed: .............................................................. 150 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 638.6 + max: ......................................................................... 781 + mean: ........................................................................ 703.4 + median: ...................................................................... 699.4 + p95: ......................................................................... 757.6 + p99: ......................................................................... 772.9 + + +REPLICA_localhost_27017 | Cpu 33 Memory 369901568 +REPLICA_localhost_27018 | Cpu 34 Memory 366034944 +REPLICA_localhost_27019 | Cpu 59 Memory 348372992 +APP | Cpu 56.00000000000001 Memory 379174912 +-------------------------------------- +Metrics for period to: 15:50:20(-0300) (width: 9.96s) +-------------------------------------- + +vusers.completed: .............................................................. 150 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 642.9 + max: ......................................................................... 770.4 + mean: ........................................................................ 714.6 + median: ...................................................................... 713.5 + p95: ......................................................................... 757.6 + p99: ......................................................................... 757.6 + + +REPLICA_localhost_27017 | Cpu 34 Memory 369885184 +REPLICA_localhost_27019 | Cpu 60 Memory 351469568 +REPLICA_localhost_27018 | Cpu 34 Memory 367788032 +APP | Cpu 61 Memory 381419520 +Phase completed: unnamed (index: 0, duration: 60s) 15:50:30(-0300) + +-------------------------------------- +Metrics for period to: 15:50:30(-0300) (width: 9.962s) +-------------------------------------- + +vusers.completed: .............................................................. 150 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 682 + max: ......................................................................... 789.2 + mean: ........................................................................ 731.7 + median: ...................................................................... 727.9 + p95: ......................................................................... 772.9 + p99: ......................................................................... 772.9 + + +-------------------------------------- +Metrics for period to: 15:50:40(-0300) (width: 1.911s) +-------------------------------------- + +vusers.completed: .............................................................. 28 +vusers.created: ................................................................ 20 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 20 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 709.5 + max: ......................................................................... 769.7 + mean: ........................................................................ 741.6 + median: ...................................................................... 742.6 + p95: ......................................................................... 757.6 + p99: ......................................................................... 772.9 + + +All VUs finished. Total time: 1 minute, 2 seconds + +-------------------------------- +Summary report @ 15:50:33(-0300) +-------------------------------- + +vusers.completed: .............................................................. 900 +vusers.created: ................................................................ 900 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 900 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 637.2 + max: ......................................................................... 909.7 + mean: ........................................................................ 725.4 + median: ...................................................................... 727.9 + p95: ......................................................................... 804.5 + p99: ......................................................................... 871.5 + +Changes to your project's package version selections: + +apm-agent removed from your project +montiapm:agent removed from your project +montiapm:agent-binary-deps removed from your project +montiapm:meteorx removed from your project +montiapm:profiler removed from your project +zodern:meteor-package-versions removed from your project +zodern:types removed from your project + +apm-agent: removed dependency +---------- +REPLICA_localhost_27018 +Average CPU usage (%): 30.37 +Average Memory usage (bytes): 355 MB +---------- +---------- +REPLICA_localhost_27019 +Average CPU usage (%): 51.44 +Average Memory usage (bytes): 340 MB +---------- +---------- +APP +Average CPU usage (%): 54.58 +Average Memory usage (bytes): 360 MB +---------- +---------- +REPLICA_localhost_27017 +Average CPU usage (%): 30.37 +Average Memory usage (bytes): 355 MB +---------- +Output is suitable for comparisons (logs/oplog-server-tasks-3.x-reactive-stress-server.yml.log) + Replicaset managed the configuration correctly. diff --git a/logs/pooling.log b/logs/pooling.log new file mode 100644 index 0000000..eb79c08 --- /dev/null +++ b/logs/pooling.log @@ -0,0 +1,325 @@ +=============================== + Artillery Configuration - Thu Oct 2 16:09:47 -03 2025 +=============================== +config: + target: ws://localhost:3000/websocket + phases: + - duration: 60 + arrivalRate: 15 + ensure: + maxErrorRate: 1 + max: 500 + processor: '../tests/server-load-helpers.js' +scenarios: + - name: Measure Task Latency (3.x) + flow: + - function: 'beforeScenario' + - function: 'reactivePubSubTasksDdp' + - function: 'afterScenario' +=============================== +=============================== + Environment Variables - Thu Oct 2 16:09:47 -03 2025 +=============================== +MONGO_URL = mongodb://localhost:27017,localhost:27018,localhost:27019/?replicaSet=rs0 +MONGO_OPLOG_URL = mongodb://localhost:27017,localhost:27018,localhost:27019/local?replicaSet=rs0 +MONTI_APP_ID = Z6A9yDhJQeaCYbjrg +MONTI_APP_SECRET = b2427f56-45b6-40ae-9eba-c9c2fa079dd0 +ENABLE_APM = 1 +METEOR_CHECKOUT_PATH = /Users/italojose/dev/meteor-dev/meteor +SKIP_KILL_CONTAINERS = +GALAXY_API_KEY = +GALAXY_TOKEN = +=============================== +Dropping 'test' database before running benchmarks... +'test' database dropped successfully. + +Changes to your project's package version selections: + +apm-agent added, version 0.0.1 +montiapm:agent+ added, version 3.0.0-beta.16 +montiapm:agent-binary-deps added, version 3.0.0 +montiapm:meteorx added, version 2.3.1 +montiapm:profiler+ added, version 1.7.0-beta.3 +zodern:meteor-package-versions added, version 0.2.2 +zodern:types added, version 1.0.13 + + ++ In order to resolve constraints, we had to use experimental versions of +these +packages. + +apm-agent +=============================== + Meteor checkout version - 3c7c7c6c3a2ee19c00047beeedf494898b6d6939 +=============================== +=> Running Meteor from a checkout -- overrides project version (Meteor 3.0.2) +[[[[[ ~/dev/meteor-dev/performance/apps/tasks-3.x ]]]]] + +=> Started proxy. +=> Started HMR server. + +Changes to your project's package version selections: + +allow-deny upgraded from 2.0.0 to 2.1.0 +autoupdate upgraded from 2.0.0 to 2.0.1 +babel-compiler upgraded from 7.11.0 to 7.12.2 +blaze-tools removed from your project +boilerplate-generator upgraded from 2.0.0 to 2.0.2 +caching-compiler upgraded from 2.0.0 to 2.0.1 +caching-html-compiler removed from your project +callback-hook upgraded from 1.6.0 to 1.6.1 +check upgraded from 1.4.2 to 1.4.4 +ddp-client upgraded from 3.0.1 to 3.1.1 +ddp-server upgraded from 3.0.1 to 3.1.2 +ecmascript upgraded from 0.16.9 to 0.16.13 +ecmascript-runtime upgraded from 0.8.2 to 0.8.3 +ecmascript-runtime-client upgraded from 0.12.2 to 0.12.3 +ejson upgraded from 1.1.4 to 1.1.5 +fetch upgraded from 0.1.5 to 0.1.6 +html-tools removed from your project +htmljs removed from your project +logging upgraded from 1.3.5 to 1.3.6 +meteor upgraded from 2.0.1 to 2.1.1 +minifier-css upgraded from 2.0.0 to 2.0.1 +minifier-js upgraded from 3.0.0 to 3.0.4 +minimongo upgraded from 2.0.1 to 2.0.4 +modern-browsers upgraded from 0.1.11 to 0.2.3 +modules upgraded from 0.20.1 to 0.20.3 +mongo upgraded from 2.0.1 to 2.1.4 +mongo-decimal upgraded from 0.1.4-beta300.7 to 0.2.0 +npm-mongo* upgraded from 4.17.4 to 6.16.1 +shell-server upgraded from 0.6.0 to 0.6.2 +socket-stream-client upgraded from 0.5.3 to 0.6.1 +spacebars-compiler removed from your project +standard-minifier-js upgraded from 3.0.0 to 3.1.1 +static-html upgraded from 1.3.3 to 1.4.0 +static-html-tools added, version 1.0.0 +templating-tools removed from your project +typescript upgraded from 5.4.3 to 5.6.6 +webapp upgraded from 2.0.1 to 2.0.7 + + +* These packages have been updated to new versions that are not backwards +compatible. +W20251002-16:10:09.566(-3)? (STDERR) Deprecation warnings are hidden but crucial to address for future Meteor updates. +W20251002-16:10:09.571(-3)? (STDERR) Remove the `METEOR_NO_DEPRECATION` env var to reveal them, then report or fix the issues. +I20251002-16:10:09.677(-3)? ✅ Using PollingObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_dLqwgsDkJFEK5xmSh","selector":{},"options":{"transform":null}} +I20251002-16:10:09.681(-3)? ✅ Using PollingObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_dLqwgsDkJFEK5xmSh","selector":{},"options":{"transform":null,"limit":20,"_disableOplog":true}} +I20251002-16:10:09.682(-3)? ✅ Using PollingObserveDriver for {"ordered":false,"collectionName":"__dummy_coll_dLqwgsDkJFEK5xmSh","selector":{},"options":{"transform":null}} +=> Started your app. + +=> App running at: http://localhost:3000/ +APP PID: 17396 +Replica node localhost:27017 PID: 49803 +Replica node localhost:27018 PID: 49806 +Replica node localhost:27019 PID: 49817 +Replica PIDs: 49803 49806 49817 +I20251002-16:10:09.904(-3)? Monti APM: Connected +Monitor CpuRam APP Pid 17435 +Monitor CpuRam REPLICA_localhost_27017 Pid 17441 +Monitor CpuRam REPLICA_localhost_27018 Pid 17442 +Monitor CpuRam REPLICA_localhost_27019 Pid 17443 +Test run id: txrbn_5zbtnwajrpq7bq6rwxa4c757eqz45_3wft +APP | Cpu 40 Memory 173391872 +REPLICA_localhost_27017 | Cpu 1.2753382439728094 Memory 385761280 +REPLICA_localhost_27019 | Cpu 1.4527272925978951 Memory 407158784 +REPLICA_localhost_27018 | Cpu 1.320495726869358 Memory 392478720 +Phase started: unnamed (index: 0, duration: 60s) 16:10:11(-0300) + +I20251002-16:10:12.223(-3)? ✅ Using PollingObserveDriver for {"ordered":false,"collectionName":"taskCollection","selector":{},"options":{"transform":null}} +REPLICA_localhost_27018 | Cpu 25 Memory 393707520 +APP | Cpu 53 Memory 266551296 +REPLICA_localhost_27017 | Cpu 25 Memory 387219456 +REPLICA_localhost_27019 | Cpu 38 Memory 410714112 +-------------------------------------- +Metrics for period to: 16:10:20(-0300) (width: 7.757s) +-------------------------------------- + +vusers.completed: .............................................................. 107 +vusers.created: ................................................................ 115 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 115 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 621.3 + max: ......................................................................... 739.6 + mean: ........................................................................ 678.3 + median: ...................................................................... 671.9 + p95: ......................................................................... 713.5 + p99: ......................................................................... 727.9 + + +REPLICA_localhost_27017 | Cpu 23 Memory 387137536 +APP | Cpu 47 Memory 386105344 +REPLICA_localhost_27019 | Cpu 36 Memory 410681344 +REPLICA_localhost_27018 | Cpu 23 Memory 393773056 +-------------------------------------- +Metrics for period to: 16:10:30(-0300) (width: 9.95s) +-------------------------------------- + +vusers.completed: .............................................................. 151 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 616.4 + max: ......................................................................... 751.8 + mean: ........................................................................ 681.1 + median: ...................................................................... 685.5 + p95: ......................................................................... 727.9 + p99: ......................................................................... 742.6 + + +APP | Cpu 38 Memory 387792896 +REPLICA_localhost_27019 | Cpu 36 Memory 398491648 +REPLICA_localhost_27018 | Cpu 22 Memory 386400256 +REPLICA_localhost_27017 | Cpu 23 Memory 385810432 +-------------------------------------- +Metrics for period to: 16:10:40(-0300) (width: 9.95s) +-------------------------------------- + +vusers.completed: .............................................................. 150 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 633.6 + max: ......................................................................... 714.4 + mean: ........................................................................ 668.3 + median: ...................................................................... 671.9 + p95: ......................................................................... 699.4 + p99: ......................................................................... 699.4 + + +APP | Cpu 38 Memory 396853248 +REPLICA_localhost_27019 | Cpu 38 Memory 398540800 +REPLICA_localhost_27017 | Cpu 22 Memory 386138112 +REPLICA_localhost_27018 | Cpu 22 Memory 387072000 +-------------------------------------- +Metrics for period to: 16:10:50(-0300) (width: 9.977s) +-------------------------------------- + +vusers.completed: .............................................................. 150 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 636 + max: ......................................................................... 713.2 + mean: ........................................................................ 669.4 + median: ...................................................................... 671.9 + p95: ......................................................................... 699.4 + p99: ......................................................................... 699.4 + + +APP | Cpu 39 Memory 398016512 +REPLICA_localhost_27019 | Cpu 39 Memory 387104768 +REPLICA_localhost_27017 | Cpu 22 Memory 377421824 +REPLICA_localhost_27018 | Cpu 22 Memory 376881152 +-------------------------------------- +Metrics for period to: 16:11:00(-0300) (width: 9.951s) +-------------------------------------- + +vusers.completed: .............................................................. 150 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 637.2 + max: ......................................................................... 735.8 + mean: ........................................................................ 678.5 + median: ...................................................................... 671.9 + p95: ......................................................................... 727.9 + p99: ......................................................................... 727.9 + + +REPLICA_localhost_27019 | Cpu 40 Memory 387481600 +REPLICA_localhost_27017 | Cpu 22 Memory 377896960 +APP | Cpu 41 Memory 398360576 +REPLICA_localhost_27018 | Cpu 22 Memory 377159680 +Phase completed: unnamed (index: 0, duration: 60s) 16:11:11(-0300) + +-------------------------------------- +Metrics for period to: 16:11:10(-0300) (width: 9.988s) +-------------------------------------- + +vusers.completed: .............................................................. 151 +vusers.created: ................................................................ 150 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 150 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 627.6 + max: ......................................................................... 704.8 + mean: ........................................................................ 666.6 + median: ...................................................................... 671.9 + p95: ......................................................................... 699.4 + p99: ......................................................................... 699.4 + + +-------------------------------------- +Metrics for period to: 16:11:20(-0300) (width: 2.823s) +-------------------------------------- + +vusers.completed: .............................................................. 41 +vusers.created: ................................................................ 35 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 35 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 618.3 + max: ......................................................................... 678.9 + mean: ........................................................................ 648.2 + median: ...................................................................... 645.6 + p95: ......................................................................... 671.9 + p99: ......................................................................... 671.9 + + +All VUs finished. Total time: 1 minute, 2 seconds + +-------------------------------- +Summary report @ 16:11:14(-0300) +-------------------------------- + +vusers.completed: .............................................................. 900 +vusers.created: ................................................................ 900 +vusers.created_by_name.Measure Task Latency (3.x): ............................. 900 +vusers.failed: ................................................................. 0 +vusers.session_length: + min: ......................................................................... 616.4 + max: ......................................................................... 751.8 + mean: ........................................................................ 672.3 + median: ...................................................................... 671.9 + p95: ......................................................................... 713.5 + p99: ......................................................................... 742.6 + +Changes to your project's package version selections: + +apm-agent removed from your project +montiapm:agent removed from your project +montiapm:agent-binary-deps removed from your project +montiapm:meteorx removed from your project +montiapm:profiler removed from your project +zodern:meteor-package-versions removed from your project +zodern:types removed from your project + +apm-agent: removed dependency +---------- +REPLICA_localhost_27017 +Average CPU usage (%): 19.02 +Average Memory usage (bytes): 384 MB +---------- +---------- +APP +Average CPU usage (%): 36.52 +Average Memory usage (bytes): 355 MB +---------- +---------- +REPLICA_localhost_27018 +Average CPU usage (%): 19.10 +Average Memory usage (bytes): 386 MB +---------- +---------- +REPLICA_localhost_27019 +Average CPU usage (%): 31.39 +Average Memory usage (bytes): 399 MB +---------- +Output is suitable for comparisons (logs/oplog-server-tasks-3.x-reactive-stress-server.yml.log) + Replicaset managed the configuration correctly. diff --git a/logs/summary.md b/logs/summary.md new file mode 100644 index 0000000..c5601f5 --- /dev/null +++ b/logs/summary.md @@ -0,0 +1,42 @@ +# MongoDB Resource Usage Results + +## 🔥 CPU (%) – REPLICAS + +| **Scenario** | **REPLICA_localhost_27017** | **REPLICA_localhost_27018** | **REPLICA_localhost_27019** | +|---------------------|-----------------------------|-----------------------------|-----------------------------| +| **Oplog** | 30.37 | 30.37 | **51.44** | +| **Events** | 20.42 | 20.58 | 38.09 | +| **Pooling** | 19.02 | 19.10 | 31.39 | +| **Change Streams** | 15.00 | 15.28 | 31.15 | + +--- + +## 💾 Memory (MB) – REPLICAS + +| **Scenario** | **REPLICA_localhost_27017** | **REPLICA_localhost_27018** | **REPLICA_localhost_27019** | +|---------------------|-----------------------------|-----------------------------|-----------------------------| +| **Pooling** | 384 | 386 | 399 | +| **Change Streams** | 370 | 374 | 386 | +| **Events** | 378 | 387 | **402** | +| **Oplog** | 355 | 355 | 340 | +--- + +## 🔥 CPU (%) – APP + +| **Scenario** | **APP** | +|---------------------|---------| +| **Oplog** | **54.58** | +| **Events** | 43.07 | +| **Change Streams** | 42.85 | +| **Pooling** | 36.52 | + +--- + +## 💾 Memory (MB) – APP + +| **Scenario** | **APP** | +|---------------------|---------| +| **Change Streams** | **422** | +| **Oplog** | 360 | +| **Events** | 379 | +| **Pooling** | 355 | diff --git a/scripts/monitor-replicaset.sh b/scripts/monitor-replicaset.sh new file mode 100755 index 0000000..5bc0919 --- /dev/null +++ b/scripts/monitor-replicaset.sh @@ -0,0 +1,394 @@ +#!/usr/bin/env bash + +# app. Application directory name within ./apps/* +# script. Artillery script name within ./artillery/* +app="${1}" +script="${2}" +logName="${3:-''}" +if [[ -z "${app}" ]] || [[ -z "${script}" ]]; then + echo "Usage: monitor-replicaset.sh " + exit 1 +fi + +# Redirect stdout (1) and stderr (2) to a file +logFile="logs/${logName}-${app}-${script}.log" +mkdir -p logs +exec > "./${logFile}" 2>&1 + +# Initialize script constants +baseDir="${PWD}" +appsDir="${baseDir}/apps" +appPath="${appsDir}/${app}" +appPort=3000 + +# Define color codes +RED='\033[0;31m' +GREEN='\033[0;32m' +NC='\033[0m' # No Color + +# Track replica monitor processes +declare -a replicaDbPids=() +declare -a replicaDbLabels=() +declare -a replicaMonitorPids=() +artPid="" +cpuRamAppPid="" + +# Define helpers +function getPidByName() { + ps aux | grep "${1}" | grep -v grep | awk '{print $2}' +} + +function getPidByPort() { + local port="${1}" + lsof -tiTCP:"${port}" -sTCP:LISTEN 2>/dev/null | head -n 1 +} + +function loadEnv() { + if [[ -f $1 ]]; then + # shellcheck disable=SC1090 + source "${1}" + while read -r line; do + eval "export ${line}" + done <"$1" + fi +} + +function formatToEnv() { + local str="${1}" + str=$(echo ${str} | sed -r -- 's/ /_/g') + str=$(echo ${str} | sed -r -- 's/\./_/g') + str=$(echo ${str} | sed -r -- 's/\-/_/g') + str=$(echo ${str} | tr -d "[@^\\\/<>\"'=]" | tr -d '*') + str=$(echo ${str} | sed -r -- 's/\//_/g') + str=$(echo ${str} | sed -r -- 's/,/_/g') + str=$(echo ${str} | sed 'y/abcdefghijklmnopqrstuvwxyz/ABCDEFGHIJKLMNOPQRSTUVWXYZ/') + echo "${str}" +} + +function getEnvVarValue() { + local key="${1}" + eval "printf '%s' \"\${${key}}\"" +} + +function trimSpaces() { + echo "${1}" | sed 's/^ *//;s/ *$//' +} + +function isRunningUrl() { + local url="${1}" + local urlStatus="$(curl -Is "${url}" | head -1)" + echo "${urlStatus}" | grep -q "200" +} + +function waitMeteorApp() { + PROCESS_WAIT_TIMEOUT=3600000 + processWaitTimeoutSecs=$((PROCESS_WAIT_TIMEOUT / 1000)) + waitSecs=0 + while ! isRunningUrl "http://localhost:${appPort}" && [[ "${waitSecs}" -lt "${processWaitTimeoutSecs}" ]]; do + sleep 1 + waitSecs=$((waitSecs + 1)) + done +} + +function getMontiAppId() { + local envKey="$(formatToEnv ${app})" + local value="$(getEnvVarValue "MONTI_APP_ID")" + echo "${value}" +} + +function getMontiAppSecret() { + local envKey="$(formatToEnv ${app})" + local value="$(getEnvVarValue "MONTI_APP_SECRET")" + echo "${value}" +} + +function getReplicaMongoUrl() { + local envKey="$(formatToEnv ${app})" + local url="$(getEnvVarValue "MONGO_URL")" + if [[ -n "${url}" ]]; then + echo "${url}" + return + fi + + echo "${url}" +} + +function getReplicaOplogUrl() { + local envKey="$(formatToEnv ${app})" + local url="$(getEnvVarValue "MONGO_OPLOG_URL")" + if [[ -n "${url}" ]]; then + echo "${url}" + return + fi + echo "${url}" +} + +function dropTestDatabase() { + if ! command -v mongosh >/dev/null 2>&1; then + echo "mongosh not found; skipping test database cleanup." + return + fi + + local uri="${1}" + if [[ -z "${uri}" ]]; then + echo "No Mongo URI supplied to dropTestDatabase." + return + fi + + echo "Dropping 'test' database before running benchmarks..." + if ! mongosh --quiet "${uri}" --eval 'db.getSiblingDB("test").dropDatabase();' >/dev/null 2>&1; then + echo "Failed to drop 'test' database. Continuing anyway." + else + echo "'test' database dropped successfully." + fi +} + +function logScriptConfig() { + echo -e "===============================" + echo -e " Artillery Configuration - $(date) " + echo -e "===============================" + cat "${baseDir}/artillery/${script}" + echo -e "===============================" +} + +function logMeteorVersion() { + echo -e "===============================" + if [[ -n "${METEOR_CHECKOUT_PATH}" ]]; then + local oldPath="${PWD}" + builtin cd "${METEOR_CHECKOUT_PATH}" + echo -e " Meteor checkout version - $(git rev-parse HEAD)" + builtin cd "${oldPath}" + else + echo -e " Meteor version - $(cat .meteor/release)" + fi + echo -e "===============================" +} + +function collectReplicaDbPids() { + local url="${1}" + local stripped="${url#*://}" + stripped="${stripped#*@}" + stripped="${stripped%%/*}" + stripped="${stripped%%\?*}" + + if [[ -z "${stripped}" ]]; then + echo "Unable to parse hosts from replicaset url: ${url}" + return 1 + fi + + IFS=',' read -ra hostEntries <<< "${stripped}" + + for entry in "${hostEntries[@]}"; do + local trimmed="$(trimSpaces "${entry}")" + if [[ -z "${trimmed}" ]]; then + continue + fi + + local host="${trimmed}" + local port="27017" + + if [[ "${trimmed}" =~ ^\[(.*)\]:(.*)$ ]]; then + host="${BASH_REMATCH[1]}" + port="${BASH_REMATCH[2]}" + elif [[ "${trimmed}" =~ ^\[(.*)\]$ ]]; then + host="${BASH_REMATCH[1]}" + elif [[ "${trimmed}" == *:* ]]; then + host="${trimmed%:*}" + port="${trimmed##*:}" + fi + + local pid="$(getPidByPort "${port}")" + if [[ -z "${pid}" ]]; then + echo "Could not find a local mongod process listening on port ${port} for host ${host}." + continue + fi + + local labelSuffix="${host}_${port}" + labelSuffix=$(echo "${labelSuffix}" | sed -r 's/[^A-Za-z0-9_]/_/g') + local label="REPLICA_${labelSuffix}" + + replicaDbPids+=("${pid}") + replicaDbLabels+=("${label}") + + echo "Replica node ${host}:${port} PID: ${pid}" + done + + if [[ "${#replicaDbPids[@]}" -eq 0 ]]; then + echo "No replicaset mongod processes could be identified locally." + return 1 + fi + + return 0 +} + +function startReplicaMonitors() { + local helperPath="${baseDir}/scripts/helpers/monitor-cpu-ram.js" + for idx in "${!replicaDbPids[@]}"; do + local pid="${replicaDbPids[$idx]}" + local label="${replicaDbLabels[$idx]}" + node "${helperPath}" "${pid}" "${label}" & + local monitorPid="$!" + replicaMonitorPids+=("${monitorPid}") + echo "Monitor CpuRam ${label} Pid ${monitorPid}" + done +} + +# Ensure proper cleanup on interrupt the process +function cleanup() { + local mode="${1}" + local exitCode=0 + + if [[ "${mode}" == "error" ]]; then + exitCode=1 + elif [[ "${mode}" == "true" ]]; then + exitCode=0 + elif [[ "${mode}" == "signal" ]]; then + exitCode=130 + fi + + if [[ -n "${ENABLE_APM}" ]]; then + METEOR_PACKAGE_DIRS="${baseDir}/packages" meteor remove apm-agent + fi + + builtin cd ${baseDir} >/dev/null 2>&1 || true + + if [[ -n "${artPid}" ]]; then + pkill -P ${artPid} 2>/dev/null || true + fi + + if [[ -n "${cpuRamAppPid}" ]]; then + kill -s TERM ${cpuRamAppPid} 2>/dev/null || true + fi + + for pid in "${replicaMonitorPids[@]}"; do + kill -s TERM "${pid}" 2>/dev/null || true + done + + pkill -P $$ 2>/dev/null || true + + if [[ "${mode}" == "true" ]]; then + sleep 6 + if cat "${baseDir}/${logFile}" | grep -q " Timeout "; then + echo -e "${RED}*** !!! ERROR: SOMETHING WENT WRONG !!! ***${NC}" + echo -e "${RED}Output triggered an unexpected timeout (${logFile})${NC}" + echo -e "${RED} Replicaset database is overloaded and unable to provide accurate comparison results.${NC}" + echo -e "${RED} Try switching to a configuration that your replicaset can handle.${NC}" + exit 1 + else + echo -e "${GREEN}Output is suitable for comparisons (${logFile})${NC}" + echo -e "${GREEN} Replicaset managed the configuration correctly.${NC}" + exit 0 + fi + fi + + exit ${exitCode} +} +trap 'cleanup signal' SIGINT SIGTERM + +if ! command -v lsof >/dev/null 2>&1; then + echo "Command 'lsof' is required to identify mongod processes. Please install it before running this script." + exit 1 +fi + +if [[ ! -d "${appPath}" ]]; then + echo "App path not found: ${appPath}" + exit 1 +fi + +logScriptConfig + +function logEnvVariables() { + echo -e "===============================" + echo -e " Environment Variables - $(date) " + echo -e "===============================" + local envKey="$(formatToEnv ${app})" + declare -a envKeys=( + "MONGO_URL" + "MONGO_OPLOG_URL" + "MONTI_APP_ID" + "MONTI_APP_SECRET" + "ENABLE_APM" + "METEOR_CHECKOUT_PATH" + "SKIP_KILL_CONTAINERS" + "GALAXY_API_KEY" + "GALAXY_TOKEN" + ) + + for key in "${envKeys[@]}"; do + echo "${key} = $(getEnvVarValue "${key}")" + done + echo -e "===============================" +} + +loadEnv "${baseDir}/.env" +if [[ -f "${baseDir}/.env.replicaset" ]]; then + loadEnv "${baseDir}/.env.replicaset" +fi + +logEnvVariables + +replicaMongoUrl="$(getReplicaMongoUrl)" +if [[ -z "${replicaMongoUrl}" ]]; then + echo "No replicaset Mongo URL provided. Set MONGO_REPLICA_URL or MONGO_URL (optionally with _$(formatToEnv ${app}) suffix)." + exit 1 +fi + +replicaOplogUrl="$(getReplicaOplogUrl)" + +dropTestDatabase "${replicaMongoUrl}" + +# Prepare, run and wait meteor app +builtin cd "${appPath}" + +if [[ -n "${ENABLE_APM}" ]]; then + export MONTI_APP_ID="$(getMontiAppId)" + export MONTI_APP_SECRET="$(getMontiAppSecret)" + METEOR_PACKAGE_DIRS="${baseDir}/packages" meteor add apm-agent +fi + +rm -rf "${appPath}/.meteor/local" +logMeteorVersion + +export MONGO_URL="${replicaMongoUrl}" +if [[ -n "${replicaOplogUrl}" ]]; then + export MONGO_OPLOG_URL="${replicaOplogUrl}" +fi + +if [[ -n "${METEOR_CHECKOUT_PATH}" ]]; then + METEOR_PACKAGE_DIRS="${baseDir}/packages" ${METEOR_CHECKOUT_PATH}/meteor run --port ${appPort} --settings ${baseDir}/apps/${app}/settings.json & +else + METEOR_PACKAGE_DIRS="${baseDir}/packages" meteor run --port ${appPort} --settings ${baseDir}/apps/${app}/settings.json & +fi +waitMeteorApp + +appPid="$(getPidByName "${app}/.meteor/local/build/main.js")" +if [[ -z "${appPid}" ]]; then + echo "Could not determine Meteor app PID." + cleanup error +fi +echo "APP PID: ${appPid}" + +if ! collectReplicaDbPids "${replicaMongoUrl}"; then + cleanup error +fi + +echo "Replica PIDs: ${replicaDbPids[*]}" + +# Run artillery script +npx artillery run "${baseDir}/artillery/${script}" & +artPid="$!" + +# Run CPU and RAM monitoring for meteor app and replica nodes +node "${baseDir}/scripts/helpers/monitor-cpu-ram.js" "${appPid}" "APP" & +cpuRamAppPid=$(getPidByName "${baseDir}/scripts/helpers/monitor-cpu-ram.js ${appPid} APP") +if [[ -z "${cpuRamAppPid}" ]]; then + cpuRamAppPid="$!" +fi +echo "Monitor CpuRam APP Pid ${cpuRamAppPid}" + +startReplicaMonitors + +# Wait for artillery script to finish the process +wait "${artPid}" + +cleanup true