diff --git a/lib/async/als.js b/lib/async/als.js index fa59f058..f67bebfb 100644 --- a/lib/async/als.js +++ b/lib/async/als.js @@ -2,7 +2,6 @@ import fs from 'fs'; import util from 'util'; import { AsyncLocalStorage } from 'node:async_hooks'; import crypto from 'crypto'; -import { awaitDetector } from './async-hook'; export const getId = () => crypto.randomUUID(); @@ -17,7 +16,7 @@ export const runWithALS = ( store.info = info; } - return awaitDetector.detect(() => MontiAsyncStorage.run(store, () => fn.apply(this, args))); + return MontiAsyncStorage.run(store, () => fn.apply(this, args)); }; export const MontiEnvironmentVariable = new AsyncLocalStorage(); @@ -30,30 +29,6 @@ export const getStore = () => MontiAsyncStorage.getStore() ?? {}; export const getInfo = () => MontiAsyncStorage.getStore()?.info; -export const startTrackingAsync = () => { - const info = getInfo(); - - if (!info) return; - - info.trackAsync = true; -}; - -export const incrementIgnoreOffset = (offset = 1) => { - const info = getInfo(); - - if (!info) return; - - if (!info.ignoreOffset) info.ignoreOffset = 0; - - info.ignoreOffset += offset; -}; - -export const setActiveEvent = (event, store = MontiAsyncStorage.getStore()) => { - if (!store) return; - - MontiAsyncStorage.enterWith({ ...store, activeEvent: event }); -}; - export const getActiveEvent = (store = MontiAsyncStorage.getStore()) => store?.activeEvent; export const debug = label => (...args) => { diff --git a/lib/async/async-hook.js b/lib/async/async-hook.js index 9cc7f64e..be5b0a73 100644 --- a/lib/async/async-hook.js +++ b/lib/async/async-hook.js @@ -32,11 +32,10 @@ export const getResource = (asyncId) => { }; export const awaitDetector = new AwaitDetector({ + logging: true, onAwaitStart (asyncId, triggerAsyncId) { const info = getInfo(); - if (!info?.trackAsync) return; - const activeEvent = getActiveEvent(); if (activeEvent?.level > MaxAsyncLevel) return; @@ -45,6 +44,8 @@ export const awaitDetector = new AwaitDetector({ if (!trace) return; + console.log('start', asyncId); + info.resources = info.resources || new Map(); const trigger = info.resources.get(triggerAsyncId); @@ -69,7 +70,7 @@ export const awaitDetector = new AwaitDetector({ res.stack = stackTrace(); } - res.event = Kadira.tracer.event(info.trace, EventType.Async, pick(res, ['shouldBeSibling', 'asyncId', 'stack', 'asyncId', 'triggerAsyncId', 'executionAsyncId'])); + res.event = Kadira.tracer.event(info.trace, EventType.Async, pick(res, ['asyncId', 'stack', 'asyncId', 'triggerAsyncId', 'executionAsyncId'])); MontiAsyncStorage.enterWith(Object.assign({}, oldStore, { activeEvent: res.event })); info.resources.set(asyncId, res); @@ -82,14 +83,13 @@ export const awaitDetector = new AwaitDetector({ onAwaitEnd (asyncId) { const resource = getResource(asyncId); - if (!resource) return; + console.log('end', asyncId, !!resource); + if (!resource) return; resource.end = Ntp._now(); resource.duration = resource.end - resource.start; - console.log({ resource }); - const info = getInfo(); if (!info) return; diff --git a/lib/hijack/wrap_session.js b/lib/hijack/wrap_session.js index 288d11cf..b787beca 100644 --- a/lib/hijack/wrap_session.js +++ b/lib/hijack/wrap_session.js @@ -2,9 +2,9 @@ import { Meteor } from 'meteor/meteor'; import { _ } from 'meteor/underscore'; import { MeteorDebugIgnore } from './error'; import { TimeoutManager } from './timeout_manager'; -import { incrementIgnoreOffset, runWithALS, startTrackingAsync } from '../async/als'; +import { runWithALS } from '../async/als'; import { EventType } from '../constants'; -import util from 'util'; +import { awaitDetector } from '../async/async-hook'; const MAX_PARAMS_LENGTH = 4000; @@ -72,10 +72,7 @@ export function wrapSession (sessionProto) { unblock = Kadira.waitTimeBuilder.trackWaitTime(this, msg, unblock); - - const promise = originalMethodHandler.call(self, msg, unblock); - - response = await promise; + response = await awaitDetector.detect(() => originalMethodHandler.call(self, msg, unblock)); unblock(); } else { @@ -106,10 +103,6 @@ export function wrapSession (sessionProto) { unblock = Kadira.waitTimeBuilder.trackWaitTime(this, msg, unblock); - startTrackingAsync(); - - incrementIgnoreOffset(2); - response = orginalSubHandler.call(self, msg, unblock); unblock(); } else { @@ -160,6 +153,7 @@ export function wrapSession (sessionProto) { } // processing the message + console.log('Processing message', msg); let trace = Kadira.tracer.buildTrace(kadiraInfo.trace); Kadira.EventBus.emit('method', 'methodCompleted', trace, this); Kadira.models.methods.processMethod(trace); @@ -193,12 +187,6 @@ Meteor.methods = function (methodMap) { function wrapMethodHandlerForErrors (name, originalHandler, methodMap) { methodMap[name] = function () { try { - startTrackingAsync(); - - if (util.types.isAsyncFunction(originalHandler)) { - incrementIgnoreOffset(); - } - return originalHandler.apply(this, arguments); } catch (ex) { if (ex && Kadira._getInfo()) { diff --git a/lib/hijack/wrap_webapp.js b/lib/hijack/wrap_webapp.js index de9b7ea0..0287715c 100644 --- a/lib/hijack/wrap_webapp.js +++ b/lib/hijack/wrap_webapp.js @@ -1,5 +1,5 @@ import { WebApp, WebAppInternals } from 'meteor/webapp'; -import { runWithALS, startTrackingAsync } from '../async/als'; +import { runWithALS } from '../async/als'; import { EventType } from '../constants'; // Maximum content-length size @@ -137,8 +137,6 @@ export async function wrapWebApp () { let potentialPromise; - startTrackingAsync(); - if (errorHandler) { potentialPromise = handler.call(this, error, req, res, next); } else { diff --git a/lib/tracer/tracer.js b/lib/tracer/tracer.js index 7f8ccee7..cc3ed0ac 100644 --- a/lib/tracer/tracer.js +++ b/lib/tracer/tracer.js @@ -354,13 +354,14 @@ Tracer.prototype.optimizeEvent = function (objectEvent, metrics) { if (![EventType.Complete, EventType.Start].includes(type)) { setEventDuration(objectEvent); - const {duration} = objectEvent; - if (!endAt) { - endAt = at; + endAt = Ntp._now(); + objectEvent.duration = endAt - at; extraInfo.forcedEnd = true; } + const {duration} = objectEvent; + // We need this info as events are not always in order or in series. extraInfo.at = at; extraInfo.endAt = endAt; diff --git a/package.js b/package.js index 88eed798..ac8e9dd0 100644 --- a/package.js +++ b/package.js @@ -9,7 +9,7 @@ Package.describe({ let npmModules = { debug: '0.8.1', - '@monti-apm/core': '2.0.0-beta.1', + '@monti-apm/core': 'file:///Users/leonardo/Repositories/monti-apm/monti-apm-core', 'lru-cache': '5.1.1', 'json-stringify-safe': '5.0.1', 'monti-apm-sketches-js': '0.0.3', diff --git a/tests/tracer/tracer.js b/tests/tracer/tracer.js index 38bcc3fe..ec87bc97 100644 --- a/tests/tracer/tracer.js +++ b/tests/tracer/tracer.js @@ -583,7 +583,7 @@ addAsyncTest.only('Tracer - Build Trace - the correct number of async events are info = getInfo(); - return sleep(300); + return await sleep(300); }); await callAsync(methodId);