From c8c49dc80b8af341b8a567d7e3b14f334615cddd Mon Sep 17 00:00:00 2001 From: Roch Devost Date: Wed, 6 Feb 2019 10:29:23 -0500 Subject: [PATCH] v0.8.0 (#430) * v0.8.0 * prefix span context properties with an underscore (#397) * add log propagator and trace identifiers for log correlation (#396) * fix baggage items at the span level instead of trace level (#398) * add middleware and stack trace support for express (#399) * add dns integration (#405) * add net integration (#406) * add trace search sampling configuration (#407) * add more metadata to net.connect and update operation name (#409) * add automatic log correlation of tracer identifiers for winston (#408) * add automatic log correlation of trace identifiers for bunyan (#410) * add noop span context with the correct API (#413) * add automatic log correlation of tracer identifiers for pino (#414) * add automatic log correlation of tracer identifiers for pino * add missing plugins to the build * Add protocol as a configuration option for the dd-trace-agent URL (#416) * Add protocol as a configuration option for the dd-trace agent URL. This is useful for scenarios where a SSL-terminating load balancer sits in front of the datadog-agent * Fix lint errors * Switching from protocol override to url override per CR * Fixing missing comma from previous commit * Fix tests * overrideUrl -> url * add support for latest module versions in all plugins (#417) * fix using log correlation with a custom logger (#419) * disable net and dns plugins (#421) * fix http server response handlers not running in the request scope (#422) * fix log injection with a null active span and update injection keys (#423) * Revert "add trace search sampling configuration (#407)" (#425) This reverts commit 4dac39465ae5fc8aef3e1a0015add2f20775b101. * add documentation about enabling log correlation (#427) * fix references to the old trace IDs (#426) * fix noop span context trace IDs to match the backend expectation (#429) --- .circleci/config.yml | 30 +++ LICENSE-3rdparty.csv | 1 + docs/API.md | 2 + ext/formats.js | 10 + ext/index.js | 4 +- lib/version.js | 2 +- package.json | 3 +- src/config.js | 5 +- src/format.js | 22 +- src/instrumenter.js | 112 +++++++++- src/noop/span.js | 14 ++ src/noop/span_context.js | 15 ++ src/{noop.js => noop/tracer.js} | 11 +- src/opentracing/propagation/log.js | 30 +++ src/opentracing/propagation/text_map.js | 14 +- src/opentracing/span.js | 50 ++--- src/opentracing/span_context.js | 32 ++- src/opentracing/tracer.js | 12 +- src/platform/node/request.js | 4 +- src/plugins/amqp10.js | 4 +- src/plugins/amqplib.js | 4 +- src/plugins/bluebird.js | 2 +- src/plugins/bunyan.js | 25 +++ src/plugins/dns.js | 165 ++++++++++++++ src/plugins/elasticsearch.js | 2 +- src/plugins/express.js | 2 +- src/plugins/graphql.js | 6 +- src/plugins/hapi.js | 2 +- src/plugins/index.js | 7 +- src/plugins/ioredis.js | 2 +- src/plugins/koa.js | 4 +- src/plugins/memcached.js | 2 +- src/plugins/mongodb-core.js | 2 +- src/plugins/mysql.js | 2 +- src/plugins/mysql2.js | 2 +- src/plugins/net.js | 109 ++++++++++ src/plugins/pg.js | 2 +- src/plugins/pino.js | 74 +++++++ src/plugins/q.js | 2 +- src/plugins/redis.js | 2 +- src/plugins/restify.js | 2 +- src/plugins/router.js | 83 +++++-- src/plugins/util/log.js | 25 +++ src/plugins/util/redis.js | 2 +- src/plugins/util/web.js | 108 ++++++++- src/plugins/when.js | 2 +- src/plugins/winston.js | 69 ++++++ src/priority_sampler.js | 10 +- src/proxy.js | 4 +- src/writer.js | 2 +- test/.eslintrc.json | 3 +- test/config.spec.js | 90 +++++++- test/dd-trace.spec.js | 4 +- test/format.spec.js | 56 ++--- test/instrumenter.spec.js | 28 ++- test/noop.spec.js | 13 +- test/opentracing/propagation/log.spec.js | 59 +++++ test/opentracing/span.spec.js | 72 +++--- test/opentracing/span_context.spec.js | 60 ++++- test/opentracing/tracer.spec.js | 2 +- test/plugins/bunyan.spec.js | 80 +++++++ test/plugins/dns.spec.js | 148 +++++++++++++ test/plugins/express.spec.js | 265 ++++++++++++++++++----- test/plugins/graphql.spec.js | 2 +- test/plugins/net.spec.js | 154 +++++++++++++ test/plugins/pino.spec.js | 80 +++++++ test/plugins/router.spec.js | 7 +- test/plugins/util/log.spec.js | 56 +++++ test/plugins/util/redis.spec.js | 8 +- test/plugins/util/tx.spec.js | 16 +- test/plugins/util/web.spec.js | 216 ++++++++++++++++-- test/plugins/winston.spec.js | 148 +++++++++++++ test/priority_sampler.spec.js | 22 +- test/proxy.spec.js | 2 +- test/setup/core.js | 4 +- test/tracer.spec.js | 22 +- test/writer.spec.js | 2 +- 77 files changed, 2406 insertions(+), 315 deletions(-) create mode 100644 ext/formats.js create mode 100644 src/noop/span.js create mode 100644 src/noop/span_context.js rename src/{noop.js => noop/tracer.js} (68%) create mode 100644 src/opentracing/propagation/log.js create mode 100644 src/plugins/bunyan.js create mode 100644 src/plugins/dns.js create mode 100644 src/plugins/net.js create mode 100644 src/plugins/pino.js create mode 100644 src/plugins/util/log.js create mode 100644 src/plugins/winston.js create mode 100644 test/opentracing/propagation/log.spec.js create mode 100644 test/plugins/bunyan.spec.js create mode 100644 test/plugins/dns.spec.js create mode 100644 test/plugins/net.spec.js create mode 100644 test/plugins/pino.spec.js create mode 100644 test/plugins/util/log.spec.js create mode 100644 test/plugins/winston.spec.js diff --git a/.circleci/config.yml b/.circleci/config.yml index 0764c91a156..3578005bcf4 100644 --- a/.circleci/config.yml +++ b/.circleci/config.yml @@ -158,6 +158,14 @@ jobs: - SERVICES= - PLUGINS=bluebird + node-bunyan: + <<: *node-plugin-base + docker: + - image: node:8 + environment: + - SERVICES= + - PLUGINS=bunyan + node-elasticsearch: <<: *node-plugin-base docker: @@ -243,6 +251,14 @@ jobs: - MONGODB_REPLICA_SET_MODE=primary - MONGODB_ADVERTISED_HOSTNAME=localhost + node-pino: + <<: *node-plugin-base + docker: + - image: node:8 + environment: + - SERVICES= + - PLUGINS=pino + node-postgres: <<: *node-plugin-base docker: @@ -293,6 +309,14 @@ jobs: - SERVICES= - PLUGINS=when + node-winston: + <<: *node-plugin-base + docker: + - image: node:8 + environment: + - SERVICES= + - PLUGINS=winston + workflows: version: 2 build: @@ -307,6 +331,7 @@ workflows: - node-amqplib - node-amqp10 - node-bluebird + - node-bunyan - node-elasticsearch - node-express - node-graphql @@ -316,11 +341,13 @@ workflows: - node-memcached - node-mongodb-core - node-mysql + - node-pino - node-postgres - node-q - node-redis - node-restify - node-when + - node-winston nightly: triggers: - schedule: @@ -338,6 +365,7 @@ workflows: - node-amqplib - node-amqp10 - node-bluebird + - node-bunyan - node-elasticsearch - node-express - node-graphql @@ -347,8 +375,10 @@ workflows: - node-memcached - node-mongodb-core - node-mysql + - node-pino - node-postgres - node-q - node-redis - node-restify - node-when + - node-winston diff --git a/LICENSE-3rdparty.csv b/LICENSE-3rdparty.csv index f5116ace8d9..c3a50f89fd2 100644 --- a/LICENSE-3rdparty.csv +++ b/LICENSE-3rdparty.csv @@ -8,6 +8,7 @@ require,lodash.pick,MIT,Copyright JS Foundation and other contributors require,lodash.truncate,MIT,Copyright JS Foundation and other contributors require,lodash.uniq,MIT,Copyright JS Foundation and other contributors require,methods,MIT,Copyright 2013-2014 TJ Holowaychuk 2013-2014 TJ Holowaychuk +require,module-details-from-path,MIT,Copyright 2016 Thomas Watson Steen require,msgpack-lite,MIT,Copyright 2015 Yusuke Kawasaki require,opentracing,MIT,Copyright 2016 Resonance Labs Inc require,parent-module,MIT,Copyright Sindre Sorhus diff --git a/docs/API.md b/docs/API.md index 0503f9b1b83..2221aa70b78 100644 --- a/docs/API.md +++ b/docs/API.md @@ -387,9 +387,11 @@ Options can be configured as a parameter to the [init()](https://datadog.github. | enabled | DD_TRACE_ENABLED | true | Whether to enable the tracer. | | debug | DD_TRACE_DEBUG | false | Enable debug logging in the tracer. | | service | DD_SERVICE_NAME | | The service name to be used for this program. | +| url | DD_TRACE_AGENT_URL | | The url of the trace agent that the tracer will submit to. Takes priority over hostname and port, if set. | | hostname | DD_TRACE_AGENT_HOSTNAME | localhost | The address of the trace agent that the tracer will submit to. | | port | DD_TRACE_AGENT_PORT | 8126 | The port of the trace agent that the tracer will submit to. | | env | DD_ENV | | Set an application’s environment e.g. `prod`, `pre-prod`, `stage`. | +| logInjection | DD_LOGS_INJECTION | false | Enable automatic injection of trace IDs in logs for supported logging libraries. | tags | | {} | Set global tags that should be applied to all spans. | | sampleRate | | 1 | Percentage of spans to sample as a float between 0 and 1. | | flushInterval | | 2000 | Interval in milliseconds at which the tracer will submit traces to the agent. | diff --git a/ext/formats.js b/ext/formats.js new file mode 100644 index 00000000000..7f5cf72fc92 --- /dev/null +++ b/ext/formats.js @@ -0,0 +1,10 @@ +'use strict' + +const opentracing = require('opentracing') + +module.exports = { + TEXT_MAP: opentracing.FORMAT_TEXT_MAP, + HTTP_HEADERS: opentracing.FORMAT_HTTP_HEADERS, + BINARY: opentracing.FORMAT_BINARY, + LOG: 'log' +} diff --git a/ext/index.js b/ext/index.js index af226ec3654..35414b99222 100644 --- a/ext/index.js +++ b/ext/index.js @@ -2,8 +2,10 @@ const priority = require('./priority') const tags = require('./tags') +const formats = require('./formats') module.exports = { priority, - tags + tags, + formats } diff --git a/lib/version.js b/lib/version.js index 4397341fb56..2ca649b51c4 100644 --- a/lib/version.js +++ b/lib/version.js @@ -1 +1 @@ -module.exports = '0.7.3' +module.exports = '0.8.0' diff --git a/package.json b/package.json index 2276510bdc2..914c3463d28 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "dd-trace", - "version": "0.7.3", + "version": "0.8.0", "description": "Datadog APM tracing client for JavaScript", "main": "index.js", "scripts": { @@ -46,6 +46,7 @@ "lodash.truncate": "^4.4.2", "lodash.uniq": "^4.5.0", "methods": "^1.1.2", + "module-details-from-path": "^1.0.3", "msgpack-lite": "^0.1.26", "opentracing": "0.14.1", "parent-module": "^0.1.0", diff --git a/src/config.js b/src/config.js index 0cc4f714def..97b86dad36f 100644 --- a/src/config.js +++ b/src/config.js @@ -10,7 +10,9 @@ class Config { const enabled = coalesce(options.enabled, platform.env('DD_TRACE_ENABLED'), true) const debug = coalesce(options.debug, platform.env('DD_TRACE_DEBUG'), false) + const logInjection = coalesce(options.logInjection, platform.env('DD_LOGS_INJECTION'), false) const env = coalesce(options.env, platform.env('DD_ENV')) + const url = coalesce(options.url, platform.env('DD_TRACE_AGENT_URL'), null) const protocol = 'http' const hostname = coalesce( options.hostname, @@ -25,8 +27,9 @@ class Config { this.enabled = String(enabled) === 'true' this.debug = String(debug) === 'true' + this.logInjection = String(logInjection) === 'true' this.env = env - this.url = new URL(`${protocol}://${hostname}:${port}`) + this.url = url ? new URL(url) : new URL(`${protocol}://${hostname}:${port}`) this.tags = Object.assign({}, options.tags) this.flushInterval = flushInterval this.bufferSize = 100000 diff --git a/src/format.js b/src/format.js index 37c9661a623..8c470edc668 100644 --- a/src/format.js +++ b/src/format.js @@ -25,11 +25,11 @@ function formatSpan (span) { const spanContext = span.context() return { - trace_id: spanContext.traceId, - span_id: spanContext.spanId, - parent_id: spanContext.parentId, - name: String(spanContext.name), - resource: String(spanContext.name), + trace_id: spanContext._traceId, + span_id: spanContext._spanId, + parent_id: spanContext._parentId, + name: String(spanContext._name), + resource: String(spanContext._name), error: 0, meta: {}, metrics: {}, @@ -39,7 +39,7 @@ function formatSpan (span) { } function extractTags (trace, span) { - const tags = span.context().tags + const tags = span.context()._tags Object.keys(tags).forEach(tag => { switch (tag) { @@ -78,14 +78,14 @@ function extractError (trace, span) { function extractMetrics (trace, span) { const spanContext = span.context() - Object.keys(spanContext.metrics).forEach(metric => { - if (typeof spanContext.metrics[metric] === 'number') { - trace.metrics[metric] = spanContext.metrics[metric] + Object.keys(spanContext._metrics).forEach(metric => { + if (typeof spanContext._metrics[metric] === 'number') { + trace.metrics[metric] = spanContext._metrics[metric] } }) - if (spanContext.sampling.priority !== undefined) { - trace.metrics[SAMPLING_PRIORITY_KEY] = spanContext.sampling.priority + if (spanContext._sampling.priority !== undefined) { + trace.metrics[SAMPLING_PRIORITY_KEY] = spanContext._sampling.priority } } diff --git a/src/instrumenter.js b/src/instrumenter.js index ae1eb1264ce..4298e5366f5 100644 --- a/src/instrumenter.js +++ b/src/instrumenter.js @@ -2,6 +2,7 @@ const semver = require('semver') const hook = require('require-in-the-middle') +const parse = require('module-details-from-path') const path = require('path') const shimmer = require('shimmer') const uniq = require('lodash.uniq') @@ -79,17 +80,28 @@ class Instrumenter { if (typeof nodule[name] !== 'function') { throw new Error(`Expected object ${nodule} to contain method ${name}.`) } + + Object.defineProperty(nodule[name], '_datadog_patched', { + value: true, + configurable: true + }) }) }) - return shimmer.massWrap.call(this, nodules, names, wrapper) + shimmer.massWrap.call(this, nodules, names, wrapper) } unwrap (nodules, names, wrapper) { nodules = [].concat(nodules) names = [].concat(names) - return shimmer.massUnwrap.call(this, nodules, names, wrapper) + shimmer.massUnwrap.call(this, nodules, names, wrapper) + + nodules.forEach(nodule => { + names.forEach(name => { + nodule[name] && delete nodule[name]._datadog_patched + }) + }) } hookModule (moduleExports, moduleName, moduleBaseDir) { @@ -109,7 +121,7 @@ class Instrumenter { .filter(plugin => [].concat(plugin).some(instrumentation => filename(instrumentation) === moduleName && matchVersion(moduleVersion, instrumentation.versions) )) - .forEach(plugin => this._validate(plugin, moduleBaseDir)) + .forEach(plugin => this._validate(plugin, moduleBaseDir, moduleVersion)) this._plugins .forEach((meta, plugin) => { @@ -118,8 +130,7 @@ class Instrumenter { .filter(instrumentation => moduleName === filename(instrumentation)) .filter(instrumentation => matchVersion(moduleVersion, instrumentation.versions)) .forEach(instrumentation => { - this._instrumented.set(instrumentation, moduleExports) - instrumentation.patch.call(this, moduleExports, this._tracer._tracer, this._plugins.get(plugin).config) + this._patch(instrumentation, moduleExports, this._plugins.get(plugin).config) }) } catch (e) { log.error(e) @@ -136,14 +147,18 @@ class Instrumenter { } _set (plugin, meta) { - this._plugins.set(plugin, Object.assign({ config: {} }, meta)) + meta = Object.assign({ config: {} }, meta) + + this._plugins.set(plugin, meta) + this._load(plugin, meta) } - _validate (plugin, moduleBaseDir) { + _validate (plugin, moduleBaseDir, moduleVersion) { const meta = this._plugins.get(plugin) const instrumentations = [].concat(plugin) for (let i = 0; i < instrumentations.length; i++) { + if (instrumentations[i].versions && !matchVersion(moduleVersion, instrumentations[i].versions)) continue if (instrumentations[i].file && !exists(moduleBaseDir, instrumentations[i].file)) { this._fail(plugin) log.debug([ @@ -165,15 +180,90 @@ class Instrumenter { this._plugins.delete(plugin) } + _patch (instrumentation, moduleExports, config) { + let instrumented = this._instrumented.get(instrumentation) + + if (!instrumented) { + this._instrumented.set(instrumentation, instrumented = new Set()) + } + + if (!instrumented.has(moduleExports)) { + instrumented.add(moduleExports) + instrumentation.patch.call(this, moduleExports, this._tracer._tracer, config) + } + } + _unpatch (instrumentation) { - try { - instrumentation.unpatch.call(this, this._instrumented.get(instrumentation)) - } catch (e) { - log.error(e) + const instrumented = this._instrumented.get(instrumentation) + + if (instrumented) { + instrumented.forEach(moduleExports => { + try { + instrumentation.unpatch.call(this, moduleExports) + } catch (e) { + log.error(e) + } + }) + } + } + + _load (plugin, meta) { + if (this._enabled) { + const instrumentations = [].concat(plugin) + + try { + instrumentations + .forEach(instrumentation => { + getModules(instrumentation).forEach(nodule => { + this._patch(instrumentation, nodule, meta.config) + }) + }) + } catch (e) { + log.error(e) + this._fail(plugin) + log.debug(`Error while trying to patch ${meta.name}. The plugin has been disabled.`) + } } } } +function getModules (instrumentation) { + const modules = [] + const ids = Object.keys(require.cache) + + let pkg + + for (let i = 0, l = ids.length; i < l; i++) { + const id = ids[i].replace(pathSepExpr, '/') + + if (!id.includes(`/node_modules/${instrumentation.name}/`)) continue + + if (instrumentation.file) { + if (!id.endsWith(`/node_modules/${filename(instrumentation)}`)) continue + + const basedir = getBasedir(ids[i]) + + pkg = require(`${basedir}/package.json`) + } else { + const basedir = getBasedir(ids[i]) + + pkg = require(`${basedir}/package.json`) + + if (!id.endsWith(`/node_modules/${instrumentation.name}/${pkg.main}`)) continue + } + + if (!matchVersion(pkg.version, instrumentation.versions)) continue + + modules.push(require.cache[ids[i]].exports) + } + + return modules +} + +function getBasedir (id) { + return parse(id).basedir.replace(pathSepExpr, '/') +} + function matchVersion (version, ranges) { return !version || (ranges && ranges.some(range => semver.satisfies(version, range))) } diff --git a/src/noop/span.js b/src/noop/span.js new file mode 100644 index 00000000000..1f54a4f891f --- /dev/null +++ b/src/noop/span.js @@ -0,0 +1,14 @@ +'use strict' + +const Span = require('opentracing').Span +const SpanContext = require('./span_context') + +const context = new SpanContext() + +class NoopSpan extends Span { + _context () { + return context + } +} + +module.exports = NoopSpan diff --git a/src/noop/span_context.js b/src/noop/span_context.js new file mode 100644 index 00000000000..243c9feb340 --- /dev/null +++ b/src/noop/span_context.js @@ -0,0 +1,15 @@ +'use strict' + +const SpanContext = require('opentracing').SpanContext + +class NoopSpanContext extends SpanContext { + toTraceId () { + return '0' + } + + toSpanId () { + return '0' + } +} + +module.exports = NoopSpanContext diff --git a/src/noop.js b/src/noop/tracer.js similarity index 68% rename from src/noop.js rename to src/noop/tracer.js index f4d2519c266..0c0a8586238 100644 --- a/src/noop.js +++ b/src/noop/tracer.js @@ -1,6 +1,9 @@ 'use strict' const Tracer = require('opentracing').Tracer +const Span = require('./span') + +const span = new Span() class NoopTracer extends Tracer { constructor (config) { @@ -9,9 +12,9 @@ class NoopTracer extends Tracer { let ScopeManager if (process.env.DD_CONTEXT_PROPAGATION === 'false') { - ScopeManager = require('./scope/noop/scope_manager') + ScopeManager = require('../scope/noop/scope_manager') } else { - ScopeManager = require('./scope/scope_manager') + ScopeManager = require('../scope/scope_manager') } this._scopeManager = new ScopeManager() @@ -28,6 +31,10 @@ class NoopTracer extends Tracer { currentSpan () { return null } + + _startSpan (name, options) { + return span + } } module.exports = NoopTracer diff --git a/src/opentracing/propagation/log.js b/src/opentracing/propagation/log.js new file mode 100644 index 00000000000..c05d486c79c --- /dev/null +++ b/src/opentracing/propagation/log.js @@ -0,0 +1,30 @@ +'use strict' + +const Uint64BE = require('int64-buffer').Uint64BE +const DatadogSpanContext = require('../span_context') + +class LogPropagator { + inject (spanContext, carrier) { + if (!carrier) return + + carrier.dd = { + trace_id: spanContext.toTraceId(), + span_id: spanContext.toSpanId() + } + } + + extract (carrier) { + if (!carrier || !carrier.dd || !carrier.dd.trace_id || !carrier.dd.span_id) { + return null + } + + const spanContext = new DatadogSpanContext({ + traceId: new Uint64BE(carrier.dd.trace_id, 10), + spanId: new Uint64BE(carrier.dd.span_id, 10) + }) + + return spanContext + } +} + +module.exports = LogPropagator diff --git a/src/opentracing/propagation/text_map.js b/src/opentracing/propagation/text_map.js index e7b7f2f94fe..d2629e173db 100644 --- a/src/opentracing/propagation/text_map.js +++ b/src/opentracing/propagation/text_map.js @@ -14,8 +14,8 @@ const logKeys = [traceKey, spanKey, samplingKey] class TextMapPropagator { inject (spanContext, carrier) { - carrier[traceKey] = spanContext.traceId.toString() - carrier[spanKey] = spanContext.spanId.toString() + carrier[traceKey] = spanContext.toTraceId() + carrier[spanKey] = spanContext.toSpanId() this._injectSamplingPriority(spanContext, carrier) this._injectBaggageItems(spanContext, carrier) @@ -42,7 +42,7 @@ class TextMapPropagator { } _injectSamplingPriority (spanContext, carrier) { - const priority = spanContext.sampling.priority + const priority = spanContext._sampling.priority if (Number.isInteger(priority)) { carrier[samplingKey] = priority.toString() @@ -50,8 +50,8 @@ class TextMapPropagator { } _injectBaggageItems (spanContext, carrier) { - spanContext.baggageItems && Object.keys(spanContext.baggageItems).forEach(key => { - carrier[baggagePrefix + key] = String(spanContext.baggageItems[key]) + spanContext._baggageItems && Object.keys(spanContext._baggageItems).forEach(key => { + carrier[baggagePrefix + key] = String(spanContext._baggageItems[key]) }) } @@ -60,7 +60,7 @@ class TextMapPropagator { const match = key.match(baggageExpr) if (match) { - spanContext.baggageItems[match[1]] = carrier[key] + spanContext._baggageItems[match[1]] = carrier[key] } }) } @@ -69,7 +69,7 @@ class TextMapPropagator { const priority = parseInt(carrier[samplingKey], 10) if (Number.isInteger(priority)) { - spanContext.sampling.priority = parseInt(carrier[samplingKey], 10) + spanContext._sampling.priority = parseInt(carrier[samplingKey], 10) } } } diff --git a/src/opentracing/span.js b/src/opentracing/span.js index d8074f66423..0895715fc66 100644 --- a/src/opentracing/span.js +++ b/src/opentracing/span.js @@ -29,20 +29,20 @@ class DatadogSpan extends Span { this._startTime = startTime this._spanContext = this._createContext(parent) - this._spanContext.name = operationName - this._spanContext.tags = tags - this._spanContext.metrics = metrics + this._spanContext._name = operationName + this._spanContext._tags = tags + this._spanContext._metrics = metrics } toString () { const spanContext = this.context() const json = JSON.stringify({ - traceId: spanContext.traceId, - spanId: spanContext.spanId, - parentId: spanContext.parentId, - service: spanContext.tags['service.name'], - name: spanContext.name, - resource: truncate(spanContext.tags['resource.name'], { length: 100 }) + traceId: spanContext._traceId, + spanId: spanContext._spanId, + parentId: spanContext._parentId, + service: spanContext._tags['service.name'], + name: spanContext._name, + resource: truncate(spanContext._tags['resource.name'], { length: 100 }) }) return `Span${json}` @@ -53,13 +53,13 @@ class DatadogSpan extends Span { if (parent) { spanContext = new SpanContext({ - traceId: parent.traceId, + traceId: parent._traceId, spanId: platform.id(), - parentId: parent.spanId, - sampled: parent.sampled, - sampling: parent.sampling, - baggageItems: Object.assign({}, parent.baggageItems), - trace: parent.trace.started.length !== parent.trace.finished.length ? parent.trace : null + parentId: parent._spanId, + sampled: parent._sampled, + sampling: parent._sampling, + baggageItems: parent._baggageItems, + trace: parent._trace.started.length !== parent._trace.finished.length ? parent._trace : null }) } else { const spanId = platform.id() @@ -70,7 +70,7 @@ class DatadogSpan extends Span { }) } - spanContext.trace.started.push(this) + spanContext._trace.started.push(this) return spanContext } @@ -84,21 +84,21 @@ class DatadogSpan extends Span { } _setOperationName (name) { - this._spanContext.name = name + this._spanContext._name = name } _setBaggageItem (key, value) { - this._spanContext.baggageItems[key] = value + this._spanContext._baggageItems[key] = value } _getBaggageItem (key) { - return this._spanContext.baggageItems[key] + return this._spanContext._baggageItems[key] } _addTags (keyValuePairs) { try { Object.keys(keyValuePairs).forEach(key => { - this._spanContext.tags[key] = String(keyValuePairs[key]) + this._spanContext._tags[key] = String(keyValuePairs[key]) }) } catch (e) { log.error(e) @@ -113,16 +113,16 @@ class DatadogSpan extends Span { finishTime = parseFloat(finishTime) || platform.now() this._duration = finishTime - this._startTime - this._spanContext.trace.finished.push(this) - this._spanContext.isFinished = true + this._spanContext._trace.finished.push(this) + this._spanContext._isFinished = true this._prioritySampler.sample(this) - if (this._spanContext.sampled) { + if (this._spanContext._sampled) { this._recorder.record(this) } - this._spanContext.children - .filter(child => !child.context().isFinished) + this._spanContext._children + .filter(child => !child.context()._isFinished) .forEach(child => { log.error(`Parent span ${this} was finished before child span ${child}.`) }) diff --git a/src/opentracing/span_context.js b/src/opentracing/span_context.js index 21765c24a16..ae204280fbe 100644 --- a/src/opentracing/span_context.js +++ b/src/opentracing/span_context.js @@ -6,22 +6,30 @@ class DatadogSpanContext extends SpanContext { constructor (props) { super() - this.traceId = props.traceId - this.spanId = props.spanId - this.parentId = props.parentId || null - this.name = props.name - this.children = props.children || [] - this.isFinished = props.isFinished || false - this.tags = props.tags || {} - this.metrics = props.metrics || {} - this.sampled = props.sampled === undefined || props.sampled - this.sampling = props.sampling || {} - this.baggageItems = props.baggageItems || {} - this.trace = props.trace || { + this._traceId = props.traceId + this._spanId = props.spanId + this._parentId = props.parentId || null + this._name = props.name + this._children = props.children || [] + this._isFinished = props.isFinished || false + this._tags = props.tags || {} + this._metrics = props.metrics || {} + this._sampled = props.sampled === undefined || props.sampled + this._sampling = props.sampling || {} + this._baggageItems = props.baggageItems || {} + this._trace = props.trace || { started: [], finished: [] } } + + toTraceId () { + return this._traceId.toString() + } + + toSpanId () { + return this._spanId.toString() + } } module.exports = DatadogSpanContext diff --git a/src/opentracing/tracer.js b/src/opentracing/tracer.js index 49bea92a0db..2e473b441d4 100644 --- a/src/opentracing/tracer.js +++ b/src/opentracing/tracer.js @@ -12,6 +12,8 @@ const PrioritySampler = require('../priority_sampler') const TextMapPropagator = require('./propagation/text_map') const HttpPropagator = require('./propagation/http') const BinaryPropagator = require('./propagation/binary') +const LogPropagator = require('./propagation/log') +const formats = require('../../ext/formats') const log = require('../log') class DatadogTracer extends Tracer { @@ -25,15 +27,17 @@ class DatadogTracer extends Tracer { this._url = config.url this._env = config.env this._tags = config.tags + this._logInjection = config.logInjection this._prioritySampler = new PrioritySampler(config.env) this._writer = new Writer(this._prioritySampler, config.url, config.bufferSize) this._recorder = new Recorder(this._writer, config.flushInterval) this._recorder.init() this._sampler = new Sampler(config.sampleRate) this._propagators = { - [opentracing.FORMAT_TEXT_MAP]: new TextMapPropagator(), - [opentracing.FORMAT_HTTP_HEADERS]: new HttpPropagator(), - [opentracing.FORMAT_BINARY]: new BinaryPropagator() + [formats.TEXT_MAP]: new TextMapPropagator(), + [formats.HTTP_HEADERS]: new HttpPropagator(), + [formats.BINARY]: new BinaryPropagator(), + [formats.LOG]: new LogPropagator() } } @@ -57,7 +61,7 @@ class DatadogTracer extends Tracer { }) if (parent && parent.type() === opentracing.REFERENCE_CHILD_OF) { - parent.referencedContext().children.push(span) + parent.referencedContext()._children.push(span) } return span diff --git a/src/platform/node/request.js b/src/platform/node/request.js index 9ebf4caa6df..dd2f8de9625 100644 --- a/src/platform/node/request.js +++ b/src/platform/node/request.js @@ -1,6 +1,7 @@ 'use strict' const http = require('http') +const https = require('https') function request (options, callback) { options = Object.assign({ @@ -14,7 +15,8 @@ function request (options, callback) { options.headers['Content-Length'] = byteLength(data) return new Promise((resolve, reject) => { - const req = http.request(options, res => { + const client = options.protocol === 'https:' ? https : http + const req = client.request(options, res => { let data = '' res.on('data', chunk => { data += chunk }) diff --git a/src/plugins/amqp10.js b/src/plugins/amqp10.js index a659bc9624c..fa07eb81feb 100644 --- a/src/plugins/amqp10.js +++ b/src/plugins/amqp10.js @@ -127,7 +127,7 @@ module.exports = [ { name: 'amqp10', file: 'lib/sender_link.js', - versions: ['3.x'], + versions: ['>=3'], patch (SenderLink, tracer, config) { this.wrap(SenderLink.prototype, 'send', createWrapSend(tracer, config)) }, @@ -138,7 +138,7 @@ module.exports = [ { name: 'amqp10', file: 'lib/receiver_link.js', - versions: ['3.x'], + versions: ['>=3'], patch (ReceiverLink, tracer, config) { this.wrap(ReceiverLink.prototype, '_messageReceived', createWrapMessageReceived(tracer, config)) }, diff --git a/src/plugins/amqplib.js b/src/plugins/amqplib.js index 70db0c904fd..7a40f1f6ce0 100644 --- a/src/plugins/amqplib.js +++ b/src/plugins/amqplib.js @@ -129,7 +129,7 @@ module.exports = [ { name: 'amqplib', file: 'lib/defs.js', - versions: ['0.5.x'], + versions: ['>=0.5'], patch (defs, tracer, config) { methods = Object.keys(defs) .filter(key => Number.isInteger(defs[key])) @@ -143,7 +143,7 @@ module.exports = [ { name: 'amqplib', file: 'lib/channel.js', - versions: ['0.5.x'], + versions: ['>=0.5'], patch (channel, tracer, config) { this.wrap(channel.Channel.prototype, 'sendImmediately', createWrapSendImmediately(tracer, config)) this.wrap(channel.Channel.prototype, 'sendMessage', createWrapSendMessage(tracer, config)) diff --git a/src/plugins/bluebird.js b/src/plugins/bluebird.js index defae254547..79a3df4f50d 100644 --- a/src/plugins/bluebird.js +++ b/src/plugins/bluebird.js @@ -5,7 +5,7 @@ const tx = require('./util/promise') module.exports = [ { name: 'bluebird', - versions: ['2.0.2 - 3'], // 2.0.0 and 2.0.1 were removed from npm + versions: ['>=2.0.2'], // 2.0.0 and 2.0.1 were removed from npm patch (Promise, tracer, config) { this.wrap(Promise.prototype, '_then', tx.createWrapThen(tracer, config)) }, diff --git a/src/plugins/bunyan.js b/src/plugins/bunyan.js new file mode 100644 index 00000000000..9a94de59a4f --- /dev/null +++ b/src/plugins/bunyan.js @@ -0,0 +1,25 @@ +'use strict' + +const tx = require('./util/log') + +function createWrapEmit (tracer, config) { + return function wrapEmit (emit) { + return function emitWithTrace (rec, noemit) { + tx.correlate(tracer, rec) + + return emit.apply(this, arguments) + } + } +} + +module.exports = { + name: 'bunyan', + versions: ['>=1'], + patch (Logger, tracer, config) { + if (!tracer._logInjection) return + this.wrap(Logger.prototype, '_emit', createWrapEmit(tracer, config)) + }, + unpatch (Logger) { + this.unwrap(Logger.prototype, '_emit') + } +} diff --git a/src/plugins/dns.js b/src/plugins/dns.js new file mode 100644 index 00000000000..125b126a870 --- /dev/null +++ b/src/plugins/dns.js @@ -0,0 +1,165 @@ +'use strict' + +const tx = require('./util/tx') + +const rrtypes = { + resolveAny: 'ANY', + resolve4: 'A', + resolve6: 'AAAA', + resolveCname: 'CNAME', + resolveMx: 'MX', + resolveNs: 'NS', + resolveTxt: 'TXT', + resolveSrv: 'SRV', + resolvePtr: 'PTR', + resolveNaptr: 'NAPTR', + resolveSoa: 'SOA' +} + +function createWrapLookup (tracer, config) { + return function wrapLookup (lookup) { + return function lookupWithTrace (hostname, options, callback) { + const span = startSpan(tracer, config, 'dns.lookup', { + 'resource.name': hostname, + 'dns.hostname': hostname + }) + + wrapArgs(span, arguments) + + return lookup.apply(this, arguments) + } + } +} + +function createWrapLookupService (tracer, config) { + return function wrapLookupService (lookupService) { + return function lookupServiceWithTrace (address, port, callback) { + const span = startSpan(tracer, config, 'dns.lookup_service', { + 'resource.name': `${address}:${port}`, + 'dns.address': address, + 'dns.port': port + }) + + wrapArgs(span, arguments) + + return lookupService.apply(this, arguments) + } + } +} + +function createWrapResolve (tracer, config) { + return function wrapResolve (resolve) { + return function resolveWithTrace (hostname, rrtype, callback) { + if (typeof rrtype !== 'string') { + rrtype = 'A' + } + + wrapResolver(tracer, config, rrtype, arguments) + + return resolve.apply(this, arguments) + } + } +} + +function createWrapResolver (tracer, config, rrtype) { + return function wrapResolve (resolve) { + return function resolveWithTrace (hostname, callback) { + wrapResolver(tracer, config, rrtype, arguments) + + return resolve.apply(this, arguments) + } + } +} + +function createWrapReverse (tracer, config) { + return function wrapReverse (reverse) { + return function reverseWithTrace (ip, callback) { + const span = startSpan(tracer, config, 'dns.reverse', { + 'resource.name': ip, + 'dns.ip': ip + }) + + wrapArgs(span, arguments) + + return reverse.apply(this, arguments) + } + } +} + +function startSpan (tracer, config, operation, tags) { + const scope = tracer.scopeManager().active() + const span = tracer.startSpan(operation, { + childOf: scope && scope.span(), + tags: Object.assign({ + 'span.kind': 'client', + 'service.name': config.service || `${tracer._service}-dns` + }, tags) + }) + + return span +} + +function wrapArgs (span, args) { + args[args.length - 1] = tx.wrap(span, args[args.length - 1]) +} + +function wrapResolver (tracer, config, rrtype, args) { + const hostname = args[0] + const span = startSpan(tracer, config, 'dns.resolve', { + 'resource.name': `${rrtype} ${hostname}`, + 'dns.hostname': hostname, + 'dns.rrtype': rrtype + }) + + wrapArgs(span, args) +} + +module.exports = [ + { + name: 'dns', + patch (dns, tracer, config) { + this.wrap(dns, 'lookup', createWrapLookup(tracer, config)) + this.wrap(dns, 'lookupService', createWrapLookupService(tracer, config)) + this.wrap(dns, 'resolve', createWrapResolve(tracer, config)) + this.wrap(dns, 'reverse', createWrapReverse(tracer, config)) + + Object.keys(rrtypes).forEach(method => { + this.wrap(dns, method, createWrapResolver(tracer, config, rrtypes[method])) + }) + + if (dns.Resolver) { + this.wrap(dns.Resolver.prototype, 'resolve', createWrapResolve(tracer, config)) + this.wrap(dns.Resolver.prototype, 'reverse', createWrapReverse(tracer, config)) + + Object.keys(rrtypes).forEach(method => { + this.wrap(dns.Resolver.prototype, method, createWrapResolver(tracer, config, rrtypes[method])) + }) + } + }, + unpatch (dns) { + this.unwrap(dns, [ + 'lookup', + 'lookupService', + 'resolve', + 'reverse' + ]) + + Object.keys(rrtypes).forEach(method => { + this.unwrap(dns, method) + }) + + if (dns.Resolver) { + this.unwrap(dns.prototype.Resolver, [ + 'resolve', + 'reverse' + ]) + + Object.keys(rrtypes).forEach(method => { + this.unwrap(dns.prototype.Resolver, method) + }) + } + } + } +] + +module.exports = [] // disable this integration for the upcoming release diff --git a/src/plugins/elasticsearch.js b/src/plugins/elasticsearch.js index d18d0cfcc21..53eb808f227 100644 --- a/src/plugins/elasticsearch.js +++ b/src/plugins/elasticsearch.js @@ -64,7 +64,7 @@ module.exports = [ { name: 'elasticsearch', file: 'src/lib/transport.js', - versions: ['>=10 <=15'], + versions: ['>=10'], patch (Transport, tracer, config) { this.wrap(Transport.prototype, 'request', createWrapRequest(tracer, config)) }, diff --git a/src/plugins/express.js b/src/plugins/express.js index fab639e2c36..7b13c8136f6 100644 --- a/src/plugins/express.js +++ b/src/plugins/express.js @@ -36,7 +36,7 @@ function unpatch (express) { module.exports = { name: 'express', - versions: ['4.x'], + versions: ['>=4'], patch, unpatch } diff --git a/src/plugins/graphql.js b/src/plugins/graphql.js index c28d9d9889f..473fc300fb0 100644 --- a/src/plugins/graphql.js +++ b/src/plugins/graphql.js @@ -441,7 +441,7 @@ module.exports = [ { name: 'graphql', file: 'execution/execute.js', - versions: ['>=0.10 <=14'], + versions: ['>=0.10'], patch (execute, tracer, config) { this.wrap(execute, 'execute', createWrapExecute( tracer, @@ -457,7 +457,7 @@ module.exports = [ { name: 'graphql', file: 'language/parser.js', - versions: ['>=0.10 <=14'], + versions: ['>=0.10'], patch (parser, tracer, config) { this.wrap(parser, 'parse', createWrapParse(tracer, validateConfig(config))) }, @@ -468,7 +468,7 @@ module.exports = [ { name: 'graphql', file: 'validation/validate.js', - versions: ['>=0.10 <=14'], + versions: ['>=0.10'], patch (validate, tracer, config) { this.wrap(validate, 'validate', createWrapValidate(tracer, validateConfig(config))) }, diff --git a/src/plugins/hapi.js b/src/plugins/hapi.js index 05dfd05d9ef..ddfdb43dd79 100644 --- a/src/plugins/hapi.js +++ b/src/plugins/hapi.js @@ -48,7 +48,7 @@ function createWrapExecute (tracer, config) { module.exports = [ { name: 'hapi', - versions: ['^17.1'], + versions: ['>=17.1'], file: 'lib/request.js', patch (Request, tracer, config) { this.wrap(Request, 'generate', createWrapGenerate(tracer, config)) diff --git a/src/plugins/index.js b/src/plugins/index.js index da63a6ee439..fa601c33d83 100644 --- a/src/plugins/index.js +++ b/src/plugins/index.js @@ -4,6 +4,8 @@ module.exports = { 'amqp10': require('./amqp10'), 'amqplib': require('./amqplib'), 'bluebird': require('./bluebird'), + 'bunyan': require('./bunyan'), + 'dns': require('./dns'), 'elasticsearch': require('./elasticsearch'), 'express': require('./express'), 'graphql': require('./graphql'), @@ -15,9 +17,12 @@ module.exports = { 'mongodb-core': require('./mongodb-core'), 'mysql': require('./mysql'), 'mysql2': require('./mysql2'), + 'net': require('./net'), 'pg': require('./pg'), + 'pino': require('./pino'), 'q': require('./q'), 'redis': require('./redis'), 'restify': require('./restify'), - 'when': require('./when') + 'when': require('./when'), + 'winston': require('./winston') } diff --git a/src/plugins/ioredis.js b/src/plugins/ioredis.js index c093bcf0704..b7653820133 100644 --- a/src/plugins/ioredis.js +++ b/src/plugins/ioredis.js @@ -18,7 +18,7 @@ function createWrapSendCommand (tracer, config) { module.exports = { name: 'ioredis', - versions: ['>=2 <=4'], + versions: ['>=2'], patch (Redis, tracer, config) { this.wrap(Redis.prototype, 'sendCommand', createWrapSendCommand(tracer, config)) }, diff --git a/src/plugins/koa.js b/src/plugins/koa.js index 6b6f5654ee1..364fd5ff8dd 100644 --- a/src/plugins/koa.js +++ b/src/plugins/koa.js @@ -57,7 +57,7 @@ function createWrapRegister (tracer, config) { module.exports = [ { name: 'koa', - versions: ['2.x'], + versions: ['>=2'], patch (Koa, tracer, config) { this.wrap(Koa.prototype, 'use', createWrapUse(tracer, config)) }, @@ -67,7 +67,7 @@ module.exports = [ }, { name: 'koa-router', - versions: ['7.x'], + versions: ['>=7'], patch (Router, tracer, config) { this.wrap(Router.prototype, 'register', createWrapRegister(tracer, config)) }, diff --git a/src/plugins/memcached.js b/src/plugins/memcached.js index 9f830f426d0..7de0d20c661 100644 --- a/src/plugins/memcached.js +++ b/src/plugins/memcached.js @@ -89,7 +89,7 @@ function getAddress (client, server, query) { module.exports = { name: 'memcached', - versions: ['^2.2'], + versions: ['>=2.2'], patch (Memcached, tracer, config) { this.wrap(Memcached.prototype, 'command', createWrapCommand(tracer, config)) }, diff --git a/src/plugins/mongodb-core.js b/src/plugins/mongodb-core.js index 7bae52bfc99..c2c36202473 100644 --- a/src/plugins/mongodb-core.js +++ b/src/plugins/mongodb-core.js @@ -136,7 +136,7 @@ function isBSON (val) { module.exports = [ { name: 'mongodb-core', - versions: ['>=2 <=3'], + versions: ['>=2'], patch (mongo, tracer, config) { this.wrap(mongo.Server.prototype, 'command', createWrapOperation(tracer, config)) this.wrap(mongo.Server.prototype, 'insert', createWrapOperation(tracer, config, 'insert')) diff --git a/src/plugins/mysql.js b/src/plugins/mysql.js index f6d0b69d9e7..f65e376fb94 100644 --- a/src/plugins/mysql.js +++ b/src/plugins/mysql.js @@ -73,7 +73,7 @@ module.exports = [ { name: 'mysql', file: 'lib/Connection.js', - versions: ['2.x'], + versions: ['>=2'], patch: patchConnection, unpatch: unpatchConnection } diff --git a/src/plugins/mysql2.js b/src/plugins/mysql2.js index 278ad85aeee..0e12b4895e8 100644 --- a/src/plugins/mysql2.js +++ b/src/plugins/mysql2.js @@ -73,7 +73,7 @@ module.exports = [ { name: 'mysql2', file: 'lib/connection.js', - versions: ['1.x'], + versions: ['>=1'], patch: patchConnection, unpatch: unpatchConnection } diff --git a/src/plugins/net.js b/src/plugins/net.js new file mode 100644 index 00000000000..36d27d531e3 --- /dev/null +++ b/src/plugins/net.js @@ -0,0 +1,109 @@ +'use strict' + +const tx = require('./util/tx') + +function createWrapConnect (tracer, config) { + return function wrapConnect (connect) { + return function connectWithTrace () { + const options = getOptions(arguments) + + if (!options) return connect.apply(this, arguments) + + const span = options.path + ? wrapIpc(tracer, config, this, options) + : wrapTcp(tracer, config, this, options) + + this.once('connect', tx.wrap(span)) + this.once('error', tx.wrap(span)) + + return connect.apply(this, arguments) + } + } +} + +function wrapTcp (tracer, config, socket, options) { + const host = options.host || 'localhost' + const port = options.port || 0 + const family = options.family || 4 + + const span = startSpan(tracer, config, 'tcp', { + 'resource.name': [host, port].filter(val => val).join(':'), + 'tcp.remote.host': host, + 'tcp.remote.port': port, + 'tcp.family': `IPv${family}`, + 'out.host': host, + 'out.port': port + }) + + socket.once('connect', () => { + if (socket.localAddress) { + span.addTags({ + 'tcp.local.address': socket.localAddress, + 'tcp.local.port': socket.localPort + }) + } + }) + + socket.once('lookup', (err, address) => { + if (!err) { + span.setTag('tcp.remote.address', address) + } + }) + + return span +} + +function wrapIpc (tracer, config, socket, options) { + return startSpan(tracer, config, 'ipc', { + 'resource.name': options.path, + 'ipc.path': options.path + }) +} + +function startSpan (tracer, config, protocol, tags) { + const scope = tracer.scopeManager().active() + const span = tracer.startSpan(`${protocol}.connect`, { + childOf: scope && scope.span(), + tags: Object.assign({ + 'span.kind': 'client', + 'service.name': config.service || `${tracer._service}-${protocol}` + }, tags) + }) + + return span +} + +function getOptions (args) { + if (!args[0]) return + + switch (typeof args[0]) { + case 'object': + if (Array.isArray(args[0])) return getOptions(args[0]) + return args[0] + case 'string': + if (isNaN(parseFloat(args[0]))) { + return { + path: args[0] + } + } + case 'number': // eslint-disable-line no-fallthrough + return { + port: args[0], + host: typeof args[1] === 'string' ? args[1] : 'localhost' + } + } +} + +module.exports = { + name: 'net', + patch (net, tracer, config) { + require('dns') // net will otherwise get an unpatched version for DNS lookups + + this.wrap(net.Socket.prototype, 'connect', createWrapConnect(tracer, config)) + }, + unpatch (net) { + this.unwrap(net.Socket.prototype, 'connect') + } +} + +module.exports = [] // disable this integration for the upcoming release diff --git a/src/plugins/pg.js b/src/plugins/pg.js index 09478622e13..069192835af 100644 --- a/src/plugins/pg.js +++ b/src/plugins/pg.js @@ -73,7 +73,7 @@ function unpatch (pg) { module.exports = { name: 'pg', - versions: ['>=4 <=7'], + versions: ['>=4'], patch, unpatch } diff --git a/src/plugins/pino.js b/src/plugins/pino.js new file mode 100644 index 00000000000..3c4fb2d3b15 --- /dev/null +++ b/src/plugins/pino.js @@ -0,0 +1,74 @@ +'use strict' + +const tx = require('./util/log') + +function createWrapWrite (tracer, config) { + return function wrapWrite (write) { + return function writeWithTrace (obj, msg, num) { + arguments[0] = obj = obj || {} + + tx.correlate(tracer, obj) + + return write.apply(this, arguments) + } + } +} + +function createWrapGenLog (tracer, config) { + return function wrapGenLog (genLog) { + return function genLogWithTrace (z) { + const log = genLog(z) + + return function logWithTrace (a, b, c, d, e, f, g, h, i, j, k) { + const args = [a, b, c, d, e, f, g, h, i, j, k] + + if (!a) { + args[0] = {} + } else if (typeof a !== 'object') { + args.unshift({}) + } + + tx.correlate(tracer, args[0]) + + return log.apply(this, args) + } + } + } +} + +module.exports = [ + { + name: 'pino', + versions: ['>=5'], + patch (pino, tracer, config) { + if (!tracer._logInjection) return + this.wrap(Object.getPrototypeOf(pino()), pino.symbols.writeSym, createWrapWrite(tracer, config)) + }, + unpatch (pino) { + this.unwrap(Object.getPrototypeOf(pino()), pino.symbols.writeSym) + } + }, + { + name: 'pino', + versions: ['4'], + file: 'lib/tools.js', + patch (tools, tracer, config) { + if (!tracer._logInjection) return + this.wrap(tools, 'genLog', createWrapGenLog(tracer, config)) + }, + unpatch (tools) { + this.unwrap(tools, 'genLog') + } + }, + { + name: 'pino', + versions: ['2 - 3'], + patch (pino, tracer, config) { + if (!tracer._logInjection) return + this.wrap(Object.getPrototypeOf(pino()), 'asJson', createWrapWrite(tracer, config)) + }, + unpatch (pino) { + this.unwrap(Object.getPrototypeOf(pino()), 'asJson') + } + } +] diff --git a/src/plugins/q.js b/src/plugins/q.js index 1a05ae5f82d..4e7fbdf7185 100644 --- a/src/plugins/q.js +++ b/src/plugins/q.js @@ -5,7 +5,7 @@ const tx = require('./util/promise') module.exports = [ { name: 'q', - versions: ['1'], + versions: ['>=1'], patch (Q, tracer, config) { this.wrap(Q.makePromise.prototype, 'then', tx.createWrapThen(tracer, config)) }, diff --git a/src/plugins/redis.js b/src/plugins/redis.js index 01faefe742c..df39b1123f9 100644 --- a/src/plugins/redis.js +++ b/src/plugins/redis.js @@ -45,7 +45,7 @@ function startSpan (tracer, config, client, command, args) { module.exports = [ { name: 'redis', - versions: ['^2.6'], + versions: ['>=2.6'], patch (redis, tracer, config) { this.wrap(redis.RedisClient.prototype, 'internal_send_command', createWrapInternalSendCommand(tracer, config)) }, diff --git a/src/plugins/restify.js b/src/plugins/restify.js index f45e4d500a3..7cc60d3e937 100644 --- a/src/plugins/restify.js +++ b/src/plugins/restify.js @@ -53,7 +53,7 @@ function wrapFn (fn) { module.exports = [ { name: 'restify', - versions: ['>=3 <=7'], + versions: ['>=3'], file: 'lib/server.js', patch (Server, tracer, config) { this.wrap(Server.prototype, '_setupRequest', createWrapSetupRequest(tracer, config)) diff --git a/src/plugins/router.js b/src/plugins/router.js index 442d4d64a19..07131c4cac0 100644 --- a/src/plugins/router.js +++ b/src/plugins/router.js @@ -6,10 +6,10 @@ const web = require('./util/web') function createWrapHandle (tracer, config) { return function wrapHandle (handle) { - return function handleWithTracer (req) { + return function handleWithTracer (req, res, done) { web.patch(req) - return handle.apply(this, arguments) + return handle.call(this, req, res, wrapDone(done, req)) } } } @@ -42,32 +42,39 @@ function wrapRouterMethod (original) { const offset = this.stack ? [].concat(this.stack).length : 0 const router = original.apply(this, arguments) - if (this.stack) { - wrapStack(this.stack, offset, extractMatchers(fn)) + if (typeof this.stack === 'function') { + this.stack = [{ handle: this.stack }] } + wrapStack(this.stack, offset, extractMatchers(fn)) + return router } } -function wrapStack (stack, offset, matchers) { - [].concat(stack).slice(offset).forEach(layer => { - const handle = layer.handle || layer - - if (handle.length === 4) { - layer.handle = (error, req, res, next) => { - return handle.call(layer, error, req, res, wrapNext(layer, req, next)) - } - } else { - layer.handle = (req, res, next) => { - return handle.call(layer, req, res, wrapNext(layer, req, next)) - } +function wrapLayerHandle (layer, handle) { + if (handle.length === 4) { + return function (error, req, res, next) { + return callHandle(layer, handle, req, [error, req, res, wrapNext(layer, req, next)]) } + } else { + return function (req, res, next) { + return callHandle(layer, handle, req, [req, res, wrapNext(layer, req, next)]) + } + } +} +function wrapStack (stack, offset, matchers) { + [].concat(stack).slice(offset).forEach(layer => { + layer.handle = wrapLayerHandle(layer, layer.handle) layer._datadog_matchers = matchers if (layer.route) { METHODS.forEach(method => { + if (typeof layer.route.stack === 'function') { + layer.route.stack = [{ handle: layer.route.stack }] + } + layer.route[method] = wrapRouterMethod(layer.route[method]) }) } @@ -75,25 +82,45 @@ function wrapStack (stack, offset, matchers) { } function wrapNext (layer, req, next) { - if (!web.active(req)) { - return next - } + if (!next || !web.active(req)) return next const originalNext = next - web.reactivate(req) - return function (error) { if (!error && layer.path && !isFastStar(layer)) { web.exitRoute(req) } + addError(web.active(req), error) + + web.exitMiddleware(req) + process.nextTick(() => { originalNext.apply(null, arguments) }) } } +function wrapDone (original, req) { + return function done (error) { + const span = web.root(req) + + addError(span, error) + + return original.apply(this, arguments) + } +} + +function callHandle (layer, handle, req, args) { + web.enterMiddleware(req, handle, 'express.middleware') + + try { + return handle.apply(layer, args) + } catch (e) { + throw addError(web.active(req), e) + } +} + function extractMatchers (fn) { const arg = flatten([].concat(fn)) @@ -119,9 +146,21 @@ function flatten (arr) { return arr.reduce((acc, val) => Array.isArray(val) ? acc.concat(flatten(val)) : acc.concat(val), []) } +function addError (span, error) { + if (error) { + span.addTags({ + 'error.type': error.name, + 'error.msg': error.message, + 'error.stack': error.stack + }) + } + + return error +} + module.exports = { name: 'router', - versions: ['1.x'], + versions: ['>=1'], patch (Router, tracer, config) { this.wrap(Router.prototype, 'handle', createWrapHandle(tracer, config)) this.wrap(Router.prototype, 'process_params', createWrapProcessParams(tracer, config)) diff --git a/src/plugins/util/log.js b/src/plugins/util/log.js new file mode 100644 index 00000000000..d8780e96f0e --- /dev/null +++ b/src/plugins/util/log.js @@ -0,0 +1,25 @@ +'use strict' + +const tx = require('./tx') + +const log = { + // Add trace identifiers from the current scope to a log record. + correlate (tracer, record) { + const scope = tracer.scopeManager().active() + + record = record || {} + + if (scope && scope.span()) { + const span = scope.span() + + record.dd = { + trace_id: span.context().toTraceId(), + span_id: span.context().toSpanId() + } + } + + return record + } +} + +module.exports = Object.assign({}, tx, log) diff --git a/src/plugins/util/redis.js b/src/plugins/util/redis.js index 210e114927c..efc318c73ff 100644 --- a/src/plugins/util/redis.js +++ b/src/plugins/util/redis.js @@ -20,7 +20,7 @@ const redis = { } }) - span.setTag('service.name', config.service || `${span.context().tags['service.name']}-redis`) + span.setTag('service.name', config.service || `${span.context()._tags['service.name']}-redis`) return span } diff --git a/src/plugins/util/web.js b/src/plugins/util/web.js index 4d050a77fd7..0649fc77e70 100644 --- a/src/plugins/util/web.js +++ b/src/plugins/util/web.js @@ -46,14 +46,14 @@ const web = { callback && callback(span) wrapEnd(req) + wrapEvents(req) return span }, // Reactivate the request scope in case it was changed by a middleware. reactivate (req) { - req._datadog.scope && req._datadog.scope.close() - req._datadog.scope = req._datadog.tracer.scopeManager().activate(req._datadog.span) + reactivate(req) }, // Add a route segment that will be used for the resource name. @@ -66,6 +66,38 @@ const web = { req._datadog.paths.pop() }, + // Start a new middleware span and activate a new scope with the span. + enterMiddleware (req, middleware, name) { + if (!this.active(req)) return + + const tracer = req._datadog.tracer + const childOf = this.active(req) + const span = tracer.startSpan(name, { childOf }) + const scope = tracer.scopeManager().activate(span) + + span.addTags({ + [RESOURCE_NAME]: middleware.name || '' + }) + + req._datadog.middleware.push(scope) + + return span + }, + + // Close the active middleware scope and finish its span. + exitMiddleware (req) { + if (!this.active(req)) return + + const scope = req._datadog.middleware.pop() + + if (!scope) return + + const span = scope.span() + + span.finish() + scope.close() + }, + // Register a callback to run before res.end() is called. beforeEnd (req, callback) { req._datadog.beforeEnd.push(callback) @@ -80,14 +112,23 @@ const web = { span: null, scope: null, paths: [], + middleware: [], beforeEnd: [] } }) }, - // Return the active span. For now, this is always the request span. - active (req) { + // Return the request root span. + root (req) { return req._datadog ? req._datadog.span : null + }, + + // Return the active span. + active (req) { + if (!req._datadog) return null + if (req._datadog.middleware.length === 0) return req._datadog.span || null + + return req._datadog.middleware.slice(-1)[0].span() } } @@ -95,7 +136,7 @@ function startSpan (tracer, config, req, res, name) { req._datadog.config = config if (req._datadog.span) { - req._datadog.span.context().name = name + req._datadog.span.context()._name = name return req._datadog.span } @@ -123,25 +164,76 @@ function finish (req, res) { addResourceTag(req) req._datadog.span.finish() - req._datadog.scope && req._datadog.scope.close() req._datadog.finished = true } +function finishMiddleware (req, res) { + if (req._datadog.finished) return + + let scope + + while ((scope = req._datadog.middleware.pop())) { + scope.span().finish() + scope.close() + } +} + function wrapEnd (req) { const res = req._datadog.res const end = res.end if (end === req._datadog.end) return - req._datadog.end = res.end = function () { + let _end = req._datadog.end = res.end = function () { req._datadog.beforeEnd.forEach(beforeEnd => beforeEnd()) + finishMiddleware(req, res) + const returnValue = end.apply(this, arguments) finish(req, res) return returnValue } + + Object.defineProperty(res, 'end', { + configurable: true, + get () { + return _end + }, + set (value) { + _end = value + if (typeof value === 'function') { + _end = function () { + reactivate(req) + return value.apply(this, arguments) + } + } else { + _end = value + } + } + }) +} + +function wrapEvents (req) { + const res = req._datadog.res + const on = res.on + + if (on === req._datadog.on) return + + req._datadog.on = res.on = function (eventName, listener) { + if (typeof listener !== 'function') return on.apply(this, arguments) + + return on.call(this, eventName, function () { + reactivate(req) + return listener.apply(this, arguments) + }) + } +} + +function reactivate (req) { + req._datadog.scope && req._datadog.scope.close() + req._datadog.scope = req._datadog.tracer.scopeManager().activate(req._datadog.span) } function addRequestTags (req) { @@ -176,7 +268,7 @@ function addResponseTags (req) { function addResourceTag (req) { const span = req._datadog.span - const tags = span.context().tags + const tags = span.context()._tags if (tags['resource.name']) return diff --git a/src/plugins/when.js b/src/plugins/when.js index 73d3a080bfb..2204aecde15 100644 --- a/src/plugins/when.js +++ b/src/plugins/when.js @@ -6,7 +6,7 @@ module.exports = [ { name: 'when', file: 'lib/Promise.js', - versions: ['3'], + versions: ['>=3'], patch (Promise, tracer, config) { this.wrap(Promise.prototype, 'then', tx.createWrapThen(tracer, config)) }, diff --git a/src/plugins/winston.js b/src/plugins/winston.js new file mode 100644 index 00000000000..79f363a499c --- /dev/null +++ b/src/plugins/winston.js @@ -0,0 +1,69 @@ +'use strict' + +const tx = require('./util/log') + +function createWrapWrite (tracer, config) { + return function wrapWrite (write) { + return function writeWithTrace (chunk, encoding, callback) { + tx.correlate(tracer, chunk) + + return write.apply(this, arguments) + } + } +} + +function createWrapLog (tracer, config) { + return function wrapLog (log) { + return function logWithTrace (level, msg, meta, callback) { + const scope = tracer.scopeManager().active() + + if (!scope || arguments.length < 1) return log.apply(this, arguments) + + for (let i = 0, l = arguments.length; i < l; i++) { + if (typeof arguments[i] !== 'object') continue + + tx.correlate(tracer, arguments[i]) + + return log.apply(this, arguments) + } + + meta = tx.correlate(tracer) + callback = arguments[arguments.length - 1] + + const index = typeof callback === 'function' + ? arguments.length - 1 + : arguments.length + + Array.prototype.splice.call(arguments, index, 0, meta) + + return log.apply(this, arguments) + } + } +} + +module.exports = [ + { + name: 'winston', + file: 'lib/winston/logger.js', + versions: ['>=3'], + patch (Logger, tracer, config) { + if (!tracer._logInjection) return + this.wrap(Logger.prototype, 'write', createWrapWrite(tracer, config)) + }, + unpatch (Logger) { + this.unwrap(Logger.prototype, 'write') + } + }, + { + name: 'winston', + file: 'lib/winston/logger.js', + versions: ['1 - 2'], + patch (logger, tracer, config) { + if (!tracer._logInjection) return + this.wrap(logger.Logger.prototype, 'log', createWrapLog(tracer, config)) + }, + unpatch (logger) { + this.unwrap(logger.Logger.prototype, 'log') + } + } +] diff --git a/src/priority_sampler.js b/src/priority_sampler.js index ff9987912e3..5c484e1ccdd 100644 --- a/src/priority_sampler.js +++ b/src/priority_sampler.js @@ -26,7 +26,7 @@ class PrioritySampler { isSampled (span) { const context = this._getContext(span) - const key = `service:${context.tags[SERVICE_NAME]},env:${this._env}` + const key = `service:${context._tags[SERVICE_NAME]},env:${this._env}` const sampler = this._samplers[key] || this._samplers[DEFAULT_KEY] return sampler.isSampled(span) @@ -35,16 +35,16 @@ class PrioritySampler { sample (span) { const context = this._getContext(span) - if (context.sampling.priority !== undefined) return + if (context._sampling.priority !== undefined) return - const tag = parseInt(context.tags[SAMPLING_PRIORITY], 10) + const tag = parseInt(context._tags[SAMPLING_PRIORITY], 10) if (this.validate(tag)) { - context.sampling.priority = tag + context._sampling.priority = tag return } - context.sampling.priority = this.isSampled(span) ? AUTO_KEEP : AUTO_REJECT + context._sampling.priority = this.isSampled(span) ? AUTO_KEEP : AUTO_REJECT } update (rates) { diff --git a/src/proxy.js b/src/proxy.js index 69a474c553d..52c0e4cc34b 100644 --- a/src/proxy.js +++ b/src/proxy.js @@ -2,7 +2,7 @@ const BaseTracer = require('opentracing').Tracer const memoize = require('lodash.memoize') -const NoopTracer = require('./noop') +const NoopTracer = require('./noop/tracer') const DatadogTracer = require('./tracer') const Config = require('./config') const Instrumenter = require('./instrumenter') @@ -36,6 +36,8 @@ class Tracer extends BaseTracer { * @param {boolean} [options.enabled=true] Whether to enable the tracer. * @param {boolean} [options.debug=false] Enable debug logging in the tracer. * @param {string} [options.service] The service name to be used for this program. + * @param {string} [options.url=null] The url to the trace agent that the tracer will submit to. Takes + * precedence over hostname and port, if set. * @param {string} [options.hostname=localhost] The address of the trace agent that the tracer will submit to. * @param {number|string} [options.port=8126] The port of the trace agent that the tracer will submit to. * @param {number} [options.sampleRate=1] Percentage of spans to sample as a float between 0 and 1. diff --git a/src/writer.js b/src/writer.js index ef88a126e0c..64f12077b66 100644 --- a/src/writer.js +++ b/src/writer.js @@ -19,7 +19,7 @@ class Writer { } append (span) { - const trace = span.context().trace + const trace = span.context()._trace if (trace.started.length === trace.finished.length) { const formattedTrace = trace.finished.map(format) diff --git a/test/.eslintrc.json b/test/.eslintrc.json index fabba82a1b4..afebed27d8a 100644 --- a/test/.eslintrc.json +++ b/test/.eslintrc.json @@ -14,6 +14,7 @@ "withVersions": true }, "rules": { - "no-unused-expressions": 0 + "no-unused-expressions": 0, + "handle-callback-err": 0 } } diff --git a/test/config.spec.js b/test/config.spec.js index db0a567fde4..ea20f2232da 100644 --- a/test/config.spec.js +++ b/test/config.spec.js @@ -49,12 +49,33 @@ describe('Config', () => { expect(config).to.have.property('enabled', false) expect(config).to.have.property('debug', true) + expect(config).to.have.nested.property('url.protocol', 'http:') expect(config).to.have.nested.property('url.hostname', 'agent') expect(config).to.have.nested.property('url.port', '6218') expect(config).to.have.property('service', 'service') expect(config).to.have.property('env', 'test') }) + it('should initialize from environment variables with url taking precedence', () => { + platform.env.withArgs('DD_TRACE_AGENT_URL').returns('https://agent2:7777') + platform.env.withArgs('DD_TRACE_AGENT_HOSTNAME').returns('agent') + platform.env.withArgs('DD_TRACE_AGENT_PORT').returns('6218') + platform.env.withArgs('DD_TRACE_ENABLED').returns('false') + platform.env.withArgs('DD_TRACE_DEBUG').returns('true') + platform.env.withArgs('DD_SERVICE_NAME').returns('service') + platform.env.withArgs('DD_ENV').returns('test') + + const config = new Config() + + expect(config).to.have.property('enabled', false) + expect(config).to.have.property('debug', true) + expect(config).to.have.nested.property('url.protocol', 'https:') + expect(config).to.have.nested.property('url.hostname', 'agent2') + expect(config).to.have.nested.property('url.port', '7777') + expect(config).to.have.property('service', 'service') + expect(config).to.have.property('env', 'test') + }) + it('should initialize from the options', () => { const logger = {} const tags = { foo: 'bar' } @@ -74,6 +95,7 @@ describe('Config', () => { expect(config).to.have.property('enabled', false) expect(config).to.have.property('debug', true) + expect(config).to.have.nested.property('url.protocol', 'http:') expect(config).to.have.nested.property('url.hostname', 'agent') expect(config).to.have.nested.property('url.port', '6218') expect(config).to.have.property('service', 'service') @@ -85,6 +107,38 @@ describe('Config', () => { expect(config).to.have.property('plugins', false) }) + it('should initialize from the options with url taking precedence', () => { + const logger = {} + const tags = { foo: 'bar' } + const config = new Config({ + enabled: false, + debug: true, + hostname: 'agent', + url: 'https://agent2:7777', + port: 6218, + service: 'service', + env: 'test', + sampleRate: 0.5, + logger, + tags, + flushInterval: 5000, + plugins: false + }) + + expect(config).to.have.property('enabled', false) + expect(config).to.have.property('debug', true) + expect(config).to.have.nested.property('url.protocol', 'https:') + expect(config).to.have.nested.property('url.hostname', 'agent2') + expect(config).to.have.nested.property('url.port', '7777') + expect(config).to.have.property('service', 'service') + expect(config).to.have.property('env', 'test') + expect(config).to.have.property('sampleRate', 0.5) + expect(config).to.have.property('logger', logger) + expect(config).to.have.deep.property('tags', tags) + expect(config).to.have.property('flushInterval', 5000) + expect(config).to.have.property('plugins', false) + }) + it('should give priority to the common agent environment variable', () => { platform.env.withArgs('DD_TRACE_AGENT_HOSTNAME').returns('trace-agent') platform.env.withArgs('DD_AGENT_HOST').returns('agent') @@ -95,6 +149,7 @@ describe('Config', () => { }) it('should give priority to the options', () => { + platform.env.withArgs('DD_TRACE_AGENT_URL').returns('https://agent2:6218') platform.env.withArgs('DD_TRACE_AGENT_HOSTNAME').returns('agent') platform.env.withArgs('DD_TRACE_AGENT_PORT').returns('6218') platform.env.withArgs('DD_TRACE_ENABLED').returns('false') @@ -105,6 +160,7 @@ describe('Config', () => { const config = new Config({ enabled: true, debug: false, + protocol: 'https', hostname: 'server', port: 7777, service: 'test', @@ -113,8 +169,38 @@ describe('Config', () => { expect(config).to.have.property('enabled', true) expect(config).to.have.property('debug', false) - expect(config).to.have.nested.property('url.hostname', 'server') - expect(config).to.have.nested.property('url.port', '7777') + expect(config).to.have.nested.property('url.protocol', 'https:') + expect(config).to.have.nested.property('url.hostname', 'agent2') + expect(config).to.have.nested.property('url.port', '6218') + expect(config).to.have.property('service', 'test') + expect(config).to.have.property('env', 'development') + }) + + it('should give priority to the options especially url', () => { + platform.env.withArgs('DD_TRACE_AGENT_URL').returns('http://agent2:6218') + platform.env.withArgs('DD_TRACE_AGENT_HOSTNAME').returns('agent') + platform.env.withArgs('DD_TRACE_AGENT_PORT').returns('6218') + platform.env.withArgs('DD_TRACE_ENABLED').returns('false') + platform.env.withArgs('DD_TRACE_DEBUG').returns('true') + platform.env.withArgs('DD_SERVICE_NAME').returns('service') + platform.env.withArgs('DD_ENV').returns('test') + + const config = new Config({ + enabled: true, + debug: false, + url: 'https://agent3:7778', + protocol: 'http', + hostname: 'server', + port: 7777, + service: 'test', + env: 'development' + }) + + expect(config).to.have.property('enabled', true) + expect(config).to.have.property('debug', false) + expect(config).to.have.nested.property('url.protocol', 'https:') + expect(config).to.have.nested.property('url.hostname', 'agent3') + expect(config).to.have.nested.property('url.port', '7778') expect(config).to.have.property('service', 'test') expect(config).to.have.property('env', 'development') }) diff --git a/test/dd-trace.spec.js b/test/dd-trace.spec.js index 52219bf2336..3b99a331564 100644 --- a/test/dd-trace.spec.js +++ b/test/dd-trace.spec.js @@ -47,9 +47,9 @@ describe('dd-trace', () => { const payload = msgpack.decode(req.body, { codec }) expect(payload[0][0].trace_id).to.be.instanceof(Uint64BE) - expect(payload[0][0].trace_id.toString()).to.equal(span.context().traceId.toString()) + expect(payload[0][0].trace_id.toString()).to.equal(span.context()._traceId.toString()) expect(payload[0][0].span_id).to.be.instanceof(Uint64BE) - expect(payload[0][0].span_id.toString()).to.equal(span.context().spanId.toString()) + expect(payload[0][0].span_id.toString()).to.equal(span.context()._spanId.toString()) expect(payload[0][0].service).to.equal('test') expect(payload[0][0].name).to.equal('hello') expect(payload[0][0].resource).to.equal('/hello/:name') diff --git a/test/format.spec.js b/test/format.spec.js index 8970c866c02..5e1e7878ca5 100644 --- a/test/format.spec.js +++ b/test/format.spec.js @@ -17,11 +17,11 @@ describe('format', () => { spanContext = { traceId: id, spanId: id, - parentId: id, - tags: {}, - metrics: {}, - sampling: {}, - name: 'operation' + _parentId: id, + _tags: {}, + _metrics: {}, + _sampling: {}, + _name: 'operation' } span = { @@ -37,11 +37,11 @@ describe('format', () => { it('should convert a span to the correct trace format', () => { trace = format(span) - expect(trace.trace_id).to.equal(span.context().traceId) - expect(trace.span_id).to.equal(span.context().spanId) - expect(trace.parent_id).to.equal(span.context().parentId) - expect(trace.name).to.equal(span.context().name) - expect(trace.resource).to.equal(span.context().name) + expect(trace.trace_id).to.equal(span.context()._traceId) + expect(trace.span_id).to.equal(span.context()._spanId) + expect(trace.parent_id).to.equal(span.context()._parentId) + expect(trace.name).to.equal(span.context()._name) + expect(trace.resource).to.equal(span.context()._name) expect(trace.error).to.equal(0) expect(trace.start).to.be.instanceof(Int64BE) expect(trace.start.toNumber()).to.equal(span._startTime * 1e6) @@ -50,9 +50,9 @@ describe('format', () => { }) it('should extract Datadog specific tags', () => { - spanContext.tags['service.name'] = 'service' - spanContext.tags['span.type'] = 'type' - spanContext.tags['resource.name'] = 'resource' + spanContext._tags['service.name'] = 'service' + spanContext._tags['span.type'] = 'type' + spanContext._tags['resource.name'] = 'resource' trace = format(span) @@ -62,10 +62,10 @@ describe('format', () => { }) it('should only extract tags that are not Datadog specific to meta', () => { - spanContext.tags['service.name'] = 'service' - spanContext.tags['span.type'] = 'type' - spanContext.tags['resource.name'] = 'resource' - spanContext.tags['foo.bar'] = 'foobar' + spanContext._tags['service.name'] = 'service' + spanContext._tags['span.type'] = 'type' + spanContext._tags['resource.name'] = 'resource' + spanContext._tags['foo.bar'] = 'foobar' trace = format(span) @@ -76,7 +76,7 @@ describe('format', () => { }) it('should extract metrics', () => { - spanContext.metrics = { metric: 50 } + spanContext._metrics = { metric: 50 } trace = format(span) @@ -84,7 +84,7 @@ describe('format', () => { }) it('should ignore metrics with invalid values', () => { - spanContext.metrics = { metric: 'test' } + spanContext._metrics = { metric: 'test' } trace = format(span) @@ -103,7 +103,7 @@ describe('format', () => { describe('when there is an `error` tag ', () => { it('should set the error flag when error tag is true', () => { - spanContext.tags['error'] = true + spanContext._tags['error'] = true trace = format(span) @@ -111,7 +111,7 @@ describe('format', () => { }) it('should not set the error flag when error is false', () => { - spanContext.tags['error'] = false + spanContext._tags['error'] = false trace = format(span) @@ -119,7 +119,7 @@ describe('format', () => { }) it('should not extract error to meta', () => { - spanContext.tags['error'] = true + spanContext._tags['error'] = true trace = format(span) @@ -128,9 +128,9 @@ describe('format', () => { }) it('should set the error flag when there is an error-related tag', () => { - spanContext.tags['error.type'] = 'Error' - spanContext.tags['error.msg'] = 'boom' - spanContext.tags['error.stack'] = '' + spanContext._tags['error.type'] = 'Error' + spanContext._tags['error.msg'] = 'boom' + spanContext._tags['error.stack'] = '' trace = format(span) @@ -138,8 +138,8 @@ describe('format', () => { }) it('should sanitize the input', () => { - spanContext.name = null - spanContext.tags = { + spanContext._name = null + spanContext._tags = { 'foo.bar': null } span._startTime = NaN @@ -155,7 +155,7 @@ describe('format', () => { }) it('should include the sampling priority', () => { - spanContext.sampling.priority = 0 + spanContext._sampling.priority = 0 trace = format(span) expect(trace.metrics[SAMPLING_PRIORITY_KEY]).to.equal(0) }) diff --git a/test/instrumenter.spec.js b/test/instrumenter.spec.js index 9e61b83e97a..b9a34419c61 100644 --- a/test/instrumenter.spec.js +++ b/test/instrumenter.spec.js @@ -1,6 +1,7 @@ 'use strict' const proxyquire = require('proxyquire').noCallThru() +const path = require('path') describe('Instrumenter', () => { let Instrumenter @@ -67,7 +68,13 @@ describe('Instrumenter', () => { }) afterEach(() => { - delete require.cache[require.resolve('mysql-mock')] + const basedir = path.resolve(path.join(__dirname, 'node_modules')) + + Object.keys(require.cache) + .filter(name => name.indexOf(basedir) !== -1) + .forEach(name => { + delete require.cache[name] + }) }) describe('with integrations enabled', () => { @@ -142,6 +149,25 @@ describe('Instrumenter', () => { expect(integrations.mysql[0].patch).to.not.have.been.called expect(integrations.mysql[1].patch).to.not.have.been.called }) + + it('should attempt to patch already loaded modules', () => { + const express = require('express-mock') + + instrumenter.use('express-mock') + + expect(integrations.express.patch).to.have.been.called + expect(integrations.express.patch).to.have.been.calledWith(express, 'tracer', {}) + }) + + it('should not patch twice already loaded modules', () => { + require('express-mock') + + instrumenter.use('express-mock') + + require('express-mock') + + expect(integrations.express.patch).to.have.been.calledOnce + }) }) describe('patch', () => { diff --git a/test/noop.spec.js b/test/noop.spec.js index 441481d55ff..677c2794525 100644 --- a/test/noop.spec.js +++ b/test/noop.spec.js @@ -7,7 +7,7 @@ describe('NoopTracer', () => { let tracer beforeEach(() => { - NoopTracer = require('../src/noop') + NoopTracer = require('../src/noop/tracer') tracer = new NoopTracer() }) @@ -25,4 +25,15 @@ describe('NoopTracer', () => { expect(tracer.currentSpan()).to.be.null }) }) + + describe('startSpan', () => { + it('should return a span with a valid context', () => { + const span = tracer.startSpan() + + expect(span.context().toTraceId).to.be.a('function') + expect(span.context().toTraceId()).to.equal('0') + expect(span.context().toSpanId).to.be.a('function') + expect(span.context().toSpanId()).to.equal('0') + }) + }) }) diff --git a/test/opentracing/propagation/log.spec.js b/test/opentracing/propagation/log.spec.js new file mode 100644 index 00000000000..84eab0b1d85 --- /dev/null +++ b/test/opentracing/propagation/log.spec.js @@ -0,0 +1,59 @@ +'use strict' + +const Uint64BE = require('int64-buffer').Uint64BE +const SpanContext = require('../../../src/opentracing/span_context') + +describe('LogPropagator', () => { + let LogPropagator + let propagator + let log + + beforeEach(() => { + LogPropagator = require('../../../src/opentracing/propagation/log') + propagator = new LogPropagator() + log = { + dd: { + trace_id: '123', + span_id: '18446744073709551160' // -456 casted to uint64 + } + } + }) + + describe('inject', () => { + it('should inject the span context into the carrier', () => { + const carrier = {} + const spanContext = new SpanContext({ + traceId: new Uint64BE(0, 123), + spanId: new Uint64BE(-456) + }) + + propagator.inject(spanContext, carrier) + + expect(carrier).to.deep.include({ + dd: { + trace_id: '123', + span_id: '18446744073709551160' // -456 casted to uint64 + } + }) + }) + }) + + describe('extract', () => { + it('should extract a span context from the carrier', () => { + const carrier = log + const spanContext = propagator.extract(carrier) + + expect(spanContext).to.deep.equal(new SpanContext({ + traceId: new Uint64BE(0, 123), + spanId: new Uint64BE(-456) + })) + }) + + it('should return null if the carrier does not contain a trace', () => { + const carrier = {} + const spanContext = propagator.extract(carrier) + + expect(spanContext).to.equal(null) + }) + }) +}) diff --git a/test/opentracing/span.spec.js b/test/opentracing/span.spec.js index 025021011a8..b96cf466361 100644 --- a/test/opentracing/span.spec.js +++ b/test/opentracing/span.spec.js @@ -42,23 +42,23 @@ describe('Span', () => { it('should have a default context', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation' }) - expect(span.context().traceId).to.deep.equal(new Uint64BE(123, 123)) - expect(span.context().spanId).to.deep.equal(new Uint64BE(123, 123)) + expect(span.context()._traceId).to.deep.equal(new Uint64BE(123, 123)) + expect(span.context()._spanId).to.deep.equal(new Uint64BE(123, 123)) }) it('should add itself to the context trace started spans', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation' }) - expect(span.context().trace.started).to.deep.equal([span]) + expect(span.context()._trace.started).to.deep.equal([span]) }) it('should use a parent context', () => { const parent = { - traceId: new Uint64BE(123, 123), - spanId: new Uint64BE(456, 456), - sampled: false, - baggageItems: { foo: 'bar' }, - trace: { + _traceId: new Uint64BE(123, 123), + _spanId: new Uint64BE(456, 456), + _sampled: false, + _baggageItems: { foo: 'bar' }, + _trace: { started: ['span'], finished: [] } @@ -66,19 +66,19 @@ describe('Span', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation', parent }) - expect(span.context().traceId).to.deep.equal(new Uint64BE(123, 123)) - expect(span.context().parentId).to.deep.equal(new Uint64BE(456, 456)) - expect(span.context().baggageItems).to.deep.equal({ foo: 'bar' }) - expect(span.context().trace.started).to.deep.equal(['span', span]) + expect(span.context()._traceId).to.deep.equal(new Uint64BE(123, 123)) + expect(span.context()._parentId).to.deep.equal(new Uint64BE(456, 456)) + expect(span.context()._baggageItems).to.deep.equal({ foo: 'bar' }) + expect(span.context()._trace.started).to.deep.equal(['span', span]) }) it('should start a new trace if the parent trace is finished', () => { const parent = { - traceId: new Uint64BE(123, 123), - spanId: new Uint64BE(456, 456), - sampled: false, - baggageItems: { foo: 'bar' }, - trace: { + _traceId: new Uint64BE(123, 123), + _spanId: new Uint64BE(456, 456), + _sampled: false, + _baggageItems: { foo: 'bar' }, + _trace: { started: ['span'], finished: ['span'] } @@ -86,11 +86,11 @@ describe('Span', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation', parent }) - expect(span.context().trace.started).to.deep.equal([span]) + expect(span.context()._trace.started).to.deep.equal([span]) }) it('should set the sample rate metric from the sampler', () => { - expect(span.context().metrics).to.have.property(SAMPLE_RATE_METRIC_KEY, 1) + expect(span.context()._metrics).to.have.property(SAMPLE_RATE_METRIC_KEY, 1) }) describe('tracer', () => { @@ -106,23 +106,35 @@ describe('Span', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'foo' }) span.setOperationName('bar') - expect(span.context().name).to.equal('bar') + expect(span.context()._name).to.equal('bar') }) }) describe('setBaggageItem', () => { - it('should set a baggage item', () => { - span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation' }) + it('should set a baggage item on the trace', () => { + const parent = { + traceId: new Uint64BE(123, 123), + spanId: new Uint64BE(456, 456), + _sampled: false, + _baggageItems: {}, + _trace: { + started: ['span'], + finished: ['span'] + } + } + + span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation', parent }) span.setBaggageItem('foo', 'bar') - expect(span.context().baggageItems).to.have.property('foo', 'bar') + expect(span.context()._baggageItems).to.have.property('foo', 'bar') + expect(parent._baggageItems).to.have.property('foo', 'bar') }) }) describe('getBaggageItem', () => { it('should get a baggage item', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation' }) - span._spanContext.baggageItems.foo = 'bar' + span._spanContext._baggageItems.foo = 'bar' expect(span.getBaggageItem('foo')).to.equal('bar') }) @@ -133,7 +145,7 @@ describe('Span', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation' }) span.setTag('foo', 'bar') - expect(span.context().tags).to.have.property('foo', 'bar') + expect(span.context()._tags).to.have.property('foo', 'bar') }) }) @@ -142,14 +154,14 @@ describe('Span', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation' }) span.addTags({ foo: 'bar' }) - expect(span.context().tags).to.have.property('foo', 'bar') + expect(span.context()._tags).to.have.property('foo', 'bar') }) it('should ensure tags are strings', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation' }) span.addTags({ foo: 123 }) - expect(span.context().tags).to.have.property('foo', '123') + expect(span.context()._tags).to.have.property('foo', '123') }) it('should handle errors', () => { @@ -166,7 +178,7 @@ describe('Span', () => { span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation' }) span.finish() - expect(span.context().trace.finished).to.deep.equal([span]) + expect(span.context()._trace.finished).to.deep.equal([span]) }) it('should record the span if sampled', () => { @@ -200,12 +212,12 @@ describe('Span', () => { it('should generate sampling priority', () => { prioritySampler.sample = span => { - span.context().sampling.priority = 2 + span.context()._sampling.priority = 2 } span = new Span(tracer, recorder, sampler, prioritySampler, { operationName: 'operation' }) span.finish() - expect(span.context().sampling.priority).to.equal(2) + expect(span.context()._sampling.priority).to.equal(2) }) }) }) diff --git a/test/opentracing/span_context.spec.js b/test/opentracing/span_context.spec.js index 920d88db356..c3bafdccec1 100644 --- a/test/opentracing/span_context.spec.js +++ b/test/opentracing/span_context.spec.js @@ -1,5 +1,7 @@ 'use strict' +const Uint64BE = require('int64-buffer').Uint64BE + describe('SpanContext', () => { let SpanContext @@ -27,7 +29,23 @@ describe('SpanContext', () => { } const spanContext = new SpanContext(props) - expect(spanContext).to.deep.equal(props) + expect(spanContext).to.deep.equal({ + _traceId: '123', + _spanId: '456', + _parentId: '789', + _name: 'test', + _children: ['span'], + _isFinished: true, + _tags: {}, + _metrics: {}, + _sampled: false, + _sampling: { priority: 2 }, + _baggageItems: { foo: 'bar' }, + _trace: { + started: ['span1', 'span2'], + finished: ['span1'] + } + }) }) it('should have the correct default values', () => { @@ -54,6 +72,44 @@ describe('SpanContext', () => { spanId: expected.spanId }) - expect(spanContext).to.deep.equal(expected) + expect(spanContext).to.deep.equal({ + _traceId: '123', + _spanId: '456', + _parentId: null, + _name: undefined, + _children: [], + _isFinished: false, + _tags: {}, + _metrics: {}, + _sampled: true, + _sampling: {}, + _baggageItems: {}, + _trace: { + started: [], + finished: [] + } + }) + }) + + describe('toTraceId()', () => { + it('should return the trace ID as string', () => { + const spanContext = new SpanContext({ + traceId: new Uint64BE(123), + spanId: new Uint64BE(456) + }) + + expect(spanContext.toTraceId()).to.equal('123') + }) + }) + + describe('toSpanId()', () => { + it('should return the span ID as string', () => { + const spanContext = new SpanContext({ + traceId: new Uint64BE(123), + spanId: new Uint64BE(456) + }) + + expect(spanContext.toSpanId()).to.equal('456') + }) }) }) diff --git a/test/opentracing/tracer.spec.js b/test/opentracing/tracer.spec.js index 7814f5fcce6..04283b6b7e9 100644 --- a/test/opentracing/tracer.spec.js +++ b/test/opentracing/tracer.spec.js @@ -141,7 +141,7 @@ describe('Tracer', () => { it('should start a span that is the child of a span', () => { const parent = new SpanContext() - parent.children = [] + parent._children = [] fields.references = [ new Reference(opentracing.REFERENCE_CHILD_OF, parent) ] diff --git a/test/plugins/bunyan.spec.js b/test/plugins/bunyan.spec.js new file mode 100644 index 00000000000..00e0bcefeec --- /dev/null +++ b/test/plugins/bunyan.spec.js @@ -0,0 +1,80 @@ +'use strict' + +const Writable = require('stream').Writable +const agent = require('./agent') +const plugin = require('../../src/plugins/bunyan') + +wrapIt() + +describe('Plugin', () => { + let logger + let tracer + let stream + let span + + function setup (version) { + const bunyan = require(`../../versions/bunyan@${version}`).get() + + span = tracer.startSpan('test') + + stream = new Writable() + stream._write = () => {} + + sinon.spy(stream, 'write') + + logger = bunyan.createLogger({ name: 'test', stream }) + } + + describe('bunyan', () => { + withVersions(plugin, 'bunyan', version => { + beforeEach(() => { + tracer = require('../..') + return agent.load(plugin, 'bunyan') + }) + + afterEach(() => { + return agent.close() + }) + + describe('without configuration', () => { + beforeEach(() => { + setup(version) + }) + + it('should not alter the default behavior', () => { + tracer.scopeManager().activate(span) + + logger.info('message') + + expect(stream.write).to.have.been.called + + const record = JSON.parse(stream.write.firstCall.args[0].toString()) + + expect(record).to.not.have.property('dd') + }) + }) + + describe('with configuration', () => { + beforeEach(() => { + tracer._tracer._logInjection = true + setup(version) + }) + + it('should add the trace identifiers to logger instances', () => { + tracer.scopeManager().activate(span) + + logger.info('message') + + expect(stream.write).to.have.been.called + + const record = JSON.parse(stream.write.firstCall.args[0].toString()) + + expect(record).to.have.deep.property('dd', { + trace_id: span.context().toTraceId(), + span_id: span.context().toSpanId() + }) + }) + }) + }) + }) +}) diff --git a/test/plugins/dns.spec.js b/test/plugins/dns.spec.js new file mode 100644 index 00000000000..3289fa8219c --- /dev/null +++ b/test/plugins/dns.spec.js @@ -0,0 +1,148 @@ +'use strict' + +const semver = require('semver') +const agent = require('./agent') +const plugin = require('../../src/plugins/dns') + +wrapIt() + +const describe = () => {} // integration disabled for the upcoming release + +describe('Plugin', () => { + let dns + + describe('dns', () => { + afterEach(() => { + return agent.close() + }) + + beforeEach(() => { + return agent.load(plugin, 'dns') + .then(() => { + dns = require(`dns`) + }) + }) + + it('should instrument lookup', done => { + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'dns.lookup', + service: 'test-dns', + resource: 'localhost', + meta: { + 'dns.hostname': 'localhost', + 'span.kind': 'client' + } + }) + }) + .then(done) + .catch(done) + + dns.lookup('localhost', 4, (err, address, family) => err && done(err)) + }) + + it('should instrument lookupService', done => { + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'dns.lookup_service', + service: 'test-dns', + resource: '127.0.0.1:22', + meta: { + 'dns.address': '127.0.0.1', + 'dns.port': '22', + 'span.kind': 'client' + } + }) + }) + .then(done) + .catch(done) + + dns.lookupService('127.0.0.1', 22, err => err && done(err)) + }) + + it('should instrument resolve', done => { + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'dns.resolve', + service: 'test-dns', + resource: 'A localhost', + meta: { + 'dns.hostname': 'localhost', + 'dns.rrtype': 'A', + 'span.kind': 'client' + } + }) + }) + .then(done) + .catch(done) + + dns.resolve('localhost', err => err && done(err)) + }) + + it('should instrument resolve shorthands', done => { + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'dns.resolve', + service: 'test-dns', + resource: 'ANY localhost', + meta: { + 'dns.hostname': 'localhost', + 'dns.rrtype': 'ANY', + 'span.kind': 'client' + } + }) + }) + .then(done) + .catch(done) + + dns.resolveAny('localhost', err => err && done(err)) + }) + + it('should instrument reverse', done => { + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'dns.reverse', + service: 'test-dns', + resource: '127.0.0.1', + meta: { + 'dns.ip': '127.0.0.1', + 'span.kind': 'client' + } + }) + }) + .then(done) + .catch(done) + + dns.reverse('127.0.0.1', err => err && done(err)) + }) + + if (semver.gte(process.version, '8.3.0')) { + it('should instrument Resolver', done => { + const resolver = new dns.Resolver() + + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'dns.resolve', + service: 'test-dns', + resource: 'A localhost', + meta: { + 'dns.hostname': 'localhost', + 'dns.rrtype': 'A', + 'span.kind': 'client' + } + }) + }) + .then(done) + .catch(done) + + resolver.resolve('localhost', err => err && done(err)) + }) + } + }) +}) diff --git a/test/plugins/express.spec.js b/test/plugins/express.spec.js index f7c99a271b9..56704dce07f 100644 --- a/test/plugins/express.spec.js +++ b/test/plugins/express.spec.js @@ -7,6 +7,8 @@ const plugin = require('../../src/plugins/express') wrapIt() +const sort = spans => spans.sort((a, b) => a.start.toString() >= b.start.toString() ? 1 : -1) + describe('Plugin', () => { let tracer let express @@ -45,13 +47,15 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('service', 'test') - expect(traces[0][0]).to.have.property('type', 'http') - expect(traces[0][0]).to.have.property('resource', 'GET /user') - expect(traces[0][0].meta).to.have.property('span.kind', 'server') - expect(traces[0][0].meta).to.have.property('http.url', `http://localhost:${port}/user`) - expect(traces[0][0].meta).to.have.property('http.method', 'GET') - expect(traces[0][0].meta).to.have.property('http.status_code', '200') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('service', 'test') + expect(spans[0]).to.have.property('type', 'http') + expect(spans[0]).to.have.property('resource', 'GET /user') + expect(spans[0].meta).to.have.property('span.kind', 'server') + expect(spans[0].meta).to.have.property('http.url', `http://localhost:${port}/user`) + expect(spans[0].meta).to.have.property('http.method', 'GET') + expect(spans[0].meta).to.have.property('http.status_code', '200') }) .then(done) .catch(done) @@ -77,13 +81,15 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('service', 'test') - expect(traces[0][0]).to.have.property('type', 'http') - expect(traces[0][0]).to.have.property('resource', 'GET /app/user/:id') - expect(traces[0][0].meta).to.have.property('span.kind', 'server') - expect(traces[0][0].meta).to.have.property('http.url', `http://localhost:${port}/app/user/1`) - expect(traces[0][0].meta).to.have.property('http.method', 'GET') - expect(traces[0][0].meta).to.have.property('http.status_code', '200') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('service', 'test') + expect(spans[0]).to.have.property('type', 'http') + expect(spans[0]).to.have.property('resource', 'GET /app/user/:id') + expect(spans[0].meta).to.have.property('span.kind', 'server') + expect(spans[0].meta).to.have.property('http.url', `http://localhost:${port}/app/user/1`) + expect(spans[0].meta).to.have.property('http.method', 'GET') + expect(spans[0].meta).to.have.property('http.status_code', '200') }) .then(done) .catch(done) @@ -111,13 +117,56 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('service', 'test') - expect(traces[0][0]).to.have.property('type', 'http') - expect(traces[0][0]).to.have.property('resource', 'GET /app/user/:id') - expect(traces[0][0].meta).to.have.property('span.kind', 'server') - expect(traces[0][0].meta).to.have.property('http.url', `http://localhost:${port}/app/user/1`) - expect(traces[0][0].meta).to.have.property('http.method', 'GET') - expect(traces[0][0].meta).to.have.property('http.status_code', '200') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('service', 'test') + expect(spans[0]).to.have.property('type', 'http') + expect(spans[0]).to.have.property('resource', 'GET /app/user/:id') + expect(spans[0].meta).to.have.property('span.kind', 'server') + expect(spans[0].meta).to.have.property('http.url', `http://localhost:${port}/app/user/1`) + expect(spans[0].meta).to.have.property('http.method', 'GET') + expect(spans[0].meta).to.have.property('http.status_code', '200') + }) + .then(done) + .catch(done) + + appListener = app.listen(port, 'localhost', () => { + axios + .get(`http://localhost:${port}/app/user/1`) + .catch(done) + }) + }) + }) + + it('should do automatic instrumentation on middleware', done => { + const app = express() + const router = express.Router() + + router.get('/user/:id', (req, res) => { + res.status(200).send() + }) + + app.use(function named (req, res, next) { next() }) + app.use('/app', router) + + getPort().then(port => { + agent + .use(traces => { + const spans = sort(traces[0]) + + expect(spans).to.have.length(5) + + expect(spans[0]).to.have.property('resource', 'GET /app/user/:id') + expect(spans[0]).to.have.property('name', 'express.request') + expect(spans[1]).to.have.property('resource', 'named') + expect(spans[1]).to.have.property('name', 'express.middleware') + expect(spans[1].parent_id.toString()).to.equal(spans[0].trace_id.toString()) + expect(spans[2]).to.have.property('resource', 'router') + expect(spans[2]).to.have.property('name', 'express.middleware') + expect(spans[3].resource).to.match(/^bound\s.*$/) + expect(spans[3]).to.have.property('name', 'express.middleware') + expect(spans[4]).to.have.property('resource', '') + expect(spans[4]).to.have.property('name', 'express.middleware') }) .then(done) .catch(done) @@ -143,7 +192,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('resource', 'GET /app(/^\\/user\\/(\\d)$/)') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /app(/^\\/user\\/(\\d)$/)') }) .then(done) .catch(done) @@ -169,7 +220,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('resource', 'GET /app/user/:id') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /app/user/:id') }) .then(done) .catch(done) @@ -201,7 +254,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('resource', 'GET /foo/bar') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /foo/bar') }) .then(done) .catch(done) @@ -227,7 +282,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('resource', 'GET /app/user/:id') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /app/user/:id') }) .then(done) .catch(done) @@ -254,7 +311,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('resource', 'GET /app/user/:id') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /app/user/:id') }) .then(done) .catch(done) @@ -280,8 +339,10 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0]).to.have.length(1) - expect(traces[0][0]).to.have.property('resource', 'GET /parent/child') + const spans = sort(traces[0]) + + expect(spans.filter(span => span.name === 'express.request')).to.have.length(1) + expect(spans[0]).to.have.property('resource', 'GET /parent/child') }) .then(done) .catch(done) @@ -294,6 +355,35 @@ describe('Plugin', () => { }) }) + it('should finish middleware spans when next() is called', done => { + const app = express() + + let span + + app.use((req, res, next) => { + const scope = tracer.scopeManager().active() + + span = scope.span() + sinon.spy(span, 'finish') + + next() + }) + + app.use((req, res, next) => { + expect(span.finish).to.have.been.called + res.status(200).send() + done() + }) + + getPort().then(port => { + appListener = app.listen(port, 'localhost', () => { + axios + .get(`http://localhost:${port}/app/user/1`) + .catch(done) + }) + }) + }) + it('should not lose the current path when changing scope', done => { if (process.env.DD_CONTEXT_PROPAGATION === 'false') return done() @@ -322,7 +412,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][1]).to.have.property('resource', 'GET /app/user/:id') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /app/user/:id') }) .then(done) .catch(done) @@ -358,7 +450,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('resource', 'GET /app/user/:id') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /app/user/:id') }) .then(done) .catch(done) @@ -385,7 +479,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('resource', 'GET /app') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /app') }) .then(done) .catch(done) @@ -440,7 +536,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('resource', 'GET') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET') }) .then(done) .catch(done) @@ -453,13 +551,13 @@ describe('Plugin', () => { }) }) - it('should reactivate the span when the active scope is closed', done => { + it('should activate a scope per middleware', done => { if (process.env.DD_CONTEXT_PROPAGATION === 'false') return done() const app = express() - let span let scope + let span app.use((req, res, next) => { scope = tracer.scopeManager().active() @@ -475,7 +573,7 @@ describe('Plugin', () => { try { expect(scope).to.not.be.null - expect(scope.span()).to.equal(span) + expect(scope.span()).to.not.equal(span) done() } catch (e) { done(e) @@ -490,7 +588,7 @@ describe('Plugin', () => { }) }) - it('should reactivate the span with multiple middleware on a route', done => { + it('should activate a span for every middleware on a route', done => { if (process.env.DD_CONTEXT_PROPAGATION === 'false') return done() const app = express() @@ -500,10 +598,8 @@ describe('Plugin', () => { app.get( '/user', (req, res, next) => { - const scope = tracer.scopeManager().active() - + const scope = tracer.scopeManager().activate({}) span = scope.span() - tracer.scopeManager().activate({}) next() }, @@ -514,7 +610,7 @@ describe('Plugin', () => { try { expect(scope).to.not.be.null - expect(scope.span()).to.equal(span) + expect(scope.span()).to.not.equal(span) done() } catch (e) { done(e) @@ -547,7 +643,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('resource', 'GET /app/user/:id') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /app/user/:id') }) .then(done) .catch(done) @@ -568,8 +666,10 @@ describe('Plugin', () => { getPort().then(port => { agent.use(traces => { - expect(traces[0][0].trace_id.toString()).to.equal('1234') - expect(traces[0][0].parent_id.toString()).to.equal('5678') + const spans = sort(traces[0]) + + expect(spans[0].trace_id.toString()).to.equal('1234') + expect(spans[0].parent_id.toString()).to.equal('5678') }) .then(done) .catch(done) @@ -588,7 +688,7 @@ describe('Plugin', () => { }) }) - it('should handle errors', done => { + it('should handle error status codes', done => { const app = express() app.use((req, res, next) => { @@ -601,9 +701,11 @@ describe('Plugin', () => { getPort().then(port => { agent.use(traces => { - expect(traces[0][0]).to.have.property('error', 1) - expect(traces[0][0]).to.have.property('resource', 'GET /user') - expect(traces[0][0].meta).to.have.property('http.status_code', '500') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('error', 1) + expect(spans[0]).to.have.property('resource', 'GET /user') + expect(spans[0].meta).to.have.property('http.status_code', '500') done() }) @@ -617,6 +719,63 @@ describe('Plugin', () => { }) }) }) + + it('should handle request errors', done => { + const app = express() + const error = new Error('boom') + + app.use(() => { throw error }) + + getPort().then(port => { + agent + .use(traces => { + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('error', 1) + expect(spans[0].meta).to.have.property('http.status_code', '500') + }) + .then(done) + .catch(done) + + appListener = app.listen(port, 'localhost', () => { + axios + .get(`http://localhost:${port}/user`, { + validateStatus: status => status === 500 + }) + .catch(done) + }) + }) + }) + + it('should handle middleware errors', done => { + const app = express() + const error = new Error('boom') + + app.use((req, res) => { throw error }) + app.use((error, req, res, next) => res.status(500).send()) + + getPort().then(port => { + agent + .use(traces => { + const spans = sort(traces[0]) + + expect(spans[1]).to.have.property('error', 1) + expect(spans[1].meta).to.have.property('error.type', error.name) + expect(spans[1].meta).to.have.property('error.msg', error.message) + expect(spans[1].meta).to.have.property('error.stack', error.stack) + }) + .then(done) + .catch(done) + + appListener = app.listen(port, 'localhost', () => { + axios + .get(`http://localhost:${port}/user`, { + validateStatus: status => status === 500 + }) + .catch(done) + }) + }) + }) }) describe('with configuration', () => { @@ -646,7 +805,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('service', 'custom') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('service', 'custom') }) .then(done) .catch(done) @@ -669,7 +830,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0]).to.have.property('error', 1) + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('error', 1) }) .then(done) .catch(done) @@ -694,7 +857,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0][0].meta).to.have.property('http.headers.user-agent', 'test') + const spans = sort(traces[0]) + + expect(spans[0].meta).to.have.property('http.headers.user-agent', 'test') }) .then(done) .catch(done) diff --git a/test/plugins/graphql.spec.js b/test/plugins/graphql.spec.js index ef1eb352da0..98a4960b85b 100644 --- a/test/plugins/graphql.spec.js +++ b/test/plugins/graphql.spec.js @@ -986,7 +986,7 @@ describe('Plugin', () => { try { expect(scope).to.not.be.null - expect(scope.span().context()).to.have.property('name', 'graphql.execute') + expect(scope.span().context()).to.have.property('_name', 'graphql.execute') done() } catch (e) { done(e) diff --git a/test/plugins/net.spec.js b/test/plugins/net.spec.js new file mode 100644 index 00000000000..fb781038fce --- /dev/null +++ b/test/plugins/net.spec.js @@ -0,0 +1,154 @@ +'use strict' + +const getPort = require('get-port') +const agent = require('./agent') +const plugin = require('../../src/plugins/net') + +wrapIt() + +const describe = () => {} // integration disabled for the upcoming release + +describe('Plugin', () => { + let net + let tcp + let ipc + let port + + describe('net', () => { + afterEach(() => { + return agent.close() + }) + + afterEach(() => { + tcp.close() + }) + + afterEach(() => { + ipc.close() + }) + + beforeEach(() => { + return agent.load(plugin, 'net') + .then(() => { + net = require(`net`) + + return getPort().then(_port => { + port = _port + }) + }) + }) + + beforeEach(done => { + tcp = new net.Server(socket => { + socket.write('') + }) + tcp.listen(port, () => done()) + }) + + beforeEach(done => { + ipc = new net.Server(socket => { + socket.write('') + }) + ipc.listen('/tmp/dd-trace.sock', () => done()) + }) + + it('should instrument connect with a path', done => { + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'ipc.connect', + service: 'test-ipc', + resource: '/tmp/dd-trace.sock', + meta: { + 'span.kind': 'client', + 'ipc.path': '/tmp/dd-trace.sock' + } + }) + }) + .then(done) + .catch(done) + + net.connect('/tmp/dd-trace.sock') + }) + + it('should instrument connect with a port', done => { + const socket = new net.Socket() + + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'tcp.connect', + service: 'test-tcp', + resource: `localhost:${port}`, + meta: { + 'span.kind': 'client', + 'tcp.family': 'IPv4', + 'tcp.remote.host': 'localhost', + 'tcp.remote.address': '127.0.0.1', + 'tcp.remote.port': `${port}`, + 'tcp.local.address': '127.0.0.1', + 'tcp.local.port': `${socket.localPort}`, + 'out.host': 'localhost', + 'out.port': `${port}` + } + }) + }) + .then(done) + .catch(done) + + socket.connect(port, 'localhost') + }) + + it('should instrument connect with TCP options', done => { + const socket = new net.Socket() + + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'tcp.connect', + service: 'test-tcp', + resource: `localhost:${port}`, + meta: { + 'span.kind': 'client', + 'tcp.family': 'IPv4', + 'tcp.remote.host': 'localhost', + 'tcp.remote.address': '127.0.0.1', + 'tcp.remote.port': `${port}`, + 'tcp.local.address': '127.0.0.1', + 'tcp.local.port': `${socket.localPort}`, + 'out.host': 'localhost', + 'out.port': `${port}` + } + }) + }) + .then(done) + .catch(done) + + socket.connect({ + port, + host: 'localhost' + }) + }) + + it('should instrument connect with IPC options', done => { + agent + .use(traces => { + expect(traces[0][0]).to.deep.include({ + name: 'ipc.connect', + service: 'test-ipc', + resource: '/tmp/dd-trace.sock', + meta: { + 'span.kind': 'client', + 'ipc.path': '/tmp/dd-trace.sock' + } + }) + }) + .then(done) + .catch(done) + + net.connect({ + path: '/tmp/dd-trace.sock' + }) + }) + }) +}) diff --git a/test/plugins/pino.spec.js b/test/plugins/pino.spec.js new file mode 100644 index 00000000000..f075b7b6a13 --- /dev/null +++ b/test/plugins/pino.spec.js @@ -0,0 +1,80 @@ +'use strict' + +const Writable = require('stream').Writable +const agent = require('./agent') +const plugin = require('../../src/plugins/pino') + +wrapIt() + +describe('Plugin', () => { + let logger + let tracer + let stream + let span + + function setup (version) { + const pino = require(`../../versions/pino@${version}`).get() + + span = tracer.startSpan('test') + + stream = new Writable() + stream._write = () => {} + + sinon.spy(stream, 'write') + + logger = pino(stream) + } + + describe('pino', () => { + withVersions(plugin, 'pino', version => { + beforeEach(() => { + tracer = require('../..') + return agent.load(plugin, 'pino') + }) + + afterEach(() => { + return agent.close() + }) + + describe('without configuration', () => { + beforeEach(() => { + setup(version) + }) + + it('should not alter the default behavior', () => { + tracer.scopeManager().activate(span) + + logger.info('message') + + expect(stream.write).to.have.been.called + + const record = JSON.parse(stream.write.firstCall.args[0].toString()) + + expect(record).to.not.have.property('dd') + }) + }) + + describe('with configuration', () => { + beforeEach(() => { + tracer._tracer._logInjection = true + setup(version) + }) + + it('should add the trace identifiers to logger instances', () => { + tracer.scopeManager().activate(span) + + logger.info('message') + + expect(stream.write).to.have.been.called + + const record = JSON.parse(stream.write.firstCall.args[0].toString()) + + expect(record).to.have.deep.property('dd', { + trace_id: span.context().toTraceId(), + span_id: span.context().toSpanId() + }) + }) + }) + }) + }) +}) diff --git a/test/plugins/router.spec.js b/test/plugins/router.spec.js index 5f70ac6df3f..5c03f499836 100644 --- a/test/plugins/router.spec.js +++ b/test/plugins/router.spec.js @@ -11,6 +11,8 @@ const plugin = require('../../src/plugins/router') wrapIt() +const sort = spans => spans.sort((a, b) => a.start.toString() >= b.start.toString() ? 1 : -1) + describe('Plugin', () => { let tracer let Router @@ -66,8 +68,9 @@ describe('Plugin', () => { getPort().then(port => { agent .use(traces => { - expect(traces[0]).to.have.length(1) - expect(traces[0][0]).to.have.property('resource', 'GET /parent/child/:id') + const spans = sort(traces[0]) + + expect(spans[0]).to.have.property('resource', 'GET /parent/child/:id') }) .then(done) .catch(done) diff --git a/test/plugins/util/log.spec.js b/test/plugins/util/log.spec.js new file mode 100644 index 00000000000..e8d92fff3e0 --- /dev/null +++ b/test/plugins/util/log.spec.js @@ -0,0 +1,56 @@ +'use strict' + +wrapIt() + +describe('plugins/util/log', () => { + let log + let tracer + + beforeEach(() => { + tracer = require('../../..').init({ service: 'test', plugins: false }) + log = require('../../../src/plugins/util/log') + }) + + describe('correlate', () => { + it('should attach the current scope trace identifiers to the log record', () => { + const record = {} + const span = tracer.startSpan('test') + + tracer.scopeManager().activate(span) + + log.correlate(tracer, record) + + expect(record).to.have.deep.property('dd', { + trace_id: span.context().toTraceId(), + span_id: span.context().toSpanId() + }) + }) + + it('should return a new correlated log record if one was not provided', () => { + const span = tracer.startSpan('test') + + tracer.scopeManager().activate(span) + + const record = log.correlate(tracer) + + expect(record).to.have.deep.property('dd', { + trace_id: span.context().toTraceId(), + span_id: span.context().toSpanId() + }) + }) + + it('should do nothing if there is no active scope', () => { + const record = log.correlate(tracer) + + expect(record).to.not.have.property('dd') + }) + + it('should do nothing if the active span is null', () => { + tracer.scopeManager().activate(null) + + const record = log.correlate(tracer) + + expect(record).to.not.have.property('dd') + }) + }) +}) diff --git a/test/plugins/util/redis.spec.js b/test/plugins/util/redis.spec.js index e578b2471dd..3325f0f27d5 100644 --- a/test/plugins/util/redis.spec.js +++ b/test/plugins/util/redis.spec.js @@ -16,7 +16,7 @@ describe('plugins/util/redis', () => { it('should start a span with the correct tags', () => { span = redis.instrument(tracer, config, '1', 'set', ['foo', 'bar']) - expect(span.context().tags).to.deep.include({ + expect(span.context()._tags).to.deep.include({ 'span.kind': 'client', 'service.name': 'test-redis', 'resource.name': 'set', @@ -38,7 +38,7 @@ describe('plugins/util/redis', () => { span = redis.instrument(tracer, config, '1', 'ping', []) - expect(span.context().parentId.toString()).to.equal(parent.context().spanId.toString()) + expect(span.context()._parentId.toString()).to.equal(parent.context()._spanId.toString()) }) it('should trim command arguments if yoo long', () => { @@ -50,7 +50,7 @@ describe('plugins/util/redis', () => { span = redis.instrument(tracer, config, '1', 'get', [key]) - const rawCommand = span.context().tags['redis.raw_command'] + const rawCommand = span.context()._tags['redis.raw_command'] expect(rawCommand).to.have.length(104) expect(rawCommand.substr(0, 10)).to.equal('GET aaaaaa') @@ -72,7 +72,7 @@ describe('plugins/util/redis', () => { span = redis.instrument(tracer, config, '1', 'get', values) - const rawCommand = span.context().tags['redis.raw_command'] + const rawCommand = span.context()._tags['redis.raw_command'] expect(rawCommand).to.have.length(1000) expect(rawCommand.substr(0, 10)).to.equal('GET aaaaaa') diff --git a/test/plugins/util/tx.spec.js b/test/plugins/util/tx.spec.js index bd83d2c4ea4..8c3d9c45f9d 100644 --- a/test/plugins/util/tx.spec.js +++ b/test/plugins/util/tx.spec.js @@ -21,8 +21,8 @@ describe('plugins/util/tx', () => { it('should set the out.host and out.port tags', () => { tx.setHost(span, 'example.com', '1234') - expect(span.context().tags).to.have.property('out.host', 'example.com') - expect(span.context().tags).to.have.property('out.port', '1234') + expect(span.context()._tags).to.have.property('out.host', 'example.com') + expect(span.context()._tags).to.have.property('out.port', '1234') }) }) @@ -45,9 +45,9 @@ describe('plugins/util/tx', () => { wrapper(error) - expect(span.context().tags).to.have.property('error.msg', error.message) - expect(span.context().tags).to.have.property('error.type', error.name) - expect(span.context().tags).to.have.property('error.stack', error.stack) + expect(span.context()._tags).to.have.property('error.msg', error.message) + expect(span.context()._tags).to.have.property('error.type', error.name) + expect(span.context()._tags).to.have.property('error.stack', error.stack) }) it('should return a wrapper that runs in the current scope', done => { @@ -91,9 +91,9 @@ describe('plugins/util/tx', () => { return promise.catch(err => { expect(err).to.equal(error) - expect(span.context().tags).to.have.property('error.msg', error.message) - expect(span.context().tags).to.have.property('error.type', error.name) - expect(span.context().tags).to.have.property('error.stack', error.stack) + expect(span.context()._tags).to.have.property('error.msg', error.message) + expect(span.context()._tags).to.have.property('error.type', error.name) + expect(span.context()._tags).to.have.property('error.stack', error.stack) }) }) }) diff --git a/test/plugins/util/web.spec.js b/test/plugins/util/web.spec.js index 462c13518d7..66eae56b83b 100644 --- a/test/plugins/util/web.spec.js +++ b/test/plugins/util/web.spec.js @@ -1,5 +1,7 @@ 'use strict' +const getPort = require('get-port') +const agent = require('../agent') const types = require('../../../ext/types') const kinds = require('../../../ext/kinds') const tags = require('../../../ext/tags') @@ -17,6 +19,8 @@ const HTTP_STATUS_CODE = tags.HTTP_STATUS_CODE const HTTP_ROUTE = tags.HTTP_ROUTE const HTTP_HEADERS = tags.HTTP_HEADERS +wrapIt() + describe('plugins/util/web', () => { let web let tracer @@ -58,8 +62,8 @@ describe('plugins/util/web', () => { span = web.instrument(tracer, config, req, res, 'test.request') - expect(span.context().traceId.toString()).to.equal('123') - expect(span.context().parentId.toString()).to.equal('456') + expect(span.context()._traceId.toString()).to.equal('123') + expect(span.context()._parentId.toString()).to.equal('456') }) it('should set the service name', () => { @@ -67,7 +71,7 @@ describe('plugins/util/web', () => { span = web.instrument(tracer, config, req, res, 'test.request') - expect(span.context().tags).to.have.property(SERVICE_NAME, 'custom') + expect(span.context()._tags).to.have.property(SERVICE_NAME, 'custom') }) it('should activate a scope with the span', () => { @@ -88,7 +92,7 @@ describe('plugins/util/web', () => { res.end() - expect(span.context().tags).to.include({ + expect(span.context()._tags).to.include({ [SPAN_TYPE]: HTTP, [HTTP_URL]: 'http://localhost/user/123', [HTTP_METHOD]: 'GET', @@ -103,7 +107,7 @@ describe('plugins/util/web', () => { res.end() - expect(span.context().tags).to.include({ + expect(span.context()._tags).to.include({ [`${HTTP_HEADERS}.host`]: 'localhost' }) }) @@ -122,7 +126,7 @@ describe('plugins/util/web', () => { span = web.instrument(tracer, config, req, res, 'test.request') span = web.instrument(tracer, config, req, res, 'test2.request') - expect(span.context().name).to.equal('test2.request') + expect(span.context()._name).to.equal('test2.request') }) it('should allow overriding the span service name', () => { @@ -130,7 +134,7 @@ describe('plugins/util/web', () => { config.service = 'test2' span = web.instrument(tracer, config, req, res, 'test.request') - expect(span.context().tags).to.have.property('service.name', 'test2') + expect(span.context()._tags).to.have.property('service.name', 'test2') }) it('should only wrap res.end once', () => { @@ -147,7 +151,7 @@ describe('plugins/util/web', () => { span = web.instrument(tracer, config, req, res, 'test.request') }) - it('should finish the span', () => { + it('should finish the request span', () => { sinon.spy(span, 'finish') res.end() @@ -164,6 +168,16 @@ describe('plugins/util/web', () => { expect(span.finish).to.have.been.calledOnce }) + it('should finish middleware spans', () => { + span = web.enterMiddleware(req, () => {}, 'middleware') + + sinon.spy(span, 'finish') + + res.end() + + expect(span.finish).to.have.been.called + }) + it('should execute any beforeEnd handlers', () => { const spy1 = sinon.spy() const spy2 = sinon.spy() @@ -190,7 +204,7 @@ describe('plugins/util/web', () => { res.end() - expect(span.context().tags).to.include({ + expect(span.context()._tags).to.include({ [RESOURCE_NAME]: 'GET', [HTTP_STATUS_CODE]: '200' }) @@ -201,7 +215,7 @@ describe('plugins/util/web', () => { res.end() - expect(span.context().tags).to.include({ + expect(span.context()._tags).to.include({ [ERROR]: 'true' }) }) @@ -211,7 +225,7 @@ describe('plugins/util/web', () => { res.end() - expect(span.context().tags).to.include({ + expect(span.context()._tags).to.include({ [ERROR]: 'true' }) }) @@ -221,7 +235,7 @@ describe('plugins/util/web', () => { res.end() - expect(span.context().tags).to.include({ + expect(span.context()._tags).to.include({ [HTTP_ROUTE]: '/custom/route' }) }) @@ -255,7 +269,7 @@ describe('plugins/util/web', () => { res.end() - expect(span.context().tags).to.have.property('resource.name', 'GET /custom/route') + expect(span.context()._tags).to.have.property('resource.name', 'GET /custom/route') }) }) }) @@ -273,8 +287,8 @@ describe('plugins/util/web', () => { web.enterRoute(req, '/bar') res.end() - expect(span.context().tags).to.have.property(RESOURCE_NAME, 'GET /foo/bar') - expect(span.context().tags).to.have.property(HTTP_ROUTE, '/foo/bar') + expect(span.context()._tags).to.have.property(RESOURCE_NAME, 'GET /foo/bar') + expect(span.context()._tags).to.have.property(HTTP_ROUTE, '/foo/bar') }) }) @@ -292,7 +306,52 @@ describe('plugins/util/web', () => { web.exitRoute(req) res.end() - expect(span.context().tags).to.have.property(RESOURCE_NAME, 'GET /foo') + expect(span.context()._tags).to.have.property(RESOURCE_NAME, 'GET /foo') + }) + }) + + describe('enterMiddleware', () => { + beforeEach(() => { + config = web.normalizeConfig(config) + span = web.instrument(tracer, config, req, res, 'test.request') + }) + + it('should activate a scope with the span', (done) => { + const fn = function test () { + const scope = tracer.scopeManager().active() + + expect(scope).to.not.be.null + expect(scope.span()).to.equal(span) + expect(scope.span().context()._tags).to.have.property('resource.name', 'test') + + done() + } + + span = web.enterMiddleware(req, fn, 'middleware') + + fn(req, res) + }) + }) + + describe('exitMiddleware', () => { + beforeEach(() => { + config = web.normalizeConfig(config) + span = web.instrument(tracer, config, req, res, 'test.request') + }) + + it('should close the scope of the current middleware', (done) => { + const fn = () => { + const scope = tracer.scopeManager().active() + + expect(scope).to.be.null + + done() + } + + web.enterMiddleware(req, fn, 'middleware') + web.exitMiddleware(req, fn, 'middleware') + + fn(req, res) }) }) @@ -307,15 +366,138 @@ describe('plugins/util/web', () => { }) }) + describe('root', () => { + it('should return the request root span', () => { + span = web.instrument(tracer, config, req, res, 'test.request') + + web.enterMiddleware(req, () => {}, 'express.middleware') + + expect(web.root(req)).to.equal(span) + }) + + it('should return null when not yet instrumented', () => { + expect(web.active(req)).to.be.null + }) + }) + describe('active', () => { - it('should return the active span', () => { + it('should return the request span by default', () => { span = web.instrument(tracer, config, req, res, 'test.request') expect(web.active(req)).to.equal(span) }) + it('should return the active middleware span', () => { + span = web.instrument(tracer, config, req, res, 'test.request') + + web.enterMiddleware(req, () => {}, 'express.middleware') + + expect(web.active(req)).to.not.be.null + expect(web.active(req)).to.not.equal(span) + }) + it('should return null when not yet instrumented', () => { expect(web.active(req)).to.be.null }) }) + + describe('with an instrumented web server', done => { + let express + let app + let port + let server + let http + + beforeEach(done => { + agent.load(null, 'express') + .then(getPort) + .then(_port => { + port = _port + http = require('http') + express = require('express') + app = express() + + server = app.listen(port, '127.0.0.1', () => done()) + }) + }) + + afterEach(done => { + agent.close().then(() => { + server.close(() => done()) + }) + }) + + it('should run res.end handlers in the request scope', done => { + let handler + + const interval = setInterval(() => { + if (handler) { + handler() + clearInterval(interval) + } + }) + + app.use((req, res) => { + const end = res.end + + res.end = function () { + end.apply(this, arguments) + + try { + expect(tracer.scopeManager().active()).to.not.be.null + done() + } catch (e) { + done(e) + } + } + + handler = () => res.status(200).send() + }) + + const req = http.get(`http://127.0.0.1:${port}`) + req.on('error', done) + }) + + it('should run "finish" event handlers in the request scope', done => { + app.use((req, res, next) => { + res.on('finish', () => { + try { + expect(tracer.scopeManager().active()).to.not.be.null + done() + } catch (e) { + done(e) + } + }) + + res.status(200).send() + }) + + const req = http.get(`http://127.0.0.1:${port}`) + req.on('error', done) + }) + + it('should run "close" event handlers in the request scope', done => { + const sockets = [] + + app.use((req, res, next) => { + res.on('close', () => { + try { + expect(tracer.scopeManager().active()).to.not.be.null + done() + } catch (e) { + done(e) + } + }) + + sockets.forEach(socket => socket.destroy()) + }) + + server.on('connection', (socket) => { + sockets.push(socket) + }) + + const req = http.get(`http://127.0.0.1:${port}`) + req.on('error', () => {}) + }) + }) }) diff --git a/test/plugins/winston.spec.js b/test/plugins/winston.spec.js new file mode 100644 index 00000000000..6cdd398f475 --- /dev/null +++ b/test/plugins/winston.spec.js @@ -0,0 +1,148 @@ +'use strict' + +const semver = require('semver') +const agent = require('./agent') +const plugin = require('../../src/plugins/winston') + +wrapIt() + +describe('Plugin', () => { + let winston + let tracer + let transport + let span + + function setup (version) { + span = tracer.startSpan('test') + + winston = require(`../../versions/winston@${version}`).get() + + class Transport extends winston.Transport {} + + Transport.prototype.log = sinon.spy() + + transport = new Transport() + + if (winston.configure) { + winston.configure({ + transports: [transport] + }) + } else { + winston.add(Transport) + winston.remove(winston.transports.Console) + } + } + + describe('winston', () => { + withVersions(plugin, 'winston', version => { + beforeEach(() => { + tracer = require('../..') + return agent.load(plugin, 'winston') + }) + + afterEach(() => { + return agent.close() + }) + + describe('without configuration', () => { + beforeEach(() => { + setup(version) + }) + + it('should not alter the default behavior', () => { + const meta = { + dd: { + trace_id: span.context().toTraceId(), + span_id: span.context().toSpanId() + } + } + + tracer.scopeManager().activate(span) + + winston.info('message') + + if (semver.intersects(version, '>=3')) { + expect(transport.log).to.not.have.been.calledWithMatch(meta) + } else { + expect(transport.log).to.not.have.been.calledWithMatch('info', 'message', meta) + } + }) + }) + + describe('with configuration', () => { + beforeEach(() => { + tracer._tracer._logInjection = true + setup(version) + }) + + it('should add the trace identifiers to the default logger', () => { + const meta = { + dd: { + trace_id: span.context().toTraceId(), + span_id: span.context().toSpanId() + } + } + + tracer.scopeManager().activate(span) + + winston.info('message') + + if (semver.intersects(version, '>=3')) { + expect(transport.log).to.have.been.calledWithMatch(meta) + } else { + expect(transport.log).to.have.been.calledWithMatch('info', 'message', meta) + } + }) + + it('should add the trace identifiers to logger instances', () => { + const options = { + transports: [transport] + } + + const meta = { + dd: { + trace_id: span.context().toTraceId(), + span_id: span.context().toSpanId() + } + } + + const logger = winston.createLogger + ? winston.createLogger(options) + : new winston.Logger(options) + + tracer.scopeManager().activate(span) + + logger.info('message') + + if (semver.intersects(version, '>=3')) { + expect(transport.log).to.have.been.calledWithMatch(meta) + } else { + expect(transport.log).to.have.been.calledWithMatch('info', 'message', meta) + } + }) + + if (semver.intersects(version, '>=3')) { + it('should add the trace identifiers when streaming', () => { + const logger = winston.createLogger({ + transports: [transport] + }) + + tracer.scopeManager().activate(span) + + logger.write({ + level: 'info', + message: 'message' + }) + + expect(transport.log).to.have.been.calledWithMatch({ + dd: { + trace_id: span.context().toTraceId(), + span_id: span.context().toSpanId() + } + }) + }) + } + }) + }) + }) +}) diff --git a/test/priority_sampler.spec.js b/test/priority_sampler.spec.js index 8474cf8f4a4..197a66090fc 100644 --- a/test/priority_sampler.spec.js +++ b/test/priority_sampler.spec.js @@ -17,8 +17,8 @@ describe('PrioritySampler', () => { beforeEach(() => { context = { - tags: {}, - sampling: {} + _tags: {}, + _sampling: {} } span = { @@ -59,31 +59,31 @@ describe('PrioritySampler', () => { it('should set the correct priority by default', () => { prioritySampler.sample(span) - expect(context.sampling.priority).to.equal(AUTO_KEEP) + expect(context._sampling.priority).to.equal(AUTO_KEEP) }) it('should set the priority from the corresponding tag', () => { - context.tags[SAMPLING_PRIORITY] = `${USER_KEEP}` + context._tags[SAMPLING_PRIORITY] = `${USER_KEEP}` prioritySampler.sample(span) - expect(context.sampling.priority).to.equal(USER_KEEP) + expect(context._sampling.priority).to.equal(USER_KEEP) }) it('should freeze the sampling priority once set', () => { prioritySampler.sample(span) - context.tags[SAMPLING_PRIORITY] = `${USER_KEEP}` + context._tags[SAMPLING_PRIORITY] = `${USER_KEEP}` prioritySampler.sample(span) - expect(context.sampling.priority).to.equal(AUTO_KEEP) + expect(context._sampling.priority).to.equal(AUTO_KEEP) }) it('should accept a span context', () => { prioritySampler.sample(context) - expect(context.sampling.priority).to.equal(AUTO_KEEP) + expect(context._sampling.priority).to.equal(AUTO_KEEP) }) }) @@ -95,11 +95,11 @@ describe('PrioritySampler', () => { prioritySampler.sample(span) - expect(context.sampling.priority).to.equal(AUTO_REJECT) + expect(context._sampling.priority).to.equal(AUTO_REJECT) }) it('should update service rates', () => { - context.tags[SERVICE_NAME] = 'hello' + context._tags[SERVICE_NAME] = 'hello' prioritySampler.update({ 'service:hello,env:test': AUTO_REJECT @@ -107,7 +107,7 @@ describe('PrioritySampler', () => { prioritySampler.sample(span) - expect(context.sampling.priority).to.equal(AUTO_REJECT) + expect(context._sampling.priority).to.equal(AUTO_REJECT) }) }) }) diff --git a/test/proxy.spec.js b/test/proxy.spec.js index 214c59067ff..52ce7ae1c12 100644 --- a/test/proxy.spec.js +++ b/test/proxy.spec.js @@ -53,7 +53,7 @@ describe('TracerProxy', () => { Proxy = proxyquire('../src/proxy', { './tracer': DatadogTracer, - './noop': NoopTracer, + './noop/tracer': NoopTracer, './instrumenter': Instrumenter, './config': Config, './platform': platform diff --git a/test/setup/core.js b/test/setup/core.js index 9813d2856a0..8045749185f 100644 --- a/test/setup/core.js +++ b/test/setup/core.js @@ -57,11 +57,11 @@ function wrapIt () { return it.call(this, title, function (done) { arguments[0] = withoutScope(agent.wrap(done)) - return fn.apply(this, arguments) + return withoutScope(fn).apply(this, arguments) }) } else { return it.call(this, title, function () { - const result = fn.apply(this, arguments) + const result = withoutScope(fn).apply(this, arguments) if (result && result.then) { return result diff --git a/test/tracer.spec.js b/test/tracer.spec.js index b000be76cc4..bc28eb6d71f 100644 --- a/test/tracer.spec.js +++ b/test/tracer.spec.js @@ -40,7 +40,7 @@ describe('Tracer', () => { it('should use the parent context', done => { tracer.trace('parent', parent => { tracer.trace('child', child => { - expect(child.context()).to.have.property('parentId', parent.context().spanId) + expect(child.context()).to.have.property('_parentId', parent.context()._spanId) done() }) }) @@ -49,7 +49,7 @@ describe('Tracer', () => { it('should support explicitly creating a root span', done => { tracer.trace('parent', parent => { tracer.trace('child', { childOf: null }, child => { - expect(child.context()).to.have.property('parentId', null) + expect(child.context()).to.have.property('_parentId', null) done() }) }) @@ -57,30 +57,30 @@ describe('Tracer', () => { it('should set default tags', done => { tracer.trace('name', current => { - expect(current.context().tags).to.have.property('service.name', 'service') - expect(current.context().tags).to.have.property('resource.name', 'name') - expect(current.context().tags).to.not.have.property('span.type') + expect(current.context()._tags).to.have.property('service.name', 'service') + expect(current.context()._tags).to.have.property('resource.name', 'name') + expect(current.context()._tags).to.not.have.property('span.type') done() }) }) it('should support service option', done => { tracer.trace('name', { service: 'test' }, current => { - expect(current.context().tags).to.have.property('service.name', 'test') + expect(current.context()._tags).to.have.property('service.name', 'test') done() }) }) it('should support resource option', done => { tracer.trace('name', { resource: 'test' }, current => { - expect(current.context().tags).to.have.property('resource.name', 'test') + expect(current.context()._tags).to.have.property('resource.name', 'test') done() }) }) it('should support type option', done => { tracer.trace('name', { type: 'test' }, current => { - expect(current.context().tags).to.have.property('span.type', 'test') + expect(current.context()._tags).to.have.property('span.type', 'test') done() }) }) @@ -91,7 +91,7 @@ describe('Tracer', () => { } tracer.trace('name', { tags }, current => { - expect(current.context().tags).to.have.property('foo', 'bar') + expect(current.context()._tags).to.have.property('foo', 'bar') done() }) }) @@ -103,8 +103,8 @@ describe('Tracer', () => { }) tracer.trace('name', { childOf }, current => { - expect(current.context().traceId).to.equal(childOf.traceId) - expect(current.context().parentId).to.equal(childOf.spanId) + expect(current.context()._traceId).to.equal(childOf._traceId) + expect(current.context()._parentId).to.equal(childOf._spanId) done() }) }) diff --git a/test/writer.spec.js b/test/writer.spec.js index 3789e7cfbf6..4c236a87574 100644 --- a/test/writer.spec.js +++ b/test/writer.spec.js @@ -21,7 +21,7 @@ describe('Writer', () => { } span = { - context: sinon.stub().returns({ trace }) + context: sinon.stub().returns({ _trace: trace }) } response = JSON.stringify({