From cc7e64ab56c1df957ba9f394bb15fb8661565790 Mon Sep 17 00:00:00 2001 From: Tomasz Pytel Date: Thu, 4 Mar 2021 10:59:59 -0300 Subject: [PATCH 1/8] WIP: fixing async and preparing child entry/exit --- src/plugins/AxiosPlugin.ts | 18 ++++-- src/plugins/ExpressPlugin.ts | 2 +- src/plugins/HttpPlugin.ts | 99 +++++++++++++++++++++++------ src/plugins/MongoDBPlugin.ts | 10 +-- src/plugins/MySQLPlugin.ts | 6 +- src/plugins/PgPlugin.ts | 10 +-- src/trace/context/ContextManager.ts | 20 +++--- src/trace/context/SpanContext.ts | 13 ++-- 8 files changed, 122 insertions(+), 56 deletions(-) diff --git a/src/plugins/AxiosPlugin.ts b/src/plugins/AxiosPlugin.ts index 60af986..0538f80 100644 --- a/src/plugins/AxiosPlugin.ts +++ b/src/plugins/AxiosPlugin.ts @@ -41,6 +41,8 @@ class AxiosPlugin implements SwPlugin { const { host, pathname: operation } = new URL(config.url); // TODO: this may throw invalid URL const span = ContextManager.current.newExitSpan(operation, host).start(); + let ret: any; + try { span.component = Component.AXIOS; span.layer = SpanLayer.HTTP; @@ -51,7 +53,7 @@ class AxiosPlugin implements SwPlugin { config.headers[item.key] = item.value; }); - const copyStatusAndStop = (response: any) => { + const copyStatus = (response: any) => { if (response) { if (response.status) { span.tag(Tag.httpStatusCode(response.status)); @@ -64,20 +66,20 @@ class AxiosPlugin implements SwPlugin { span.tag(Tag.httpStatusMsg(response.statusText)); } } - - span.stop(); }; - return defaultAdapter(config).then( + ret = defaultAdapter(config).then( (response: any) => { - copyStatusAndStop(response); + copyStatus(response); + span.stop(); return response; }, (error: any) => { + copyStatus(error.response); span.error(error); - copyStatusAndStop(error.response); + span.stop(); return Promise.reject(error); } @@ -89,6 +91,10 @@ class AxiosPlugin implements SwPlugin { throw e; } + + span.async(); + + return ret; } } } diff --git a/src/plugins/ExpressPlugin.ts b/src/plugins/ExpressPlugin.ts index 5a550e3..d84d5ef 100644 --- a/src/plugins/ExpressPlugin.ts +++ b/src/plugins/ExpressPlugin.ts @@ -59,7 +59,7 @@ class ExpressPlugin implements SwPlugin { if (res.statusCode && res.statusCode >= 400) { span.errored = true; } - if (err) { + if (err instanceof Error) { span.error(err); } if (res.statusMessage) { diff --git a/src/plugins/HttpPlugin.ts b/src/plugins/HttpPlugin.ts index 1d43b94..799ece1 100644 --- a/src/plugins/HttpPlugin.ts +++ b/src/plugins/HttpPlugin.ts @@ -61,7 +61,7 @@ class HttpPlugin implements SwPlugin { const operation = pathname.replace(/\?.*$/g, ''); let stopped = 0; // compensating if request aborted right after creation 'close' is not emitted - const stopIfNotStopped = () => !stopped++ ? span.stop() : null; // make sure we stop only once + const stopIfNotStopped = () => !stopped++ ? span.stop() : null; // make sure we stop only because other events may proc along with req.'close' const span: ExitSpan = ContextManager.current.newExitSpan(operation, host).start() as ExitSpan; try { @@ -81,39 +81,94 @@ class HttpPlugin implements SwPlugin { const req: ClientRequest = _request.apply(this, arguments); + + // TODO: req = http.request(...).on('response') if no callback provided. + + span.inject().items.forEach((item) => { req.setHeader(item.key, item.value); }); req.on('close', stopIfNotStopped); - req.on('abort', () => (span.errored = true, stopIfNotStopped())); + req.on('abort', () => (span.errored = true, span.log('Abort', true), stopIfNotStopped())); req.on('error', (err) => (span.error(err), stopIfNotStopped())); - req.prependListener('response', (res) => { + const _emit = req.emit; + + req.emit = function(name: any, ...args: any[]): any { + if (name !== 'response') + return _emit.call(this, name, ...args); + + let ret: any; + span.resync(); - span.tag(Tag.httpStatusCode(res.statusCode)); - if (res.statusCode && res.statusCode >= 400) { - span.errored = true; - } - if (res.statusMessage) { - span.tag(Tag.httpStatusMsg(res.statusMessage)); + try { + const res = args[0]; + + span.tag(Tag.httpStatusCode(res.statusCode)); + + if (res.statusCode && res.statusCode >= 400) { + span.errored = true; + } + if (res.statusMessage) { + span.tag(Tag.httpStatusMsg(res.statusMessage)); + } + + res.on('end', stopIfNotStopped); + + const _emitRes = res.emit; + + res.emit = function(nameRes: any, ...argsRes: any[]): any { + if (nameRes !== 'data') + return _emitRes.call(this, nameRes, ...argsRes); + + let retRes: any; + + span.resync(); + + try { + retRes = _emitRes.call(this, nameRes, ...argsRes); // 'data' events wrapped in resync + + } catch (err) { + span.error(err); + + + // TODO: sometimes not exiting + + + throw err; + + } finally { + span.async(); + } + + return retRes; + } + + ret = _emit.call(this, name, ...args); // 'response' events wrapped in resync + + } catch (err) { + span.error(err); + + throw err; + + } finally { + span.async(); } - res.on('end', stopIfNotStopped); - }); + return ret; + }; span.async(); return req; - } catch (e) { - if (!stopped) { // don't want to set error if exception occurs after clean close - span.error(e); - stopIfNotStopped(); - } + } catch (err) { + span.error(err); + stopIfNotStopped(); - throw e; + throw err; } }; } @@ -177,16 +232,18 @@ class HttpPlugin implements SwPlugin { span.stop(); return Promise.reject(error); - }) + }); + + span.async(); } return ret; - } catch (e) { - span.error(e); + } catch (err) { + span.error(err); span.stop(); - throw e; + throw err; } } }; diff --git a/src/plugins/MongoDBPlugin.ts b/src/plugins/MongoDBPlugin.ts index 009c1e2..7649229 100644 --- a/src/plugins/MongoDBPlugin.ts +++ b/src/plugins/MongoDBPlugin.ts @@ -41,13 +41,13 @@ class MongoDBPlugin implements SwPlugin { return false; cursor.on('error', (err: any) => { - span.resync(); // this may precede 'close' .resync() but its fine + // span.resync(); // this may precede 'close' .resync() but its fine span.error(err); span.stop(); }); cursor.on('close', () => { - span.resync(); // cursor does not .resync() until it is closed because maybe other exit spans will be opened during processing + // span.resync(); // cursor does not .resync() until it is closed because maybe other exit spans will be opened during processing span.stop(); }); @@ -67,7 +67,7 @@ class MongoDBPlugin implements SwPlugin { args[idx] = function(this: any, error: any, result: any) { if (error || !plugin.maybeHookCursor(span, result)) { - span.resync(); + // span.resync(); if (error) span.error(error); @@ -268,14 +268,14 @@ class MongoDBPlugin implements SwPlugin { } else { ret = ret.then( (res: any) => { - span.resync(); + // span.resync(); span.stop(); return res; }, (err: any) => { - span.resync(); + // span.resync(); span.error(err); span.stop(); diff --git a/src/plugins/MySQLPlugin.ts b/src/plugins/MySQLPlugin.ts index 35ebee0..0dd6d2d 100644 --- a/src/plugins/MySQLPlugin.ts +++ b/src/plugins/MySQLPlugin.ts @@ -36,7 +36,7 @@ class MySQLPlugin implements SwPlugin { Connection.prototype.query = function(sql: any, values: any, cb: any) { const wrapCallback = (_cb: any) => { return function(this: any, error: any, results: any, fields: any) { - span.resync(); + // span.resync(); if (error) span.error(error); @@ -122,12 +122,12 @@ class MySQLPlugin implements SwPlugin { if (streaming) { query.on('error', (e: any) => { - span.resync(); + // span.resync(); span.error(e); }); query.on('end', () => { - span.resync(); // may have already been done in 'error' but safe to do multiple times + // span.resync(); // may have already been done in 'error' but safe to do multiple times span.stop() }); } diff --git a/src/plugins/PgPlugin.ts b/src/plugins/PgPlugin.ts index 0d8f4e9..ca37731 100644 --- a/src/plugins/PgPlugin.ts +++ b/src/plugins/PgPlugin.ts @@ -43,7 +43,7 @@ class MySQLPlugin implements SwPlugin { Client.prototype.query = function(config: any, values: any, callback: any) { const wrapCallback = (_cb: any) => { return function(this: any, err: any, res: any) { - span.resync(); + // span.resync(); if (err) span.error(err); @@ -105,27 +105,27 @@ class MySQLPlugin implements SwPlugin { if (query) { if (Cursor && query instanceof Cursor) { query.on('error', (err: any) => { - span.resync(); // this may precede 'end' .resync() but its fine + // span.resync(); // this may precede 'end' .resync() but its fine span.error(err); span.stop(); }); query.on('end', () => { - span.resync(); // cursor does not .resync() until it is closed because maybe other exit spans will be opened during processing + // span.resync(); // cursor does not .resync() until it is closed because maybe other exit spans will be opened during processing span.stop(); }); } else if (typeof query.then === 'function') { // generic Promise check query = query.then( (res: any) => { - span.resync(); + // span.resync(); span.stop(); return res; }, (err: any) => { - span.resync(); + // span.resync(); span.error(err); span.stop(); diff --git a/src/trace/context/ContextManager.ts b/src/trace/context/ContextManager.ts index ef21803..91a2a49 100644 --- a/src/trace/context/ContextManager.ts +++ b/src/trace/context/ContextManager.ts @@ -23,7 +23,7 @@ import SpanContext from '../../trace/context/SpanContext'; import async_hooks from 'async_hooks'; -type AsyncState = { context: Context, spans: Span[], invalid: boolean }; +type AsyncState = { context: Context, spans: Span[] }; let store: { getStore(): AsyncState | undefined; @@ -59,15 +59,18 @@ if (async_hooks.AsyncLocalStorage) { class ContextManager { get asyncState(): AsyncState { let asyncState = store.getStore(); - // since `AsyncLocalStorage.getStore` may get previous state, see issue https://github.com/nodejs/node/issues/35286#issuecomment-697207158, so recreate when asyncState is invalid - if (asyncState === undefined || asyncState.invalid) { - asyncState = { context: new SpanContext(), spans: [], invalid: false }; + if (asyncState === undefined) { + asyncState = { context: new SpanContext(), spans: [] }; store.enterWith(asyncState); } return asyncState; } + get hasContext(): boolean { + return Boolean(store.getStore()); + } + get current(): Context { return this.asyncState.context; } @@ -79,10 +82,10 @@ class ContextManager { spansDup(): Span[] { let asyncState = store.getStore(); - if (asyncState === undefined || asyncState.invalid) { - asyncState = { context: new SpanContext(), spans: [], invalid: false }; + if (asyncState === undefined) { + asyncState = { context: new SpanContext(), spans: [] }; } else { - asyncState = { context: asyncState.context, spans: [...asyncState.spans], invalid: asyncState.invalid }; + asyncState = { context: asyncState.context, spans: [...asyncState.spans] }; } store.enterWith(asyncState); @@ -91,12 +94,11 @@ class ContextManager { } clear(): void { - this.asyncState.invalid = true; store.enterWith(undefined as unknown as AsyncState); } restore(context: Context, spans: Span[]): void { - store.enterWith({ context, spans: spans || [], invalid: this.asyncState.invalid }); + store.enterWith({ context, spans: spans || [] }); } withSpan(span: Span, callback: (...args: any[]) => any, ...args: any[]): any { diff --git a/src/trace/context/SpanContext.ts b/src/trace/context/SpanContext.ts index 20bf96c..81e253c 100644 --- a/src/trace/context/SpanContext.ts +++ b/src/trace/context/SpanContext.ts @@ -201,14 +201,15 @@ export default class SpanContext implements Context { nSpans: this.nSpans, }); - const idx = ContextManager.spans.indexOf(span); + const spans = ContextManager.spansDup(); // this needed to make sure async tasks created before this call will still have this span at the top of their span list + const idx = spans.indexOf(span); if (idx !== -1) { - ContextManager.spans.splice(idx, 1); - } + spans.splice(idx, 1); - if (this.nSpans === 1) { // this will pass the context to child async task so it doesn't mess with other tasks here - ContextManager.clear(); + if (!spans.length) { // this will pass the context to child async task so it doesn't mess with other tasks here + ContextManager.clear(); + } } } @@ -219,7 +220,7 @@ export default class SpanContext implements Context { nSpans: this.nSpans, }); - if ((span.context as SpanContext).nSpans === 1) { + if (!ContextManager.hasContext) { ContextManager.restore(span.context, [span]); } else if (ContextManager.spans.every((s) => s.id !== span.id)) { ContextManager.spans.push(span); From 9d2480fd916913b25a9247606a6169e8bd3d6c2b Mon Sep 17 00:00:00 2001 From: Tomasz Pytel Date: Thu, 4 Mar 2021 12:42:27 -0300 Subject: [PATCH 2/8] working properly --- src/plugins/HttpPlugin.ts | 8 -------- 1 file changed, 8 deletions(-) diff --git a/src/plugins/HttpPlugin.ts b/src/plugins/HttpPlugin.ts index 799ece1..b5bc93c 100644 --- a/src/plugins/HttpPlugin.ts +++ b/src/plugins/HttpPlugin.ts @@ -81,10 +81,6 @@ class HttpPlugin implements SwPlugin { const req: ClientRequest = _request.apply(this, arguments); - - // TODO: req = http.request(...).on('response') if no callback provided. - - span.inject().items.forEach((item) => { req.setHeader(item.key, item.value); }); @@ -133,10 +129,6 @@ class HttpPlugin implements SwPlugin { } catch (err) { span.error(err); - - // TODO: sometimes not exiting - - throw err; } finally { From f9518ae6ab733b95507abe93f7a467fe1421a6a4 Mon Sep 17 00:00:00 2001 From: Tomasz Pytel Date: Thu, 4 Mar 2021 16:33:45 -0300 Subject: [PATCH 3/8] plugin inheritance explicitly specified --- src/plugins/AMQPLibPlugin.ts | 2 +- src/plugins/AxiosPlugin.ts | 2 +- src/plugins/ExpressPlugin.ts | 2 +- src/plugins/HttpPlugin.ts | 2 +- src/plugins/MongoDBPlugin.ts | 8 +------- src/plugins/MySQLPlugin.ts | 6 +----- src/plugins/PgPlugin.ts | 8 +------- src/trace/context/Context.ts | 11 +++++++++-- src/trace/context/DummyContext.ts | 5 +++-- src/trace/context/SpanContext.ts | 12 ++++++++---- src/trace/span/Span.ts | 1 + 11 files changed, 28 insertions(+), 31 deletions(-) diff --git a/src/plugins/AMQPLibPlugin.ts b/src/plugins/AMQPLibPlugin.ts index accbc3c..794e620 100644 --- a/src/plugins/AMQPLibPlugin.ts +++ b/src/plugins/AMQPLibPlugin.ts @@ -44,7 +44,7 @@ class AMQPLibPlugin implements SwPlugin { const queue = fields.routingKey || ''; const peer = `${this.connection.stream.remoteAddress}:${this.connection.stream.remotePort}`; - const span = ContextManager.current.newExitSpan('RabbitMQ/' + topic + '/' + queue + '/Producer', peer).start(); + const span = ContextManager.current.newExitSpan('RabbitMQ/' + topic + '/' + queue + '/Producer', peer, Component.RABBITMQ_PRODUCER).start(); try { span.inject().items.forEach((item) => { diff --git a/src/plugins/AxiosPlugin.ts b/src/plugins/AxiosPlugin.ts index 0538f80..60369b3 100644 --- a/src/plugins/AxiosPlugin.ts +++ b/src/plugins/AxiosPlugin.ts @@ -39,7 +39,7 @@ class AxiosPlugin implements SwPlugin { defaults.adapter = (config: any) => { const { host, pathname: operation } = new URL(config.url); // TODO: this may throw invalid URL - const span = ContextManager.current.newExitSpan(operation, host).start(); + const span = ContextManager.current.newExitSpan(operation, host, Component.AXIOS, Component.HTTP).start(); let ret: any; diff --git a/src/plugins/ExpressPlugin.ts b/src/plugins/ExpressPlugin.ts index d84d5ef..9afd56f 100644 --- a/src/plugins/ExpressPlugin.ts +++ b/src/plugins/ExpressPlugin.ts @@ -49,7 +49,7 @@ class ExpressPlugin implements SwPlugin { const carrier = ContextCarrier.from(headersMap); const operation = (req.url || '/').replace(/\?.*/g, ''); - const span = ContextManager.current.newEntrySpan(operation, carrier).start(); + const span = ContextManager.current.newEntrySpan(operation, carrier, Component.HTTP_SERVER).start(); let stopped = 0; const stopIfNotStopped = (err: Error | null) => { diff --git a/src/plugins/HttpPlugin.ts b/src/plugins/HttpPlugin.ts index b5bc93c..9baa1d0 100644 --- a/src/plugins/HttpPlugin.ts +++ b/src/plugins/HttpPlugin.ts @@ -62,7 +62,7 @@ class HttpPlugin implements SwPlugin { let stopped = 0; // compensating if request aborted right after creation 'close' is not emitted const stopIfNotStopped = () => !stopped++ ? span.stop() : null; // make sure we stop only because other events may proc along with req.'close' - const span: ExitSpan = ContextManager.current.newExitSpan(operation, host).start() as ExitSpan; + const span: ExitSpan = ContextManager.current.newExitSpan(operation, host, Component.HTTP).start() as ExitSpan; try { if (span.depth === 1) { // only set HTTP if this span is not overridden by a higher level one diff --git a/src/plugins/MongoDBPlugin.ts b/src/plugins/MongoDBPlugin.ts index 7649229..136bbc5 100644 --- a/src/plugins/MongoDBPlugin.ts +++ b/src/plugins/MongoDBPlugin.ts @@ -41,13 +41,11 @@ class MongoDBPlugin implements SwPlugin { return false; cursor.on('error', (err: any) => { - // span.resync(); // this may precede 'close' .resync() but its fine span.error(err); span.stop(); }); cursor.on('close', () => { - // span.resync(); // cursor does not .resync() until it is closed because maybe other exit spans will be opened during processing span.stop(); }); @@ -67,8 +65,6 @@ class MongoDBPlugin implements SwPlugin { args[idx] = function(this: any, error: any, result: any) { if (error || !plugin.maybeHookCursor(span, result)) { - // span.resync(); - if (error) span.error(error); @@ -242,7 +238,7 @@ class MongoDBPlugin implements SwPlugin { host = '???'; } - span = ContextManager.current.newExitSpan('MongoDB/' + operation, host).start(); + span = ContextManager.current.newExitSpan('MongoDB/' + operation, host, Component.MONGODB).start(); try { span.component = Component.MONGODB; @@ -268,14 +264,12 @@ class MongoDBPlugin implements SwPlugin { } else { ret = ret.then( (res: any) => { - // span.resync(); span.stop(); return res; }, (err: any) => { - // span.resync(); span.error(err); span.stop(); diff --git a/src/plugins/MySQLPlugin.ts b/src/plugins/MySQLPlugin.ts index 0dd6d2d..2b0dc8c 100644 --- a/src/plugins/MySQLPlugin.ts +++ b/src/plugins/MySQLPlugin.ts @@ -36,8 +36,6 @@ class MySQLPlugin implements SwPlugin { Connection.prototype.query = function(sql: any, values: any, cb: any) { const wrapCallback = (_cb: any) => { return function(this: any, error: any, results: any, fields: any) { - // span.resync(); - if (error) span.error(error); @@ -50,7 +48,7 @@ class MySQLPlugin implements SwPlugin { let query: any; const host = `${this.config.host}:${this.config.port}`; - const span = ContextManager.current.newExitSpan('mysql/query', host).start(); + const span = ContextManager.current.newExitSpan('mysql/query', host, Component.MYSQL).start(); try { span.component = Component.MYSQL; @@ -122,12 +120,10 @@ class MySQLPlugin implements SwPlugin { if (streaming) { query.on('error', (e: any) => { - // span.resync(); span.error(e); }); query.on('end', () => { - // span.resync(); // may have already been done in 'error' but safe to do multiple times span.stop() }); } diff --git a/src/plugins/PgPlugin.ts b/src/plugins/PgPlugin.ts index ca37731..8374688 100644 --- a/src/plugins/PgPlugin.ts +++ b/src/plugins/PgPlugin.ts @@ -43,8 +43,6 @@ class MySQLPlugin implements SwPlugin { Client.prototype.query = function(config: any, values: any, callback: any) { const wrapCallback = (_cb: any) => { return function(this: any, err: any, res: any) { - // span.resync(); - if (err) span.error(err); @@ -57,7 +55,7 @@ class MySQLPlugin implements SwPlugin { let query: any; const host = `${this.host}:${this.port}`; - const span = ContextManager.current.newExitSpan('pg/query', host).start(); + const span = ContextManager.current.newExitSpan('pg/query', host, Component.POSTGRESQL).start(); try { span.component = Component.POSTGRESQL; @@ -105,27 +103,23 @@ class MySQLPlugin implements SwPlugin { if (query) { if (Cursor && query instanceof Cursor) { query.on('error', (err: any) => { - // span.resync(); // this may precede 'end' .resync() but its fine span.error(err); span.stop(); }); query.on('end', () => { - // span.resync(); // cursor does not .resync() until it is closed because maybe other exit spans will be opened during processing span.stop(); }); } else if (typeof query.then === 'function') { // generic Promise check query = query.then( (res: any) => { - // span.resync(); span.stop(); return res; }, (err: any) => { - // span.resync(); span.error(err); span.stop(); diff --git a/src/trace/context/Context.ts b/src/trace/context/Context.ts index 8a23252..af0b678 100644 --- a/src/trace/context/Context.ts +++ b/src/trace/context/Context.ts @@ -19,6 +19,7 @@ import Span from '../../trace/span/Span'; import Segment from '../../trace/context/Segment'; +import { Component } from '../../trace/Component'; import { ContextCarrier } from './ContextCarrier'; export default interface Context { @@ -26,9 +27,15 @@ export default interface Context { newLocalSpan(operation: string): Span; - newEntrySpan(operation: string, carrier?: ContextCarrier): Span; + /* If 'inherit' is specified then if the span at the top of the stack is an Entry span of this component type then the + span is reused instead of a new child span being created. This is intended for situations like an express handler + inheriting an opened incoming http connection to present a single span. */ + newEntrySpan(operation: string, carrier?: ContextCarrier, inherit?: Component): Span; - newExitSpan(operation: string, peer: string): Span; + /* if 'inherit' is specified then the span returned is marked for inheritance by an Exit span component which is + created later and calls this function with a matching 'component' value. For example Axios using an Http exit + connection will be merged into a single exit span, see those plugins for how this is done. */ + newExitSpan(operation: string, peer: string, component: Component, inherit?: Component): Span; start(span: Span): Context; diff --git a/src/trace/context/DummyContext.ts b/src/trace/context/DummyContext.ts index b64a1dd..50d802a 100644 --- a/src/trace/context/DummyContext.ts +++ b/src/trace/context/DummyContext.ts @@ -21,6 +21,7 @@ import Context from '../../trace/context/Context'; import Span from '../../trace/span/Span'; import DummySpan from '../../trace/span/DummySpan'; import Segment from '../../trace/context/Segment'; +import { Component } from '../../trace/Component'; import { SpanType } from '../../proto/language-agent/Tracing_pb'; import { ContextCarrier } from './ContextCarrier'; @@ -33,11 +34,11 @@ export default class DummyContext implements Context { segment: Segment = new Segment(); depth = 0; - newEntrySpan(operation: string, carrier?: ContextCarrier): Span { + newEntrySpan(operation: string, carrier?: ContextCarrier, inherit?: Component): Span { return this.span; } - newExitSpan(operation: string, peer: string): Span { + newExitSpan(operation: string, peer: string, component: Component, inherit?: Component): Span { return this.span; } diff --git a/src/trace/context/SpanContext.ts b/src/trace/context/SpanContext.ts index 81e253c..0421d53 100644 --- a/src/trace/context/SpanContext.ts +++ b/src/trace/context/SpanContext.ts @@ -26,6 +26,7 @@ import Segment from '../../trace/context/Segment'; import EntrySpan from '../../trace/span/EntrySpan'; import ExitSpan from '../../trace/span/ExitSpan'; import LocalSpan from '../../trace/span/LocalSpan'; +import { Component } from '../../trace/Component'; import { createLogger } from '../../logging'; import { executionAsyncId } from 'async_hooks'; import { ContextCarrier } from './ContextCarrier'; @@ -63,7 +64,7 @@ export default class SpanContext implements Context { return undefined; } - newEntrySpan(operation: string, carrier?: ContextCarrier): Span { + newEntrySpan(operation: string, carrier?: ContextCarrier, inherit?: Component): Span { let span = this.ignoreCheck(operation, SpanType.ENTRY); if (span) @@ -79,7 +80,7 @@ export default class SpanContext implements Context { }); } - if (parent && parent.type === SpanType.ENTRY) { + if (parent && parent.type === SpanType.ENTRY && inherit && inherit === parent.component) { span = parent; parent.operation = operation; @@ -99,7 +100,7 @@ export default class SpanContext implements Context { return span; } - newExitSpan(operation: string, peer: string): Span { + newExitSpan(operation: string, peer: string, component: Component, inherit?: Component): Span { let span = this.ignoreCheck(operation, SpanType.EXIT); if (span) @@ -117,7 +118,7 @@ export default class SpanContext implements Context { }); } - if (parent && parent.type === SpanType.EXIT) { + if (parent && parent.type === SpanType.EXIT && component === parent.inherit) { span = parent; } else { @@ -130,6 +131,9 @@ export default class SpanContext implements Context { }); } + if (inherit) + span.inherit = inherit; + return span; } diff --git a/src/trace/span/Span.ts b/src/trace/span/Span.ts index 1af5383..a03808c 100644 --- a/src/trace/span/Span.ts +++ b/src/trace/span/Span.ts @@ -50,6 +50,7 @@ export default abstract class Span { operation: string; layer = SpanLayer.UNKNOWN; component = Component.UNKNOWN; + inherit?: Component; readonly tags: Tag[] = []; readonly logs: Log[] = []; From 5425181355befdca5f05994bc5dc70b07dbfcd6b Mon Sep 17 00:00:00 2001 From: Tomasz Pytel Date: Fri, 5 Mar 2021 10:18:22 -0300 Subject: [PATCH 4/8] restored invalid flag --- src/trace/context/ContextManager.ts | 21 ++++++++++++--------- 1 file changed, 12 insertions(+), 9 deletions(-) diff --git a/src/trace/context/ContextManager.ts b/src/trace/context/ContextManager.ts index 91a2a49..96fd23e 100644 --- a/src/trace/context/ContextManager.ts +++ b/src/trace/context/ContextManager.ts @@ -23,7 +23,7 @@ import SpanContext from '../../trace/context/SpanContext'; import async_hooks from 'async_hooks'; -type AsyncState = { context: Context, spans: Span[] }; +type AsyncState = { context: Context, spans: Span[], valid: boolean }; let store: { getStore(): AsyncState | undefined; @@ -58,17 +58,19 @@ if (async_hooks.AsyncLocalStorage) { class ContextManager { get asyncState(): AsyncState { + // since `AsyncLocalStorage.getStore` may get previous state, see issue https://github.com/nodejs/node/issues/35286#issuecomment-697207158, so recreate when asyncState is not valid + // Necessary because span may "finish()" in a child async task of where the asyncState was actually created and so clearing in the child would not clear in parent and invalid asyncState would be reused in new children of that parent. let asyncState = store.getStore(); - if (asyncState === undefined) { - asyncState = { context: new SpanContext(), spans: [] }; + if (!asyncState?.valid) { + asyncState = { context: new SpanContext(), spans: [], valid: true }; store.enterWith(asyncState); } return asyncState; } - get hasContext(): boolean { - return Boolean(store.getStore()); + get hasContext(): boolean | undefined { + return store.getStore()?.valid; } get current(): Context { @@ -82,10 +84,10 @@ class ContextManager { spansDup(): Span[] { let asyncState = store.getStore(); - if (asyncState === undefined) { - asyncState = { context: new SpanContext(), spans: [] }; + if (!asyncState?.valid) { + asyncState = { context: new SpanContext(), spans: [], valid: true }; } else { - asyncState = { context: asyncState.context, spans: [...asyncState.spans] }; + asyncState = { context: asyncState.context, spans: [...asyncState.spans], valid: asyncState.valid }; } store.enterWith(asyncState); @@ -94,11 +96,12 @@ class ContextManager { } clear(): void { + this.asyncState.valid = false; store.enterWith(undefined as unknown as AsyncState); } restore(context: Context, spans: Span[]): void { - store.enterWith({ context, spans: spans || [] }); + store.enterWith({ context, spans: spans || [], valid: this.asyncState.valid }); } withSpan(span: Span, callback: (...args: any[]) => any, ...args: any[]): any { From a596f8cc99d76b2fcb054ac078a41048cae90473 Mon Sep 17 00:00:00 2001 From: Tomasz Pytel Date: Fri, 5 Mar 2021 15:53:28 -0300 Subject: [PATCH 5/8] added sw_agent_disable_plugins --- README.md | 3 ++- src/config/AgentConfig.ts | 24 +++++++++++++++--------- src/core/PluginInstaller.ts | 6 ++++++ src/plugins/MongoDBPlugin.ts | 10 +++++----- src/plugins/MySQLPlugin.ts | 6 +++--- src/plugins/PgPlugin.ts | 6 +++--- 6 files changed, 34 insertions(+), 21 deletions(-) diff --git a/README.md b/README.md index 721b054..e25c0f5 100644 --- a/README.md +++ b/README.md @@ -54,7 +54,8 @@ Environment Variable | Description | Default | `SW_AGENT_INSTANCE` | The name of the service instance | Randomly generated | | `SW_AGENT_COLLECTOR_BACKEND_SERVICES` | The backend OAP server address | `127.0.0.1:11800` | | `SW_AGENT_AUTHENTICATION` | The authentication token to verify that the agent is trusted by the backend OAP, as for how to configure the backend, refer to [the yaml](https://github.com/apache/skywalking/blob/4f0f39ffccdc9b41049903cc540b8904f7c9728e/oap-server/server-bootstrap/src/main/resources/application.yml#L155-L158). | not set | -| `SW_AGENT_LOGGING_LEVEL` | The logging level, could be one of `CRITICAL`, `FATAL`, `ERROR`, `WARN`(`WARNING`), `INFO`, `DEBUG` | `INFO` | +| `SW_AGENT_LOGGING_LEVEL` | The logging level, could be one of `error`, `warn`, `info`, `debug` | `info` | +| `SW_AGENT_DISABLE_PLUGINS` | Comma-delimited list of plugins to disable in the plugins directory (e.g. "mysql", "express"). | `` | | `SW_IGNORE_SUFFIX` | The suffices of endpoints that will be ignored (not traced), comma separated | `.jpg,.jpeg,.js,.css,.png,.bmp,.gif,.ico,.mp3,.mp4,.html,.svg` | | `SW_TRACE_IGNORE_PATH` | The paths of endpoints that will be ignored (not traced), comma separated | `` | | `SW_SQL_TRACE_PARAMETERS` | If set to 'true' then SQL query parameters will be included | `false` | diff --git a/src/config/AgentConfig.ts b/src/config/AgentConfig.ts index 349e13a..2b631b8 100644 --- a/src/config/AgentConfig.ts +++ b/src/config/AgentConfig.ts @@ -25,19 +25,23 @@ export type AgentConfig = { collectorAddress?: string; authorization?: string; maxBufferSize?: number; + disablePlugins?: string; ignoreSuffix?: string; traceIgnorePath?: string; - sql_trace_parameters?: boolean; - sql_parameters_max_length?: number; - mongo_trace_parameters?: boolean; - mongo_parameters_max_length?: number; + sqlTraceParameters?: boolean; + sqlParametersMaxLength?: number; + mongoTraceParameters?: boolean; + mongoParametersMaxLength?: number; // the following is internal state computed from config values + reDisablePlugins?: RegExp; reIgnoreOperation?: RegExp; }; export function finalizeConfig(config: AgentConfig): void { const escapeRegExp = (s: string) => s.replace(/([.*+?^=!:${}()|\[\]\/\\])/g, "\\$1"); + config.reDisablePlugins = RegExp(`^(?:${config.disablePlugins!.split(',').map((s) => escapeRegExp(s.trim()) + 'Plugin\\.js').join('|')})$`, 'i'); + const ignoreSuffix =`^.+(?:${config.ignoreSuffix!.split(',').map((s) => escapeRegExp(s.trim())).join('|')})$`; const ignorePath = '^(?:' + config.traceIgnorePath!.split(',').map( (s1) => s1.trim().split('**').map( @@ -61,11 +65,13 @@ export default { authorization: process.env.SW_AGENT_AUTHENTICATION, maxBufferSize: Number.isSafeInteger(process.env.SW_AGENT_MAX_BUFFER_SIZE) ? Number.parseInt(process.env.SW_AGENT_MAX_BUFFER_SIZE as string, 10) : 1000, + disablePlugins: process.env.SW_AGENT_DISABLE_PLUGINS || '', ignoreSuffix: process.env.SW_IGNORE_SUFFIX ?? '.jpg,.jpeg,.js,.css,.png,.bmp,.gif,.ico,.mp3,.mp4,.html,.svg', traceIgnorePath: process.env.SW_TRACE_IGNORE_PATH || '', - sql_trace_parameters: (process.env.SW_SQL_TRACE_PARAMETERS || '').toLowerCase() === 'true', - sql_parameters_max_length: Math.trunc(Math.max(0, Number(process.env.SW_SQL_PARAMETERS_MAX_LENGTH))) || 512, - mongo_trace_parameters: (process.env.SW_MONGO_TRACE_PARAMETERS || '').toLowerCase() === 'true', - mongo_parameters_max_length: Math.trunc(Math.max(0, Number(process.env.SW_MONGO_PARAMETERS_MAX_LENGTH))) || 512, - reIgnoreOperation: RegExp(''), // temporary placeholder so Typescript doesn't throw a fit + sqlTraceParameters: (process.env.SW_SQL_TRACE_PARAMETERS || '').toLowerCase() === 'true', + sqlParametersMaxLength: Math.trunc(Math.max(0, Number(process.env.SW_SQL_PARAMETERS_MAX_LENGTH))) || 512, + mongoTraceParameters: (process.env.SW_MONGO_TRACE_PARAMETERS || '').toLowerCase() === 'true', + mongoParametersMaxLength: Math.trunc(Math.max(0, Number(process.env.SW_MONGO_PARAMETERS_MAX_LENGTH))) || 512, + reDisablePlugins: RegExp(''), // temporary placeholder so Typescript doesn't throw a fit + reIgnoreOperation: RegExp(''), }; diff --git a/src/core/PluginInstaller.ts b/src/core/PluginInstaller.ts index 820b2bc..c42dfcc 100644 --- a/src/core/PluginInstaller.ts +++ b/src/core/PluginInstaller.ts @@ -22,6 +22,7 @@ import * as path from 'path'; import SwPlugin from '../core/SwPlugin'; import { createLogger } from '../logging'; import * as semver from 'semver'; +import config from '../config/AgentConfig'; const logger = createLogger(__filename); @@ -76,6 +77,11 @@ export default class PluginInstaller { fs.readdirSync(this.pluginDir) .filter((file) => !(file.endsWith('.d.ts') || file.endsWith('.js.map'))) .forEach((file) => { + if (file.match(config.reDisablePlugins)) { + logger.info(`Plugin ${file} not installed because it is disabled`); + return; + } + let plugin; const pluginFile = path.join(this.pluginDir, file); diff --git a/src/plugins/MongoDBPlugin.ts b/src/plugins/MongoDBPlugin.ts index 136bbc5..c0de1ed 100644 --- a/src/plugins/MongoDBPlugin.ts +++ b/src/plugins/MongoDBPlugin.ts @@ -83,8 +83,8 @@ class MongoDBPlugin implements SwPlugin { let str = JSON.stringify(params); - if (str.length > agentConfig.mongo_parameters_max_length) - str = str.slice(0, agentConfig.mongo_parameters_max_length) + ' ...'; + if (str.length > agentConfig.mongoParametersMaxLength) + str = str.slice(0, agentConfig.mongoParametersMaxLength) + ' ...'; return str; } @@ -92,7 +92,7 @@ class MongoDBPlugin implements SwPlugin { const insertFunc = function(this: any, operation: string, span: any, args: any[]): boolean { // args = [doc(s), options, callback] span.tag(Tag.dbStatement(`${this.s.namespace.collection}.${operation}()`)); - if (agentConfig.mongo_trace_parameters) + if (agentConfig.mongoTraceParameters) span.tag(Tag.dbMongoParameters(stringify(args[0]))); return wrapCallback(span, args, 1); @@ -107,7 +107,7 @@ class MongoDBPlugin implements SwPlugin { const updateFunc = function(this: any, operation: string, span: any, args: any[]): boolean { // args = [filter, update, options, callback] span.tag(Tag.dbStatement(`${this.s.namespace.collection}.${operation}(${stringify(args[0])})`)); - if (agentConfig.mongo_trace_parameters) + if (agentConfig.mongoTraceParameters) span.tag(Tag.dbMongoParameters(stringify(args[1]))); return wrapCallback(span, args, 2); @@ -132,7 +132,7 @@ class MongoDBPlugin implements SwPlugin { params += ', ' + stringify(args[1]); if (typeof args[2] !== 'function' && args[2] !== undefined) { - if (agentConfig.mongo_trace_parameters) + if (agentConfig.mongoTraceParameters) span.tag(Tag.dbMongoParameters(stringify(args[2]))); } } diff --git a/src/plugins/MySQLPlugin.ts b/src/plugins/MySQLPlugin.ts index 2b0dc8c..b6f4826 100644 --- a/src/plugins/MySQLPlugin.ts +++ b/src/plugins/MySQLPlugin.ts @@ -107,11 +107,11 @@ class MySQLPlugin implements SwPlugin { span.tag(Tag.dbStatement(`${_sql}`)); - if (agentConfig.sql_trace_parameters && _values) { + if (agentConfig.sqlTraceParameters && _values) { let vals = _values.map((v: any) => v === undefined ? 'undefined' : JSON.stringify(v)).join(', '); - if (vals.length > agentConfig.sql_parameters_max_length) - vals = vals.slice(0, agentConfig.sql_parameters_max_length) + ' ...'; + if (vals.length > agentConfig.sqlParametersMaxLength) + vals = vals.slice(0, agentConfig.sqlParametersMaxLength) + ' ...'; span.tag(Tag.dbSqlParameters(`[${vals}]`)); } diff --git a/src/plugins/PgPlugin.ts b/src/plugins/PgPlugin.ts index 8374688..ed6415a 100644 --- a/src/plugins/PgPlugin.ts +++ b/src/plugins/PgPlugin.ts @@ -89,11 +89,11 @@ class MySQLPlugin implements SwPlugin { span.tag(Tag.dbStatement(`${_sql}`)); - if (agentConfig.sql_trace_parameters && _values) { + if (agentConfig.sqlTraceParameters && _values) { let vals = _values.map((v: any) => v === undefined ? 'undefined' : JSON.stringify(v)).join(', '); - if (vals.length > agentConfig.sql_parameters_max_length) - vals = vals.slice(0, agentConfig.sql_parameters_max_length) + ' ...'; + if (vals.length > agentConfig.sqlParametersMaxLength) + vals = vals.slice(0, agentConfig.sqlParametersMaxLength) + ' ...'; span.tag(Tag.dbSqlParameters(`[${vals}]`)); } From 30f465fb693faff6c8e2e829553bb21f9a9f596f Mon Sep 17 00:00:00 2001 From: Tomasz Pytel Date: Sun, 7 Mar 2021 12:40:28 -0300 Subject: [PATCH 6/8] HttpPlugin simplified, outgoing protocol in url --- src/plugins/HttpPlugin.ts | 64 +++++++++++---------------- tests/plugins/http/expected.data.yaml | 4 +- 2 files changed, 28 insertions(+), 40 deletions(-) diff --git a/src/plugins/HttpPlugin.ts b/src/plugins/HttpPlugin.ts index 9baa1d0..3b9da38 100644 --- a/src/plugins/HttpPlugin.ts +++ b/src/plugins/HttpPlugin.ts @@ -35,13 +35,13 @@ class HttpPlugin implements SwPlugin { const http = require('http'); const https = require('https'); - this.interceptClientRequest(http); + this.interceptClientRequest(http, 'http'); this.interceptServerRequest(http, 'http'); - this.interceptClientRequest(https); + this.interceptClientRequest(https, 'https'); this.interceptServerRequest(https, 'https'); } - private interceptClientRequest(module: any) { + private interceptClientRequest(module: any, protocol: string) { const _request = module.request; module.request = function () { @@ -57,7 +57,7 @@ class HttpPlugin implements SwPlugin { pathname: url.path || '/', }; const httpMethod = arguments[url instanceof URL || typeof url === 'string' ? 1 : 0]?.method || 'GET'; - const httpURL = host + pathname; + const httpURL = protocol + '://' + host + pathname; const operation = pathname.replace(/\?.*$/g, ''); let stopped = 0; // compensating if request aborted right after creation 'close' is not emitted @@ -92,53 +92,43 @@ class HttpPlugin implements SwPlugin { const _emit = req.emit; req.emit = function(name: any, ...args: any[]): any { - if (name !== 'response') - return _emit.call(this, name, ...args); - - let ret: any; - span.resync(); try { - const res = args[0]; - - span.tag(Tag.httpStatusCode(res.statusCode)); - - if (res.statusCode && res.statusCode >= 400) { - span.errored = true; - } - if (res.statusMessage) { - span.tag(Tag.httpStatusMsg(res.statusMessage)); - } + if (name === 'response') { + const res = args[0]; - res.on('end', stopIfNotStopped); + span.tag(Tag.httpStatusCode(res.statusCode)); - const _emitRes = res.emit; + if (res.statusCode && res.statusCode >= 400) { + span.errored = true; + } + if (res.statusMessage) { + span.tag(Tag.httpStatusMsg(res.statusMessage)); + } - res.emit = function(nameRes: any, ...argsRes: any[]): any { - if (nameRes !== 'data') - return _emitRes.call(this, nameRes, ...argsRes); + res.on('end', stopIfNotStopped); - let retRes: any; + const _emitRes = res.emit; - span.resync(); + res.emit = function(nameRes: any, ...argsRes: any[]): any { + span.resync(); - try { - retRes = _emitRes.call(this, nameRes, ...argsRes); // 'data' events wrapped in resync + try { + return _emitRes.call(this, nameRes, ...argsRes); - } catch (err) { - span.error(err); + } catch (err) { + span.error(err); - throw err; + throw err; - } finally { - span.async(); + } finally { + span.async(); + } } - - return retRes; } - ret = _emit.call(this, name, ...args); // 'response' events wrapped in resync + return _emit.call(this, name, ...args); } catch (err) { span.error(err); @@ -148,8 +138,6 @@ class HttpPlugin implements SwPlugin { } finally { span.async(); } - - return ret; }; span.async(); diff --git a/tests/plugins/http/expected.data.yaml b/tests/plugins/http/expected.data.yaml index 486b6ce..a3580e6 100644 --- a/tests/plugins/http/expected.data.yaml +++ b/tests/plugins/http/expected.data.yaml @@ -61,7 +61,7 @@ segmentItems: skipAnalysis: false tags: - key: http.url - value: httpbin.org/json + value: http://httpbin.org/json - key: http.method value: GET - key: http.status.code @@ -104,7 +104,7 @@ segmentItems: skipAnalysis: false tags: - key: http.url - value: server:5000/test + value: http://server:5000/test - key: http.method value: GET - key: http.status.code From f1864b3f98863deef8f107286f8ea987d6d5ffad Mon Sep 17 00:00:00 2001 From: Tomasz Pytel Date: Sun, 7 Mar 2021 18:46:00 -0300 Subject: [PATCH 7/8] improving http plugin --- src/plugins/HttpPlugin.ts | 109 ++++++++++------------- tests/plugins/axios/expected.data.yaml | 64 ++++++------- tests/plugins/express/expected.data.yaml | 66 +++++++------- tests/plugins/http/expected.data.yaml | 4 + tests/plugins/mongodb/expected.data.yaml | 3 +- tests/plugins/mysql/expected.data.yaml | 42 +++++---- tests/plugins/pg/expected.data.yaml | 34 +++---- 7 files changed, 160 insertions(+), 162 deletions(-) diff --git a/src/plugins/HttpPlugin.ts b/src/plugins/HttpPlugin.ts index 3b9da38..39e0dc3 100644 --- a/src/plugins/HttpPlugin.ts +++ b/src/plugins/HttpPlugin.ts @@ -42,7 +42,7 @@ class HttpPlugin implements SwPlugin { } private interceptClientRequest(module: any, protocol: string) { - const _request = module.request; + const _request = module.request; // BUG! this doesn't work with "import {request} from http", but haven't found an alternative yet module.request = function () { const url: URL | string | RequestOptions = arguments[0]; @@ -56,12 +56,11 @@ class HttpPlugin implements SwPlugin { host: (url.host || url.hostname || 'unknown') + ':' + (url.port || 80), pathname: url.path || '/', }; - const httpMethod = arguments[url instanceof URL || typeof url === 'string' ? 1 : 0]?.method || 'GET'; - const httpURL = protocol + '://' + host + pathname; - const operation = pathname.replace(/\?.*$/g, ''); - let stopped = 0; // compensating if request aborted right after creation 'close' is not emitted - const stopIfNotStopped = () => !stopped++ ? span.stop() : null; // make sure we stop only because other events may proc along with req.'close' + const httpMethod = arguments[url instanceof URL || typeof url === 'string' ? 1 : 0]?.method || 'GET'; + const httpURL = protocol + '://' + host + pathname; + const operation = pathname.replace(/\?.*$/g, ''); + const span: ExitSpan = ContextManager.current.newExitSpan(operation, host, Component.HTTP).start() as ExitSpan; try { @@ -69,53 +68,50 @@ class HttpPlugin implements SwPlugin { span.component = Component.HTTP; span.layer = SpanLayer.HTTP; } - if (!span.peer) { + + if (!span.peer) span.peer = host; - } - if (!span.hasTag(Tag.httpURLKey)) { // only set if a higher level plugin with more info did not already set + + if (!span.hasTag(Tag.httpURLKey)) // only set if a higher level plugin with more info did not already set span.tag(Tag.httpURL(httpURL)); - } - if (!span.hasTag(Tag.httpMethodKey)) { + + if (!span.hasTag(Tag.httpMethodKey)) span.tag(Tag.httpMethod(httpMethod)); - } const req: ClientRequest = _request.apply(this, arguments); - span.inject().items.forEach((item) => { - req.setHeader(item.key, item.value); - }); + span.inject().items.forEach((item) => req.setHeader(item.key, item.value)); - req.on('close', stopIfNotStopped); - req.on('abort', () => (span.errored = true, span.log('Abort', true), stopIfNotStopped())); - req.on('error', (err) => (span.error(err), stopIfNotStopped())); + req.on('timeout', () => span.log('Timeout', true)); + req.on('abort', () => span.log('Abort', span.errored = true)); + req.on('error', (err) => span.error(err)); const _emit = req.emit; - req.emit = function(name: any, ...args: any[]): any { + req.emit = function(): any { + const event = arguments[0]; + span.resync(); try { - if (name === 'response') { - const res = args[0]; + if (event === 'response') { + const res = arguments[1]; span.tag(Tag.httpStatusCode(res.statusCode)); - if (res.statusCode && res.statusCode >= 400) { + if (res.statusCode && res.statusCode >= 400) span.errored = true; - } - if (res.statusMessage) { - span.tag(Tag.httpStatusMsg(res.statusMessage)); - } - res.on('end', stopIfNotStopped); + if (res.statusMessage) + span.tag(Tag.httpStatusMsg(res.statusMessage)); const _emitRes = res.emit; - res.emit = function(nameRes: any, ...argsRes: any[]): any { + res.emit = function(): any { span.resync(); try { - return _emitRes.call(this, nameRes, ...argsRes); + return _emitRes.apply(this, arguments); } catch (err) { span.error(err); @@ -128,7 +124,7 @@ class HttpPlugin implements SwPlugin { } } - return _emit.call(this, name, ...args); + return _emit.apply(this, arguments as any); } catch (err) { span.error(err); @@ -136,7 +132,10 @@ class HttpPlugin implements SwPlugin { throw err; } finally { - span.async(); + if (event === 'close') + span.stop(); + else + span.async(); } }; @@ -146,7 +145,7 @@ class HttpPlugin implements SwPlugin { } catch (err) { span.error(err); - stopIfNotStopped(); + span.stop(); throw err; } @@ -164,26 +163,13 @@ class HttpPlugin implements SwPlugin { const headers = req.rawHeaders || []; const headersMap: { [key: string]: string } = {}; - for (let i = 0; i < headers.length / 2; i += 2) { + for (let i = 0; i < headers.length / 2; i += 2) headersMap[headers[i]] = headers[i + 1]; - } const carrier = ContextCarrier.from(headersMap); const operation = (req.url || '/').replace(/\?.*/g, ''); const span = ContextManager.current.newEntrySpan(operation, carrier).start(); - const copyStatusAndStop = () => { - span.tag(Tag.httpStatusCode(res.statusCode)); - if (res.statusCode && res.statusCode >= 400) { - span.errored = true; - } - if (res.statusMessage) { - span.tag(Tag.httpStatusMsg(res.statusMessage)); - } - - span.stop(); - }; - try { span.component = Component.HTTP_SERVER; span.layer = SpanLayer.HTTP; @@ -192,30 +178,31 @@ class HttpPlugin implements SwPlugin { || (req.connection.remoteFamily === 'IPv6' ? `[${req.connection.remoteAddress}]:${req.connection.remotePort}` : `${req.connection.remoteAddress}:${req.connection.remotePort}`); + span.tag(Tag.httpURL(protocol + '://' + (req.headers.host || '') + req.url)); span.tag(Tag.httpMethod(req.method)); - let ret = handler.call(this, req, res, ...reqArgs); + const ret = handler.call(this, req, res, ...reqArgs); - if (!ret || typeof ret.then !== 'function') { // generic Promise check - copyStatusAndStop(); + let copyStatusAndStopIfNotStopped = () => { + copyStatusAndStopIfNotStopped = () => undefined; - } else { - ret = ret.then((r: any) => { - copyStatusAndStop(); + span.tag(Tag.httpStatusCode(res.statusCode)); - return r; - }, + if (res.statusCode && res.statusCode >= 400) + span.errored = true; - (error: any) => { - span.error(error); - span.stop(); + if (res.statusMessage) + span.tag(Tag.httpStatusMsg(res.statusMessage)); - return Promise.reject(error); - }); + span.stop(); + }; - span.async(); - } + res.on('close', copyStatusAndStopIfNotStopped); + res.on('abort', () => (span.errored = true, span.log('Abort', true), copyStatusAndStopIfNotStopped())); + res.on('error', (err) => (span.error(err), copyStatusAndStopIfNotStopped())); + + span.async(); return ret; diff --git a/tests/plugins/axios/expected.data.yaml b/tests/plugins/axios/expected.data.yaml index ddb2fc9..794e4be 100644 --- a/tests/plugins/axios/expected.data.yaml +++ b/tests/plugins/axios/expected.data.yaml @@ -21,26 +21,6 @@ segmentItems: segments: - segmentId: not null spans: - - operationName: /json - operationId: 0 - parentSpanId: 0 - spanId: 1 - spanLayer: Http - startTime: gt 0 - endTime: gt 0 - componentId: 4005 - spanType: Exit - peer: httpbin.org - skipAnalysis: false - tags: - - key: http.url - value: httpbin.org/json - - key: http.method - value: GET - - key: http.status.code - value: '200' - - key: http.status.msg - value: OK - operationName: /axios operationId: 0 parentSpanId: -1 @@ -70,6 +50,26 @@ segmentItems: parentServiceInstance: not null parentService: client traceId: not null + - operationName: /json + operationId: 0 + parentSpanId: 0 + spanId: 1 + spanLayer: Http + startTime: gt 0 + endTime: gt 0 + componentId: 4005 + spanType: Exit + peer: httpbin.org + skipAnalysis: false + tags: + - key: http.url + value: httpbin.org/json + - key: http.method + value: GET + - key: http.status.code + value: '200' + - key: http.status.msg + value: OK - serviceName: client segmentSize: 1 segments: @@ -77,12 +77,12 @@ segmentItems: spans: - operationName: /axios operationId: 0 - parentSpanId: 0 - spanId: 1 + parentSpanId: -1 + spanId: 0 spanLayer: Http tags: - key: http.url - value: server:5000/axios + value: http://localhost:5001/axios - key: http.method value: GET - key: http.status.code @@ -91,18 +91,18 @@ segmentItems: value: OK startTime: gt 0 endTime: gt 0 - componentId: 4005 - spanType: Exit - peer: server:5000 + componentId: 49 + spanType: Entry + peer: not null skipAnalysis: false - operationName: /axios operationId: 0 - parentSpanId: -1 - spanId: 0 + parentSpanId: 0 + spanId: 1 spanLayer: Http tags: - key: http.url - value: http://localhost:5001/axios + value: server:5000/axios - key: http.method value: GET - key: http.status.code @@ -111,7 +111,7 @@ segmentItems: value: OK startTime: gt 0 endTime: gt 0 - componentId: 49 - spanType: Entry - peer: not null + componentId: 4005 + spanType: Exit + peer: server:5000 skipAnalysis: false diff --git a/tests/plugins/express/expected.data.yaml b/tests/plugins/express/expected.data.yaml index 240a481..118eda0 100644 --- a/tests/plugins/express/expected.data.yaml +++ b/tests/plugins/express/expected.data.yaml @@ -21,26 +21,6 @@ segmentItems: segments: - segmentId: not null spans: - - operationName: /json - operationId: 0 - parentSpanId: 0 - spanId: 1 - spanLayer: Http - startTime: gt 0 - endTime: gt 0 - componentId: 2 - spanType: Exit - peer: httpbin.org - skipAnalysis: false - tags: - - key: http.url - value: httpbin.org/json - - key: http.method - value: GET - - key: http.status.code - value: '200' - - key: http.status.msg - value: OK - operationName: /express operationId: 0 parentSpanId: -1 @@ -70,31 +50,31 @@ segmentItems: spanType: Entry peer: not null skipAnalysis: false - - serviceName: client - segmentSize: 1 - segments: - - segmentId: not null - spans: - - operationName: /express + - operationName: /json operationId: 0 parentSpanId: 0 spanId: 1 spanLayer: Http + startTime: gt 0 + endTime: gt 0 + componentId: 2 + spanType: Exit + peer: httpbin.org + skipAnalysis: false tags: - key: http.url - value: server:5000/express + value: http://httpbin.org/json - key: http.method value: GET - key: http.status.code value: '200' - key: http.status.msg value: OK - startTime: gt 0 - endTime: gt 0 - componentId: 2 - spanType: Exit - peer: server:5000 - skipAnalysis: false + - serviceName: client + segmentSize: 1 + segments: + - segmentId: not null + spans: - operationName: /express operationId: 0 parentSpanId: -1 @@ -115,3 +95,23 @@ segmentItems: spanType: Entry peer: not null skipAnalysis: false + - operationName: /express + operationId: 0 + parentSpanId: 0 + spanId: 1 + spanLayer: Http + tags: + - key: http.url + value: http://server:5000/express + - key: http.method + value: GET + - key: http.status.code + value: '200' + - key: http.status.msg + value: OK + startTime: gt 0 + endTime: gt 0 + componentId: 2 + spanType: Exit + peer: server:5000 + skipAnalysis: false diff --git a/tests/plugins/http/expected.data.yaml b/tests/plugins/http/expected.data.yaml index a3580e6..3e9076f 100644 --- a/tests/plugins/http/expected.data.yaml +++ b/tests/plugins/http/expected.data.yaml @@ -39,6 +39,8 @@ segmentItems: value: GET - key: http.status.code value: '200' + - key: http.status.msg + value: OK refs: - parentEndpoint: '' networkAddress: server:5000 @@ -91,6 +93,8 @@ segmentItems: value: GET - key: http.status.code value: '200' + - key: http.status.msg + value: OK - operationName: /test operationId: 0 parentSpanId: 0 diff --git a/tests/plugins/mongodb/expected.data.yaml b/tests/plugins/mongodb/expected.data.yaml index 580e86c..cb5165f 100644 --- a/tests/plugins/mongodb/expected.data.yaml +++ b/tests/plugins/mongodb/expected.data.yaml @@ -81,6 +81,7 @@ segmentItems: - { key: http.url, value: 'http://localhost:5001/mongo' } - { key: http.method, value: GET } - { key: http.status.code, value: '200' } + - { key: http.status.msg, value: OK } - operationName: /mongo operationId: 0 parentSpanId: 0 @@ -93,7 +94,7 @@ segmentItems: peer: server:5000 skipAnalysis: false tags: - - { key: http.url, value: 'server:5000/mongo' } + - { key: http.url, value: 'http://server:5000/mongo' } - { key: http.method, value: GET } - { key: http.status.code, value: '200' } - { key: http.status.msg, value: OK } diff --git a/tests/plugins/mysql/expected.data.yaml b/tests/plugins/mysql/expected.data.yaml index bc8bc1e..221f4e9 100644 --- a/tests/plugins/mysql/expected.data.yaml +++ b/tests/plugins/mysql/expected.data.yaml @@ -21,6 +21,24 @@ segmentItems: segments: - segmentId: not null spans: + - operationName: mysql/query + operationId: 0 + parentSpanId: 0 + spanId: 1 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 5 + spanType: Exit + peer: mysql:3306 + skipAnalysis: false + tags: + - key: db.type + value: Mysql + - key: db.instance + value: test + - key: db.statement + value: SELECT * FROM `user` WHERE `name` = "u1" - operationName: /mysql operationId: 0 parentSpanId: -1 @@ -39,6 +57,8 @@ segmentItems: value: GET - key: http.status.code value: "200" + - key: http.status.msg + value: OK refs: - parentEndpoint: "" networkAddress: server:5000 @@ -48,24 +68,6 @@ segmentItems: parentServiceInstance: not null parentService: client traceId: not null - - operationName: mysql/query - operationId: 0 - parentSpanId: 0 - spanId: 1 - spanLayer: Database - startTime: gt 0 - endTime: gt 0 - componentId: 5 - spanType: Exit - peer: mysql:3306 - skipAnalysis: false - tags: - - key: db.type - value: Mysql - - key: db.instance - value: test - - key: db.statement - value: SELECT * FROM `user` WHERE `name` = "u1" - serviceName: client segmentSize: 1 segments: @@ -89,6 +91,8 @@ segmentItems: value: GET - key: http.status.code value: "200" + - key: http.status.msg + value: OK - operationName: /mysql operationId: 0 parentSpanId: 0 @@ -102,7 +106,7 @@ segmentItems: skipAnalysis: false tags: - key: http.url - value: server:5000/mysql + value: http://server:5000/mysql - key: http.method value: GET - key: http.status.code diff --git a/tests/plugins/pg/expected.data.yaml b/tests/plugins/pg/expected.data.yaml index f89d1c8..d35cefb 100644 --- a/tests/plugins/pg/expected.data.yaml +++ b/tests/plugins/pg/expected.data.yaml @@ -21,6 +21,21 @@ segmentItems: segments: - segmentId: not null spans: + - operationName: pg/query + operationId: 0 + parentSpanId: 0 + spanId: 1 + spanLayer: Database + startTime: gt 0 + endTime: gt 0 + componentId: 22 + spanType: Exit + peer: postgres:5432 + skipAnalysis: false + tags: + - { key: db.type, value: PostgreSQL } + - { key: db.instance, value: test } + - { key: db.statement, value: SELECT * FROM "user" where name = 'u1' } - operationName: /postgres operationId: 0 parentSpanId: -1 @@ -36,6 +51,7 @@ segmentItems: - { key: http.url, value: 'http://server:5000/postgres' } - { key: http.method, value: GET } - { key: http.status.code, value: '200' } + - { key: http.status.msg, value: OK } refs: - parentEndpoint: "" networkAddress: server:5000 @@ -45,21 +61,6 @@ segmentItems: parentServiceInstance: not null parentService: client traceId: not null - - operationName: pg/query - operationId: 0 - parentSpanId: 0 - spanId: 1 - spanLayer: Database - startTime: gt 0 - endTime: gt 0 - componentId: 22 - spanType: Exit - peer: postgres:5432 - skipAnalysis: false - tags: - - { key: db.type, value: PostgreSQL } - - { key: db.instance, value: test } - - { key: db.statement, value: SELECT * FROM "user" where name = 'u1' } - serviceName: client segmentSize: 1 segments: @@ -80,6 +81,7 @@ segmentItems: - { key: http.url, value: 'http://localhost:5001/postgres' } - { key: http.method, value: GET } - { key: http.status.code, value: '200' } + - { key: http.status.msg, value: OK } - operationName: /postgres operationId: 0 parentSpanId: 0 @@ -92,7 +94,7 @@ segmentItems: peer: server:5000 skipAnalysis: false tags: - - { key: http.url, value: 'server:5000/postgres' } + - { key: http.url, value: 'http://server:5000/postgres' } - { key: http.method, value: GET } - { key: http.status.code, value: '200' } - { key: http.status.msg, value: OK } From 49bd7bdc23605190f35087640188d2ae0636bfe7 Mon Sep 17 00:00:00 2001 From: Tomasz Pytel Date: Mon, 8 Mar 2021 10:12:09 -0300 Subject: [PATCH 8/8] res.on('close') -> req.on('end') for Node 10 --- src/plugins/HttpPlugin.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/plugins/HttpPlugin.ts b/src/plugins/HttpPlugin.ts index 39e0dc3..be38904 100644 --- a/src/plugins/HttpPlugin.ts +++ b/src/plugins/HttpPlugin.ts @@ -198,7 +198,7 @@ class HttpPlugin implements SwPlugin { span.stop(); }; - res.on('close', copyStatusAndStopIfNotStopped); + req.on('end', copyStatusAndStopIfNotStopped); // this insead of 'close' because Node 10 doesn't emit those res.on('abort', () => (span.errored = true, span.log('Abort', true), copyStatusAndStopIfNotStopped())); res.on('error', (err) => (span.error(err), copyStatusAndStopIfNotStopped()));