diff --git a/lib/context/disable-trace.js b/lib/context/disable-trace.js index dde61730..27032806 100644 --- a/lib/context/disable-trace.js +++ b/lib/context/disable-trace.js @@ -14,11 +14,12 @@ class DisableTrace { constructor(traceRoot) { this.traceRoot = traceRoot this.spanRecorder = new DisableSpanRecorder() + this.spanEventRecorder = new DisableSpanEventRecorder() } traceBlockBegin() { - return new DisableSpanEventRecorder() + return this.spanEventRecorder } traceBlockEnd() {} diff --git a/lib/context/trace/child-trace-builder.js b/lib/context/trace/child-trace-builder.js index 7bb462da..95c607e2 100644 --- a/lib/context/trace/child-trace-builder.js +++ b/lib/context/trace/child-trace-builder.js @@ -29,19 +29,20 @@ class ChildTraceBuilder { } traceBlockBegin(stackId = StackId.default) { - if (this.closed) { - return SpanEventRecorder.nullObject(this.traceRoot) - } - return this.callStack.makeSpanEventRecorder(stackId) } traceBlockEnd(spanEventRecorder) { if (this.closed) { - return + // If ChildTraceBuilder is closed, aync spanEvent was popped in the previous call. + // So, increase the depth of the next spanEvent. + const spanEventBuilder = spanEventRecorder.getSpanEventBuilder() + spanEventBuilder.setDepth(spanEventBuilder.getDepth() + 1) } - this.endSpanEventBuilder(spanEventRecorder.getSpanEventBuilder()) + if (this.closed) { + this.repository.flush() + } } endSpanEventBuilder(builder) { diff --git a/lib/context/trace/disable-child-trace.js b/lib/context/trace/disable-child-trace.js index 10e05610..ac9e9b97 100644 --- a/lib/context/trace/disable-child-trace.js +++ b/lib/context/trace/disable-child-trace.js @@ -22,6 +22,10 @@ class DisableChildTrace { traceBlockEnd() {} + getSpanRecorder() { + return this.spanRecorder + } + getTraceRoot() { return this.traceRoot } diff --git a/lib/context/trace/span-event-builder.js b/lib/context/trace/span-event-builder.js index 3f4e4b2b..74d230af 100644 --- a/lib/context/trace/span-event-builder.js +++ b/lib/context/trace/span-event-builder.js @@ -113,6 +113,10 @@ class SpanEventBuilder { return this } + getDepth() { + return this.depth + } + getStartTime() { return this.startTime } diff --git a/lib/instrumentation/instrument-arrow-function.js b/lib/instrumentation/instrument-arrow-function.js index 865844b8..faead6e0 100644 --- a/lib/instrumentation/instrument-arrow-function.js +++ b/lib/instrumentation/instrument-arrow-function.js @@ -9,6 +9,7 @@ const shimmer = require('@pinpoint-apm/shimmer') const HookFunctionArguments = require('./hook-function-arguments') const localStorage = require('./context/local-storage') +// const log = require('../utils/logger') // ref: SpanEventSimpleAroundInterceptorForPlugin.java class InstrumentArrowFunction { @@ -65,6 +66,13 @@ class InstrumentArrowFunction { return original.apply(this, arguments) } + // if (log.isInfo()) { + // if (typeof method !== 'symbol') { + // log.info(`target: ${JSON.stringify(target)}, method: ${method}, original: ${original} InstrumentArrowFunction.addChildTraceInterceptor`) + // } else { + // log.info(`target: ${JSON.stringify(target)}, symbol method, original: ${original} InstrumentArrowFunction.addChildTraceInterceptor`) + // } + // } const childTraceBuilder = traceContext.continueAsyncContextTraceObject(trace.getTraceRoot(), asyncId.nextLocalAsyncId2()) return localStorage.run(childTraceBuilder, () => { const result = original.apply(this, arguments) diff --git a/test/fixture.js b/test/fixture.js index 5c15fe8b..10d1b2a8 100644 --- a/test/fixture.js +++ b/test/fixture.js @@ -36,29 +36,10 @@ const captureNamedGroup = (callSite) => { , namedGroupTypeMethod([callSite], 0)) } -function assertSpanChunk(asyncTrace, callback) { - const origin = asyncTrace.close - asyncTrace.close = function () { - origin.apply(this, arguments) - callback(asyncTrace.storage.dataSender.findSpanChunk(asyncTrace.asyncId)) - } -} - -function assertTrace(callback) { - const trace = localStorage.getStore() - const origin = trace.close - trace.close = function () { - origin.apply(this, arguments) - callback(trace) - } -} - module.exports = { config, getTransactionId, getTraceId, getAgentInfo, captureNamedGroup, - assertSpanChunk, - assertTrace, } diff --git a/test/instrumentation/context/nested-async-trace.test.js b/test/instrumentation/context/nested-async-trace.test.js index 7ad46a8f..ac720641 100644 --- a/test/instrumentation/context/nested-async-trace.test.js +++ b/test/instrumentation/context/nested-async-trace.test.js @@ -46,12 +46,23 @@ const pResultReturnUnaryService = (call, callback) => { } } +let spanOrSpanChunks = [] +const resetSpanOrSpanChunks = () => { + spanOrSpanChunks = [] +} +const getSpanOrSpanChunks = () => { + return spanOrSpanChunks +} +const getSpanChunk = (asyncId) =>{ + return getSpanOrSpanChunks().find(spanOrSpanChunk => spanOrSpanChunk.getLocalasyncid().getAsyncid() === asyncId.getAsyncId() && spanOrSpanChunk.getLocalasyncid().getSequence() === asyncId.getSequence()) +} + let spanMessageEndEventCallback let dataStreamCount = 0 const spanMessageStreamService = (call) => { call.on('data', (spanMessage) => { const spanOrSpanChunk = spanMessage.getSpan() ?? spanMessage.getSpanchunk() - const spanOrSpanChunks = agent.getSpanOrSpanChunks() + const spanOrSpanChunks = getSpanOrSpanChunks() spanOrSpanChunks.push(spanOrSpanChunk) if (agent.getTraces().length === ++dataStreamCount) { spanMessageEndEventCallback?.() @@ -100,6 +111,7 @@ test(`nested mysql async query with express`, async (t) => { collectorServer.bindAsync('localhost:0', grpc.ServerCredentials.createInsecure(), async (err, port) => { agent.bindHttpWithCallSite(port) + resetSpanOrSpanChunks() const source = path.resolve(fixtures, 'mysql.sql') const container = await new MySqlContainer() .withCommand(['--default-authentication-plugin=mysql_native_password']) @@ -144,7 +156,7 @@ test(`nested mysql async query with express`, async (t) => { agent.callbackTraceClose(async (trace) => { let actualBuilder = new MethodDescriptorBuilder(expected('get', 'app.get')) .setClassName(expected('app', 'Function')) - .setLineNumber(117) + .setLineNumber(129) .setFileName('nested-async-trace.test.js') let actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) let actualSpanEvent = trace.repository.dataSender.mockSpan.spanEventList.find(spanEvent => spanEvent.sequence === 0) @@ -157,7 +169,7 @@ test(`nested mysql async query with express`, async (t) => { t.equal(actualSpanEvent.serviceType, expressServiceType.getCode(), 'serviceType is express') actualBuilder = new MethodDescriptorBuilder('createConnection') - .setLineNumber(118) + .setLineNumber(130) .setFileName('nested-async-trace.test.js') actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) actualSpanEvent = trace.repository.dataSender.mockSpan.spanEventList.find(spanEvent => spanEvent.sequence === 1) @@ -170,7 +182,7 @@ test(`nested mysql async query with express`, async (t) => { actualBuilder = new MethodDescriptorBuilder('connect') .setClassName('Connection') - .setLineNumber(127) + .setLineNumber(139) .setFileName('nested-async-trace.test.js') actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) actualSpanEvent = trace.repository.dataSender.mockSpan.spanEventList.find(spanEvent => spanEvent.sequence === 2) @@ -192,7 +204,7 @@ test(`nested mysql async query with express`, async (t) => { actualBuilder = new MethodDescriptorBuilder('query') .setClassName('Connection') - .setLineNumber(133) + .setLineNumber(145) .setFileName('nested-async-trace.test.js') actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) actualSpanEvent = trace.spanBuilder.spanEventList.find(spanEvent => spanEvent.sequence === 3) @@ -214,7 +226,7 @@ test(`nested mysql async query with express`, async (t) => { actualBuilder = new MethodDescriptorBuilder('query') .setClassName('Connection') - .setLineNumber(139) + .setLineNumber(151) .setFileName('nested-async-trace.test.js') actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) actualSpanEvent = actualSpanChunk.spanEventList[1] @@ -241,7 +253,7 @@ test(`nested mysql async query with express`, async (t) => { spanMessageEndEventCallback = async () => { const trace = agent.getTrace(0) const childTrace = agent.getTrace(1) - const actualSpanChunkGrpc = agent.getSpanChunk(childTrace.localAsyncId) + const actualSpanChunkGrpc = getSpanChunk(childTrace.localAsyncId) t.equal(actualSpanChunkGrpc.getVersion(), 1, 'PSpanChunk.version is 1') const actualTractionId = actualSpanChunkGrpc.getTransactionid() @@ -364,7 +376,7 @@ test(`nested mysql2 async query with express`, async (t) => { t.true(trace.spanBuilder.remoteAddress === '127.0.0.1' || trace.spanBuilder.remoteAddress === '::1', `remoteAddress is ${trace.spanBuilder.remoteAddress}`) let actualBuilder = new MethodDescriptorBuilder(expected('get', 'app.get')) .setClassName(expected('app', 'Function')) - .setLineNumber(320) + .setLineNumber(332) .setFileName('nested-async-trace.test.js') let actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) let actualSpanEvent = trace.spanBuilder.spanEventList.find(spanEvent => spanEvent.sequence === 0) @@ -377,7 +389,7 @@ test(`nested mysql2 async query with express`, async (t) => { t.equal(actualSpanEvent.serviceType, expressServiceType.getCode(), 'serviceType is express') actualBuilder = new MethodDescriptorBuilder('createConnection') - .setLineNumber(321) + .setLineNumber(333) .setFileName('nested-async-trace.test.js') actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) actualSpanEvent = trace.spanBuilder.spanEventList.find(spanEvent => spanEvent.sequence === 1) @@ -390,7 +402,7 @@ test(`nested mysql2 async query with express`, async (t) => { actualBuilder = new MethodDescriptorBuilder('query') .setClassName('Connection') - .setLineNumber(331) + .setLineNumber(343) .setFileName('nested-async-trace.test.js') actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) actualSpanEvent = trace.spanBuilder.spanEventList.find(spanEvent => spanEvent.sequence === 2) @@ -412,7 +424,7 @@ test(`nested mysql2 async query with express`, async (t) => { actualBuilder = new MethodDescriptorBuilder('query') .setClassName('Connection') - .setLineNumber(337) + .setLineNumber(349) .setFileName('nested-async-trace.test.js') actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) actualSpanEvent = actualSpanChunk.spanEventList[1] @@ -493,11 +505,6 @@ test(`nested mysql2 async query with express`, async (t) => { } dataStreamCount = 0 - agent.setContinueAsyncContextTraceObjectCallback(async (trace) => { - const callerTrace = agent.getCallerTraceByAsyncId(trace.localAsyncId) - t.true(callerTrace !== undefined, 'parent trace is not undefined') - }) - const server = app.listen(5006, async () => { const result = await axios.get('http://localhost:5006/test1') t.equal(result.status, 200, 'status is 200') diff --git a/test/instrumentation/module/redis.test.js b/test/instrumentation/module/redis.test.js index f17c0cd9..f803e690 100644 --- a/test/instrumentation/module/redis.test.js +++ b/test/instrumentation/module/redis.test.js @@ -20,8 +20,6 @@ const apiMetaService = require('../../../lib/context/api-meta-service') const defaultPredefinedMethodDescriptorRegistry = require('../../../lib/constant/default-predefined-method-descriptor-registry') const ServiceType = require('../../../lib/context/service-type') const annotationKey = require('../../../lib/constant/annotation-key') -const localStorage = require('../../../lib/instrumentation/context/local-storage') -const { assertTrace } = require('../../fixture') const https = require('https') const TEST_ENV = { @@ -62,54 +60,19 @@ test(`${testName1} should Record the connections between express and redis.`, as var key = req.body.name var value = JSON.stringify(req.body) - let actualNextAsyncId - let actualSpanId req.cache.set(key, value, async function (err, data) { if (err) { console.log(err) res.send("error " + err) return } - const trace = localStorage.getStore() - axios.get(`https://www.naver.com`, { httpsAgent: new https.Agent({ keepAlive: false }) }) - .then(function (response) { - const actualHttpCallbackNextAsyncId = actualNextAsyncId - const actualHttpCallbackSpanChunk = trace.repository.dataSender.findSpanChunk(actualHttpCallbackNextAsyncId) - t.equal(actualHttpCallbackSpanChunk.traceRoot.getTraceId().getSpanId(), trace.traceRoot.getTraceId().getSpanId(), 'HTTP request callback spanId') - t.equal(actualHttpCallbackSpanChunk.getTraceRoot(), trace.getTraceRoot(), 'HTTP request callback transactionId') - t.equal(actualHttpCallbackSpanChunk.localAsyncId.asyncId, actualHttpCallbackNextAsyncId.asyncId, 'HTTP request callback localAsyncId.asyncId') - t.equal(actualHttpCallbackSpanChunk.localAsyncId.sequence, 1, 'HTTP request callback localAsyncId.sequence') - - let actualSpanEvent = actualHttpCallbackSpanChunk.spanEventList.find(spanEvent => spanEvent.sequence === 0) - t.equal(actualSpanEvent.apiId, defaultPredefinedMethodDescriptorRegistry.asyncInvocationDescriptor.apiId, 'HTTP request callback asyncInvocationDescriptor.spanEvent.apiId') - t.equal(actualSpanEvent.depth, 1, 'HTTP request callback asyncInvocationDescriptor.spanEvent.depth') - t.equal(actualSpanEvent.sequence, 0, 'HTTP request callback asyncInvocationDescriptor.spanEvent.sequence') - t.equal(actualSpanEvent.serviceType, ServiceType.async.getCode(), 'HTTP request callback asyncInvocationDescriptor.spanEvent.serviceType') - - actualSpanEvent = actualHttpCallbackSpanChunk.spanEventList.find(spanEvent => spanEvent.sequence === 1) - t.equal(actualSpanEvent.apiId, 0, 'HTTP request callback spanEvent.apiId') - t.equal(actualSpanEvent.depth, 2, 'HTTP request callback spanEvent.depth') - t.equal(actualSpanEvent.sequence, 1, 'HTTP request callback spanEvent.sequence') - t.equal(actualSpanEvent.serviceType, ServiceType.asyncHttpClient.getCode(), 'HTTP request callback spanEvent.serviceType') - - let actualAnnotation = actualSpanEvent.annotations[0] - t.equal(actualAnnotation.key, annotationKey.API.getCode(), 'HTTP request callback spanEvent.annotation[0].key') - t.equal(actualAnnotation.value, 'GET', 'HTTP request callback spanEvent.annotation[0].value') - actualAnnotation = actualSpanEvent.annotations[1] - t.equal(actualAnnotation.key, annotationKey.HTTP_URL.getCode(), 'HTTP request callback spanEvent.annotation[1].key annotationKey.HTTP_URL') - t.equal(actualAnnotation.value, 'www.naver.com/', 'HTTP request callback spanEvent.annotation[1].value annotationKey.HTTP_URL') - actualAnnotation = actualSpanEvent.annotations[2] - t.equal(actualAnnotation.key, annotationKey.HTTP_STATUS_CODE.getCode(), 'HTTP request callback spanEvent.annotation[2].key annotationKey.HTTP_STATUS_CODE') - t.equal(actualAnnotation.value, 200, 'HTTP request callback spanEvent.annotation[2].value annotationKey.HTTP_STATUS_CODE') - }) - req.cache.expire(key, 10) - agent.callbackTraceClose((trace) => { - let actualSpanChunk = trace.repository.dataSender.mockSpanChunks[0] - t.equal(actualSpanChunk.traceRoot.getTraceId().getSpanId(), trace.traceRoot.getTraceId().getSpanId(), 'spanId') - t.equal(actualSpanChunk.getTraceRoot(), trace.getTraceRoot(), 'transactionId') - t.equal(actualSpanChunk.localAsyncId.asyncId, actualNextAsyncId.asyncId, 'localAsyncId.asyncId') - t.equal(actualSpanChunk.localAsyncId.sequence, 1, 'localAsyncId.sequence') + agent.callbackTraceClose((childTrace) => { + let actualSpanChunk = childTrace.repository.dataSender.mockSpanChunks[0] + t.equal(actualSpanChunk.traceRoot.getTraceId().getSpanId(), childTrace.traceRoot.getTraceId().getSpanId(), 'spanId') + t.equal(actualSpanChunk.getTraceRoot(), childTrace.getTraceRoot(), 'transactionId') + t.equal(actualSpanChunk.localAsyncId.asyncId, childTrace.localAsyncId.asyncId, 'localAsyncId.asyncId') + t.equal(actualSpanChunk.localAsyncId.sequence, childTrace.localAsyncId.sequence, 'localAsyncId.sequence') let actualSpanEvent = actualSpanChunk.spanEventList.find(spanEvent => spanEvent.sequence === 0) t.equal(actualSpanEvent.apiId, defaultPredefinedMethodDescriptorRegistry.asyncInvocationDescriptor.apiId, 'apiId') @@ -125,25 +88,62 @@ test(`${testName1} should Record the connections between express and redis.`, as let actualAnnotation = actualSpanEvent.annotations.find(annotation => annotation.key === annotationKey.API.getCode()) t.equal(actualAnnotation.value, 'http.request', 'HTTP request annotation value') - actualNextAsyncId = actualSpanEvent.asyncId + }) - actualSpanEvent = actualSpanChunk.spanEventList.find(spanEvent => spanEvent.sequence === 2) - let actualBuilder = new MethodDescriptorBuilder('expire') - .setClassName('RedisClient') - let actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) - t.equal(actualMethodDescriptor.apiId, actualSpanEvent.apiId, 'RedisClient.expire apiId') - t.equal(actualMethodDescriptor.apiDescriptor, 'RedisClient.expire', 'RedisClient.expire apiDescriptor') - t.equal(actualMethodDescriptor.className, 'RedisClient', 'RedisClient.expire className') - t.equal(actualMethodDescriptor.methodName, 'expire', 'RedisClient.expire methodName') - t.equal(actualSpanEvent.sequence, 2, 'RedisClient.expire actualSpanEvent.sequence') - t.equal(actualSpanEvent.depth, 2, 'RedisClient.expire actualSpanEvent.depth') - t.equal(actualSpanEvent.serviceType, 8200, 'RedisClient.expire actualSpanEvent.serviceType') - t.equal(actualSpanEvent.destinationId, 'Redis', 'RedisClient.expire actualSpanEvent.destinationId') - t.equal(actualSpanEvent.endPoint, `localhost:${container.getMappedPort(6379)}`, 'RedisClient.expire actualSpanEvent.endPoint') + await axios.get(`https://www.naver.com`, { httpsAgent: new https.Agent({ keepAlive: false }) }) + req.cache.expire(key, 10, function (err, data) { + agent.callbackTraceClose((childTrace) => { + t.true(err === null, `expire callback err is null`) + let actualSpanEvent = agent.getSpanEventByAsyncId(childTrace.localAsyncId) + let actualBuilder = new MethodDescriptorBuilder('expire') + .setClassName('RedisClient') + let actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) + t.equal(actualMethodDescriptor.apiId, actualSpanEvent.apiId, 'RedisClient.expire apiId') + t.equal(actualMethodDescriptor.apiDescriptor, 'RedisClient.expire', 'RedisClient.expire apiDescriptor') + t.equal(actualMethodDescriptor.className, 'RedisClient', 'RedisClient.expire className') + t.equal(actualMethodDescriptor.methodName, 'expire', 'RedisClient.expire methodName') + t.equal(actualSpanEvent.sequence, 2, 'RedisClient.expire actualSpanEvent.sequence') + t.equal(actualSpanEvent.depth, 2, 'RedisClient.expire actualSpanEvent.depth') + t.equal(actualSpanEvent.serviceType, 8200, 'RedisClient.expire actualSpanEvent.serviceType') + t.equal(actualSpanEvent.destinationId, 'Redis', 'RedisClient.expire actualSpanEvent.destinationId') + t.equal(actualSpanEvent.endPoint, `localhost:${container.getMappedPort(6379)}`, 'RedisClient.expire actualSpanEvent.endPoint') + }) }) + + const childTrace = agent.currentTraceObject() + const actualHttpCallbackNextAsyncId = childTrace.repository.dataSender.mockSpanChunks[1].localAsyncId + const actualHttpCallbackSpanChunk = childTrace.repository.dataSender.findSpanChunk(actualHttpCallbackNextAsyncId) + t.equal(actualHttpCallbackSpanChunk.traceRoot.getTraceId().getSpanId(), childTrace.traceRoot.getTraceId().getSpanId(), 'HTTP request callback spanId') + t.equal(actualHttpCallbackSpanChunk.getTraceRoot(), childTrace.getTraceRoot(), 'HTTP request callback transactionId') + t.equal(actualHttpCallbackSpanChunk.localAsyncId.asyncId, actualHttpCallbackNextAsyncId.asyncId, 'HTTP request callback localAsyncId.asyncId') + t.equal(actualHttpCallbackSpanChunk.localAsyncId.sequence, 1, 'HTTP request callback localAsyncId.sequence') + + let actualSpanEvent = actualHttpCallbackSpanChunk.spanEventList.find(spanEvent => spanEvent.sequence === 0) + t.equal(actualSpanEvent.apiId, defaultPredefinedMethodDescriptorRegistry.asyncInvocationDescriptor.apiId, 'HTTP request callback asyncInvocationDescriptor.spanEvent.apiId') + t.equal(actualSpanEvent.depth, 1, 'HTTP request callback asyncInvocationDescriptor.spanEvent.depth') + t.equal(actualSpanEvent.sequence, 0, 'HTTP request callback asyncInvocationDescriptor.spanEvent.sequence') + t.equal(actualSpanEvent.serviceType, ServiceType.async.getCode(), 'HTTP request callback asyncInvocationDescriptor.spanEvent.serviceType') + + actualSpanEvent = actualHttpCallbackSpanChunk.spanEventList.find(spanEvent => spanEvent.sequence === 1) + t.equal(actualSpanEvent.apiId, 0, 'HTTP request callback spanEvent.apiId') + t.equal(actualSpanEvent.depth, 2, 'HTTP request callback spanEvent.depth') + t.equal(actualSpanEvent.sequence, 1, 'HTTP request callback spanEvent.sequence') + t.equal(actualSpanEvent.serviceType, ServiceType.asyncHttpClient.getCode(), 'HTTP request callback spanEvent.serviceType') + + let actualAnnotation = actualSpanEvent.annotations[0] + t.equal(actualAnnotation.key, annotationKey.API.getCode(), 'HTTP request callback spanEvent.annotation[0].key') + t.equal(actualAnnotation.value, 'GET', 'HTTP request callback spanEvent.annotation[0].value') + actualAnnotation = actualSpanEvent.annotations[1] + t.equal(actualAnnotation.key, annotationKey.HTTP_URL.getCode(), 'HTTP request callback spanEvent.annotation[1].key annotationKey.HTTP_URL') + t.equal(actualAnnotation.value, 'www.naver.com/', 'HTTP request callback spanEvent.annotation[1].value annotationKey.HTTP_URL') + actualAnnotation = actualSpanEvent.annotations[2] + t.equal(actualAnnotation.key, annotationKey.HTTP_STATUS_CODE.getCode(), 'HTTP request callback spanEvent.annotation[2].key annotationKey.HTTP_STATUS_CODE') + t.equal(actualAnnotation.value, 200, 'HTTP request callback spanEvent.annotation[2].value annotationKey.HTTP_STATUS_CODE') + + res.json(value) }) - assertTrace(trace => { + agent.callbackTraceClose(trace => { let actualBuilder = new MethodDescriptorBuilder('use') .setClassName('Router') let actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) @@ -193,10 +193,7 @@ test(`${testName1} should Record the connections between express and redis.`, as t.equal(actualSpanEvent.serviceType, 8200, 'serviceType') t.equal(actualSpanEvent.destinationId, 'Redis', 'destinationId') t.equal(actualSpanEvent.endPoint, `localhost:${container.getMappedPort(6379)}`, 'endPoint') - actualNextAsyncId = actualSpanEvent.asyncId - actualSpanId = trace.spanBuilder.traceRoot.getTraceId().getSpanId() }) - res.json(value) }) app.get(`${PATH}/:name`, function (req, res, next) { @@ -223,10 +220,12 @@ test(`${testName1} should Record the connections between express and redis.`, as const rstGet = await axios.get(getServerUrl(`${PATH}/jundol`)) t.ok(rstGet.status, 200) + t.end() + }) + t.teardown(async () => { client.quit() await container.stop() server.close() - t.end() }) }) @@ -403,7 +402,7 @@ test(`${testName3} should Record the connections between koa and redis.`, async const PATH = `/${testName}` app.use(koaBodyParser()) router.post(PATH, async function (ctx, next) { - console.log(ctx.request.body) + // console.log(ctx.request.body) const key = ctx.request.body.name const value = JSON.stringify(ctx.request.body) @@ -481,7 +480,7 @@ test(`${testName4} should Record the connections between koa and ioredis.`, asyn if (err) { console.error(err) } else { - console.log(result) + // console.log(result) } }) @@ -489,14 +488,14 @@ test(`${testName4} should Record the connections between koa and ioredis.`, asyn if (err) { console.error(err) } else { - console.log(result) + // console.log(result) } }) redis.get(key, (err, result) => { if (err) { console.error(err) } else { - console.log(result) + // console.log(result) } }) @@ -506,11 +505,8 @@ test(`${testName4} should Record the connections between koa and ioredis.`, asyn app.use(router.routes()).use(router.allowedMethods()) const server = app.listen(TEST_ENV.port, async () => { - console.log('Step1.') const rstPush = await axios.post(getServerUrl(PATH), redisData) t.ok(rstPush.status, 200) - - console.log('Step2.') const rstGet = await axios.get(getServerUrl(`${PATH}/jundol`)) t.ok(rstGet.status, 200) @@ -545,7 +541,7 @@ test(`${testName1} await connections between express and redis.`, async function res.send("error " + err) return } - assertTrace(async childTrace => { + agent.callbackTraceClose(async childTrace => { let actualSpanChunk = childTrace.repository.dataSender.mockSpanChunks[0] let actualNextAsyncId = trace.repository.buffer.find(spanEvent => spanEvent.sequence === 1).asyncId t.equal(actualSpanChunk.traceRoot.getTraceId().getSpanId(), traceRoot.getTraceId().getSpanId(), 'spanId') @@ -625,7 +621,7 @@ test(`${testName1} await connections between express and redis.`, async function res.json('ok') }) - assertTrace(trace => { + agent.callbackTraceClose(trace => { let actualBuilder = new MethodDescriptorBuilder('post') .setClassName('Router') let actualMethodDescriptor = apiMetaService.cacheApiWithBuilder(actualBuilder) diff --git a/test/pinpoint-config-test.json b/test/pinpoint-config-test.json index cf0436c9..b6177bec 100644 --- a/test/pinpoint-config-test.json +++ b/test/pinpoint-config-test.json @@ -15,7 +15,7 @@ "http-status-code-errors": [ "5xx" ], - "log-level": "WARN", + "log-level": "INFO", "enable": true, "enabled-data-sending": true, "enabled-stats-monitor-sending": false, diff --git a/test/support/agent-singleton-mock.js b/test/support/agent-singleton-mock.js index abb855c2..6be93d5c 100644 --- a/test/support/agent-singleton-mock.js +++ b/test/support/agent-singleton-mock.js @@ -32,14 +32,6 @@ const getTraces = () => { return traces } -let spanOrSpanChunks = [] -const resetSpanOrSpanChunks = () => { - spanOrSpanChunks = [] -} -const getSpanOrSpanChunks = () => { - return spanOrSpanChunks -} - let sendedApiMetaInfos = [] const resetSendedApiMetaInfos = () => { sendedApiMetaInfos = [] @@ -56,6 +48,20 @@ const getSqlMetadata = () => { return sqlMetadata } +const getSpanEvents = () => { + return getTraces().flatMap(trace => { + let spanEvents = trace.callStack.stack.concat(trace.repository.buffer) + if (trace.repository.spanChunkedSpanEvents) { + spanEvents = spanEvents.concat(trace.repository.spanChunkedSpanEvents) + } + return spanEvents + }) +} + +const getSpanEventByAsyncId = (asyncId) => { + return getSpanEvents().find(spanEvent => spanEvent.asyncId?.getAsyncId() === asyncId.getAsyncId()) +} + const getCallerTraceByAsyncId = (asyncId) => { return getTraces().find(trace => { let spanEvents = trace.callStack.stack.concat(trace.repository.buffer) @@ -134,16 +140,25 @@ class MockAgent extends Agent { apiMetaService.init(dataSender) sqlMetadataService.setDataSender(dataSender) - resetSpanOrSpanChunks() - resetTraces() - this.newTraceCallback = null - const getNewTraceCallback = () => { - return this.newTraceCallback + const findSpanEvents = function () { + let spanEvents = this.callStack.stack.concat(this.repository.buffer) + if (this.repository.spanChunkedSpanEvents) { + spanEvents = spanEvents.concat(this.repository.spanChunkedSpanEvents) + } + if (this.spanBuilder?.spanEventList) { + spanEvents = spanEvents.concat(this.spanBuilder.spanEventList) + } + return spanEvents + } + const findSpanEventByAsyncId = function (asyncId) { + return this.findSpanEvents().find(spanEvent => spanEvent.asyncId?.getAsyncId() === asyncId.getAsyncId()) } shimmer.wrap(this.traceContext, 'newTrace', function (origin) { return function () { const returned = origin.apply(this, arguments) + returned.findSpanEvents = findSpanEvents + returned.findSpanEventByAsyncId = findSpanEventByAsyncId const sendSpanChunkFunction = returned.repository.sendSpanChunk returned.repository.sendSpanChunk = function () { const result = sendSpanChunkFunction.apply(this, arguments) @@ -153,19 +168,22 @@ class MockAgent extends Agent { returned.repository.spanChunkedSpanEvents.push(arguments[0]) return result } - getNewTraceCallback()?.(returned) + const closeOrigin = returned.close + returned.close = function () { + const result = closeOrigin.apply(this, arguments) + returned.closeCallback?.(returned) + return result + } getTraces().push(returned) return returned } }) - this.continueAsyncContextTraceObjectCallback = null - const getContinueAsyncContextTraceObjectCallback = () => { - return this.continueAsyncContextTraceObjectCallback - } shimmer.wrap(this.traceContext, 'continueAsyncContextTraceObject', function (origin) { return function () { const returned = origin.apply(this, arguments) + returned.findSpanEvents = findSpanEvents + returned.findSpanEventByAsyncId = findSpanEventByAsyncId if (returned.repository) { const sendSpanChunkFunction = returned.repository.sendSpanChunk returned.repository.sendSpanChunk = function () { @@ -177,7 +195,12 @@ class MockAgent extends Agent { return result } } - getContinueAsyncContextTraceObjectCallback()?.(returned) + const closeOrigin = returned.close + returned.close = function () { + const result = closeOrigin.apply(this, arguments) + returned.closeCallback?.(returned) + return result + } getTraces().push(returned) return returned } @@ -236,12 +259,12 @@ class MockAgent extends Agent { return getTraces()[index] } - getSpanChunk(asyncId) { - return getSpanOrSpanChunks().find(spanOrSpanChunk => spanOrSpanChunk.getLocalasyncid().getAsyncid() === asyncId.getAsyncId() && spanOrSpanChunk.getLocalasyncid().getSequence() === asyncId.getSequence()) + getTraceByAsyncId(asyncId) { + return getTraces().find(trace => trace.findSpanEventByAsyncId(asyncId)) } - getSpanOrSpanChunks() { - return getSpanOrSpanChunks() + getSpanEventByAsyncId(asyncId) { + return getSpanEventByAsyncId(asyncId) } getSendedApiMetaInfos() { @@ -252,14 +275,6 @@ class MockAgent extends Agent { return getSqlMetadata() } - setNewTraceCallback(callback) { - this.newTraceCallback = callback - } - - setContinueAsyncContextTraceObjectCallback(callback) { - this.continueAsyncContextTraceObjectCallback = callback - } - getCallerTraceByAsyncId(asyncId) { return getCallerTraceByAsyncId(asyncId) }