diff --git a/.eslintrc.json b/.eslintrc.json index 007a8d4713..cd65121668 100644 --- a/.eslintrc.json +++ b/.eslintrc.json @@ -8,6 +8,8 @@ "ignorePatterns": [ "/.nyc_output", "/build", + "node_modules", + "/lib/opentelemetry-bridge/opentelemetry-core-mini", "/test/babel/out.js", "/test/sourcemaps/fixtures/lib", "/test/stacktraces/fixtures/dist", diff --git a/.gitignore b/.gitignore index ef71ae793b..173233cd36 100644 --- a/.gitignore +++ b/.gitignore @@ -11,6 +11,6 @@ /.nyc_output /test_output /build -/node_modules +node_modules /test/benchmarks/.tmp /tmp diff --git a/CHANGELOG.asciidoc b/CHANGELOG.asciidoc index f4582a8685..bb77b8b82c 100644 --- a/CHANGELOG.asciidoc +++ b/CHANGELOG.asciidoc @@ -28,6 +28,24 @@ Notes: [[release-notes-3.x]] === Node.js Agent version 3.x +==== Unreleased + +[float] +===== Breaking changes + +[float] +===== Features + +- Add an experimental <>. Briefly, the OpenTelemetry + Bridge allows one to use the vendor-neutral + https://opentelemetry.io/docs/instrumentation/js/api/[OpenTelemetry Tracing + API] (https://www.npmjs.com/package/@opentelemetry/api[`@opentelemetry/api`]) + to manually instrument your code, and have the Elastic Node.js APM agent + handle those API calls. ({pull}2641[#2641]) + +[float] +===== Bug fixes + [[release-notes-3.33.0]] ==== 3.33.0 2022/05/05 diff --git a/NOTICE.md b/NOTICE.md index 5fd9b54642..11dcc240df 100644 --- a/NOTICE.md +++ b/NOTICE.md @@ -110,6 +110,22 @@ THE SOFTWARE. Parts of "lib/instrumentation/run-context" have been adapted from or influenced by TypeScript code in `@opentelemetry/context-async-hooks`. +- **path:** [lib/opentelemetry-bridge/otelutils.js](lib/opentelemetry-bridge/otelutils.js) +- **author:** OpenTelemetry Authors +- **project url:** https://github.com/open-telemetry/opentelemetry-js +- **original file:** https://github.com/open-telemetry/opentelemetry-js/tree/main/packages/opentelemetry-core/src/common/time.ts +- **license:** Apache License 2.0, https://github.com/open-telemetry/opentelemetry-js/blob/main/packages/opentelemetry-core/LICENSE + +"lib/opentelemetry-bridge/opentelemetry-core-mini/" includes files adapted from +code in `@opentelemetry/core`. + +- **path:** [lib/opentelemetry-bridge/opentelemetry-core-mini/](lib/opentelemetry-bridge/opentelemetry-core-mini/) +- **author:** OpenTelemetry Authors +- **project url:** https://github.com/open-telemetry/opentelemetry-js +- **original file:** https://github.com/open-telemetry/opentelemetry-js/tree/main/packages/opentelemetry-core/src/ +- **license:** Apache License 2.0, https://github.com/open-telemetry/opentelemetry-js/blob/main/packages/opentelemetry-core/LICENSE + + ## load-source-map - **path:** [lib/load-source-map.js](lib/load-source-map.js) diff --git a/README.md b/README.md index ef4db9063b..007cf11e21 100644 --- a/README.md +++ b/README.md @@ -39,12 +39,12 @@ npm install elastic-apm-node --save - [Get started with a custom Node.js stack](https://www.elastic.co/guide/en/apm/agent/nodejs/current/custom-stack.html) - [Advanced Setup and Configuration](https://www.elastic.co/guide/en/apm/agent/nodejs/current/advanced-setup.html) - [API Reference](https://www.elastic.co/guide/en/apm/agent/nodejs/current/api.html) +- [OpenTelemetry Bridge](https://www.elastic.co/guide/en/apm/agent/nodejs/current/opentelemetry-bridge.html) - [Custom Transactions](https://www.elastic.co/guide/en/apm/agent/nodejs/current/custom-transactions.html) - [Custom Spans](https://www.elastic.co/guide/en/apm/agent/nodejs/current/custom-spans.html) - [Metrics](https://www.elastic.co/guide/en/apm/agent/nodejs/current/metrics.html) - [Performance Tuning](https://www.elastic.co/guide/en/apm/agent/nodejs/current/performance-tuning.html) - [Source Map Support](https://www.elastic.co/guide/en/apm/agent/nodejs/current/source-maps.html) -- [OpenTracing Support](https://www.elastic.co/guide/en/apm/agent/nodejs/current/opentracing.html) - [Supported Technologies](https://www.elastic.co/guide/en/apm/agent/nodejs/current/supported-technologies.html) - [Upgrading](https://www.elastic.co/guide/en/apm/agent/nodejs/current/upgrading.html) - [Troubleshooting](https://www.elastic.co/guide/en/apm/agent/nodejs/current/troubleshooting.html) diff --git a/docs/api-opentelemetry.asciidoc b/docs/api-opentelemetry.asciidoc new file mode 100644 index 0000000000..715807e304 --- /dev/null +++ b/docs/api-opentelemetry.asciidoc @@ -0,0 +1,147 @@ +ifdef::env-github[] +NOTE: For the best reading experience, +please view this documentation at https://www.elastic.co/guide/en/apm/agent/nodejs/current/opentelemetry-bridge.html[elastic.co] +endif::[] + +[[opentelemetry-bridge]] +== OpenTelemetry bridge + +NOTE: Added as experimental in v3.34.0. +To enable it, set <> to `true`. + +The Elastic APM OpenTelemetry bridge allows one to use the vendor-neutral +https://opentelemetry.io/docs/instrumentation/js/api/[OpenTelemetry Tracing API] +(https://www.npmjs.com/package/@opentelemetry/api[`@opentelemetry/api`]) to +manually instrument your code, and have the Elastic Node.js APM agent handle +those API calls. This allows one to use the Elastic APM agent for tracing, +without any vendor lock-in from adding manual tracing using the APM agent's own +<>. + + +[float] +[[otel-getting-started]] +=== Getting started + +The goal of the OpenTelemetry bridge is to allow using the OpenTelemetry API +with the APM agent. ① First, you will need to add those dependencies to your +project. The minimum required OpenTelemetry API version is 1.0.0. For example: + +[source,bash] +---- +npm install --save elastic-apm-node @opentelemetry/api +---- + +② Second, you will need to configure and start the APM agent. This can be done +completely with environment variables (so that there is no need to touch +your application code): + +[source,bash] +---- +export ELASTIC_APM_SERVER_URL='' +export ELASTIC_APM_SECRET_TOKEN='' # or ELASTIC_APM_API_KEY=... +export ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true +export NODE_OPTIONS='-r elastic-apm-node/start.js' # Tell node to preload and start the APM agent +node my-app.js +---- + +Or, alternatively, you can configure and start the APM agent at the top of your +application code as follows. (Note: For automatic instrumentations to function +properly, this must be executed before other `require` statements and +application code.) + +[source,js] +---- +require('elastic-apm-node').start({ + serverUrl: '', + secretToken: '', // or, apiKey: '' + opentelemetryBridgeEnabled: true +}); + +// Application code ... +---- + +NOTE: These examples show the minimal configuration. See <> for other configuration options. + +③ Finally, you can use the OpenTelemetry API for any manual tracing in your code. +For example, the following script uses +https://open-telemetry.github.io/opentelemetry-js-api/interfaces/tracer.html#startactivespan[Tracer#startActiveSpan()] +to trace an outgoing HTTPS request: + +[source,js] +---- +const https = require('https') +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('trace-https-request') + +tracer.startActiveSpan('makeRequest', span => { + https.get('https://httpstat.us/200', (response) => { + console.log('STATUS:', response.statusCode) + const body = [] + response.on('data', (chunk) => body.push(chunk)) + response.on('end', () => { + console.log('BODY:', body.toString()) + span.end() + }) + }) +}) +---- + +The APM agent source code repository includes +https://github.com/elastic/apm-agent-nodejs/tree/main/examples/opentelemetry-bridge[some examples using the OpenTelemetry bridge]. + + +[float] +[[otel-architecture]] +=== Bridge architecture + +The OpenTelemetry bridge works similarly to the +https://github.com/open-telemetry/opentelemetry-js[OpenTelemetry JS SDK]. It +registers Tracer and ContextManager providers with the OpenTelemetry API. +Subsequent `@opentelemetry/api` calls in user code will call into those +providers. The APM agent translates from OpenTelemetry to Elastic APM semantics +and sends tracing data to your APM server for full support in +https://www.elastic.co/apm[Elastic Observability's APM app]. + +Here are a couple examples of semantic translations: The first entry span of a +service (e.g. an incoming HTTP request) will be converted to an +{apm-guide-ref}/data-model-transactions.html[Elasic APM `Transaction`], +subsequent spans are mapped to +{apm-guide-ref}/data-model-spans.html[Elastic APM `Span`]. OpenTelemetry Span +attributes are translated into the appropriate fields in Elastic APM's data +model. + +The only difference, from the user's point of view, is in the setup of tracing. +Instead of setting up the OpenTelemetry JS SDK, one sets up the APM agent +as <>. + + +[float] +[[otel-caveats]] +=== Caveats +Not all features of the OpenTelemetry API are supported. + +[float] +[[otel-metrics]] +===== Metrics +This bridge only supports the tracing API. +The Metrics API is currently not supported. + +[float] +[[otel-span-links]] +===== Span Links +Adding links when +https://open-telemetry.github.io/opentelemetry-js-api/interfaces/tracer.html[starting a span] +are not currently supported. Any given links will be silently dropped. + +[float] +[[otel-span-events]] +===== Span Events +Span events (https://open-telemetry.github.io/opentelemetry-js-api/interfaces/span.html#addevent[`Span#addEvent()`]) +is not currently supported. Events will be silently dropped. + +[float] +[[otel-baggage]] +===== Baggage +https://open-telemetry.github.io/opentelemetry-js-api/classes/propagationapi.html[Propagating baggage] +within or outside the process is not supported. Baggage items are silently +dropped. diff --git a/docs/configuration.asciidoc b/docs/configuration.asciidoc index c44cc06fc4..e1369af701 100644 --- a/docs/configuration.asciidoc +++ b/docs/configuration.asciidoc @@ -1235,3 +1235,27 @@ require('elastic-apm-node').start({ }) ---- + +[[opentelemetry-bridge-enabled]] +==== `opentelemetryBridgeEnabled` + +[small]#Added in: v3.34.0 as experimental# + +* *Type:* Boolean +* *Default:* `false` +* *Env:* `ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED` + +Setting this option to true will enable the <>. Briefly, the OpenTelemetry Bridge allows one to use the vendor-neutral +https://opentelemetry.io/docs/instrumentation/js/api/[OpenTelemetry Tracing API] +(https://www.npmjs.com/package/@opentelemetry/api[`@opentelemetry/api`]) to +manually instrument your code, and have the Elastic Node.js APM agent handle +those API calls. + +Example usage: + +[source,js] +---- +require('elastic-apm-node').start({ + opentelemetryBridgeEnabled: true +}) +---- diff --git a/docs/index.asciidoc b/docs/index.asciidoc index cf7f3e362a..a5541fe3a7 100644 --- a/docs/index.asciidoc +++ b/docs/index.asciidoc @@ -31,6 +31,8 @@ include::./api.asciidoc[] include::./metrics.asciidoc[] +include::./api-opentelemetry.asciidoc[] + include::./opentracing.asciidoc[] include::./log-correlation.asciidoc[] diff --git a/docs/opentracing.asciidoc b/docs/opentracing.asciidoc index 062ad9a521..3972b0e9e9 100644 --- a/docs/opentracing.asciidoc +++ b/docs/opentracing.asciidoc @@ -5,7 +5,10 @@ NOTE: For the best reading experience, please view this documentation at https://www.elastic.co/guide/en/apm/agent/nodejs/current/opentracing.html[elastic.co] endif::[] -== OpenTracing API +== OpenTracing bridge + +NOTE: https://opentracing.io/[OpenTracing] is discontinued in favor of OpenTelemetry. This Elastic APM OpenTracing bridge is **deprecated**. Consider using the <> instead. + The Elastic APM OpenTracing bridge allows creating Elastic APM transactions and spans, using the https://opentracing-javascript.surge.sh/[OpenTracing API]. diff --git a/examples/opentelemetry-bridge/.gitignore b/examples/opentelemetry-bridge/.gitignore new file mode 100644 index 0000000000..07e6e472cc --- /dev/null +++ b/examples/opentelemetry-bridge/.gitignore @@ -0,0 +1 @@ +/node_modules diff --git a/examples/opentelemetry-bridge/.npmrc b/examples/opentelemetry-bridge/.npmrc new file mode 100644 index 0000000000..43c97e719a --- /dev/null +++ b/examples/opentelemetry-bridge/.npmrc @@ -0,0 +1 @@ +package-lock=false diff --git a/examples/opentelemetry-bridge/README.md b/examples/opentelemetry-bridge/README.md new file mode 100644 index 0000000000..9e69a4d737 --- /dev/null +++ b/examples/opentelemetry-bridge/README.md @@ -0,0 +1,41 @@ +This directory includes example Node.js scripts showing usage of the +OpenTelemetry JS API. These can be instrumented with the Elastic Node.js APM +agent using its OpenTelemetry Bridge. + +Setup dependencies via: + + npm install + +To run a script using the **Elastic Node.js APM Agent** use: + + export ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true + node -r elastic-apm-node/start.js THE-SCRIPT.js + +For example: + + export ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true + node -r elastic-apm-node/start.js trace-https-request.js + +While these examples are written to use the `node -r elastic-apm-node/start.js ...` +mechanism to start the APM agent. That isn't required. One can still load and +start the APM agent at the top of a script like this: + +```js +require('elastic-apm-node').start({ + opentelemetryBridgeEnabled: true + // serviceName: ... + // serverUrl: ... + // secretToken: ... +}) +``` + +## Compare to using the OpenTelemetry JS SDK + +For comparison, these scripts can be instrumented with the OpenTelemetry JS SDK +with something like the following: + + node -r ./otel-sdk.js trace-https-request.js + +The "otel-sdk.js" is a simplified tracing setup of the OpenTelemetry SDK. For +the sake of simpler demonstration it writes tracing spans to the console rather +than sending to some collection service (like Jaeger or Elastic APM). diff --git a/examples/opentelemetry-bridge/otel-sdk.js b/examples/opentelemetry-bridge/otel-sdk.js new file mode 100644 index 0000000000..657cebdb92 --- /dev/null +++ b/examples/opentelemetry-bridge/otel-sdk.js @@ -0,0 +1,35 @@ +'use strict' + +// Start a simply-configured OpenTelemetry SDK for Node.js tracing for demo +// purposes. +// +// Based on https://github.com/open-telemetry/opentelemetry-js/blob/main/examples/http/tracer.js +// +// Usage: +// node -r ./otel-sdk.js MY-SCRIPT.js + +// Uncomment this to get OpenTelemetry internal diagnostic messages. +// const otel = require('@opentelemetry/api') +// otel.diag.setLogger({ +// verbose () { console.log('diag VERBOSE:', ...arguments) }, +// debug () { console.log('diag DEBUG:', ...arguments) }, +// info () { console.log('diag INFO:', ...arguments) }, +// warn () { console.log('diag WARN:', ...arguments) }, +// error () { console.log('diag ERROR:', ...arguments) } +// }, opentelemetry.DiagLogLevel.ALL) + +const { registerInstrumentations } = require('@opentelemetry/instrumentation') +const { NodeTracerProvider } = require('@opentelemetry/sdk-trace-node') +const { SimpleSpanProcessor, ConsoleSpanExporter } = require('@opentelemetry/sdk-trace-base') +const { HttpInstrumentation } = require('@opentelemetry/instrumentation-http') + +module.exports = (() => { + const provider = new NodeTracerProvider() + provider.addSpanProcessor(new SimpleSpanProcessor(new ConsoleSpanExporter())) + provider.register() + registerInstrumentations({ + instrumentations: [ + new HttpInstrumentation() + ] + }) +})() diff --git a/examples/opentelemetry-bridge/package.json b/examples/opentelemetry-bridge/package.json new file mode 100644 index 0000000000..17e6c398a2 --- /dev/null +++ b/examples/opentelemetry-bridge/package.json @@ -0,0 +1,18 @@ +{ + "name": "elastic-apm-node-opentelemetry-bridge-examples", + "version": "1.0.0", + "private": true, + "scripts": { + "trace-hello-world": "ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true node -r elastic-apm-node/start.js trace-hello-world.js", + "trace-https-request": "ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true node -r elastic-apm-node/start.js trace-https-request.js" + }, + "dependencies": { + "@opentelemetry/api": "^1.1.0", + "@opentelemetry/core": "^1.2.0", + "@opentelemetry/instrumentation": "^0.28.0", + "@opentelemetry/instrumentation-http": "^0.28.0", + "@opentelemetry/sdk-trace-base": "^1.2.0", + "@opentelemetry/sdk-trace-node": "^1.2.0", + "elastic-apm-node": "file:../.." + } +} diff --git a/examples/opentelemetry-bridge/trace-hello-world.js b/examples/opentelemetry-bridge/trace-hello-world.js new file mode 100644 index 0000000000..f6c28a821a --- /dev/null +++ b/examples/opentelemetry-bridge/trace-hello-world.js @@ -0,0 +1,23 @@ +'use strict' + +// A simple OpenTelemetry API-using script. + +const otel = require('@opentelemetry/api') + +const tracer = otel.trace.getTracer('hello-world') + +function main () { + tracer.startActiveSpan('hi', span => { + console.log('hello') + span.end() + }) + tracer.startActiveSpan('bye', span => { + console.log('goodbye') + span.end() + }) +} + +tracer.startActiveSpan('main', span => { + main() + span.end() +}) diff --git a/examples/opentelemetry-bridge/trace-https-request.js b/examples/opentelemetry-bridge/trace-https-request.js new file mode 100644 index 0000000000..0aca00a239 --- /dev/null +++ b/examples/opentelemetry-bridge/trace-https-request.js @@ -0,0 +1,25 @@ +// A demonstration of using the Elastic APM OpenTelemetry bridge to +// trace an HTTP request. +// +// Usage: +// npm install +// export ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true +// node -r elastic-apm-node/start.js trace-https-request.js + +'use strict' + +const https = require('https') +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('trace-https-request') + +tracer.startActiveSpan('makeRequest', span => { + https.get('https://httpstat.us/200', (response) => { + console.log('STATUS:', response.statusCode) + const body = [] + response.on('data', (chunk) => body.push(chunk)) + response.on('end', () => { + console.log('BODY:', body.toString()) + span.end() + }) + }) +}) diff --git a/lib/agent.js b/lib/agent.js index eacaf2706e..a0212591af 100644 --- a/lib/agent.js +++ b/lib/agent.js @@ -257,7 +257,13 @@ Agent.prototype.start = function (opts) { this._transport = this._conf.transport(this._conf, this) - this._instrumentation.start() + let runContextClass + if (this._conf.opentelemetryBridgeEnabled) { + const { setupOTelBridge, OTelBridgeRunContext } = require('./opentelemetry-bridge') + runContextClass = OTelBridgeRunContext + setupOTelBridge(this) + } + this._instrumentation.start(runContextClass) this._metrics.start() this._origStackTraceLimit = Error.stackTraceLimit diff --git a/lib/config.js b/lib/config.js index 3a174065fe..ea8e294a1c 100644 --- a/lib/config.js +++ b/lib/config.js @@ -60,6 +60,7 @@ var DEFAULTS = { maxQueueSize: 1024, metricsInterval: '30s', metricsLimit: 1000, + opentelemetryBridgeEnabled: false, sanitizeFieldNames: ['password', 'passwd', 'pwd', 'secret', '*key', '*token*', '*session*', '*credit*', '*card*', '*auth*', 'set-cookie', 'pw', 'pass', 'connect.sid' @@ -126,6 +127,7 @@ var ENV_TABLE = { maxQueueSize: 'ELASTIC_APM_MAX_QUEUE_SIZE', metricsInterval: 'ELASTIC_APM_METRICS_INTERVAL', metricsLimit: 'ELASTIC_APM_METRICS_LIMIT', + opentelemetryBridgeEnabled: 'ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED', payloadLogFile: 'ELASTIC_APM_PAYLOAD_LOG_FILE', sanitizeFieldNames: 'ELASTIC_SANITIZE_FIELD_NAMES', serverCaCertFile: 'ELASTIC_APM_SERVER_CA_CERT_FILE', @@ -179,6 +181,7 @@ var BOOL_OPTS = [ 'instrument', 'instrumentIncomingHTTPRequests', 'logUncaughtExceptions', + 'opentelemetryBridgeEnabled', 'spanCompressionEnabled', 'usePathAsTransactionName', 'verifyServerCert' diff --git a/lib/instrumentation/generic-span.js b/lib/instrumentation/generic-span.js index 87074db8a0..574830feab 100644 --- a/lib/instrumentation/generic-span.js +++ b/lib/instrumentation/generic-span.js @@ -30,6 +30,8 @@ function GenericSpan (agent, ...args) { this._agent = agent this._labels = null this._ids = null // Populated by sub-types of GenericSpan + this._otelKind = null + this._otelAttributes = null this.timestamp = this._timer.start this.ended = false @@ -180,3 +182,33 @@ GenericSpan.prototype.isCompositeSameKind = function () { GenericSpan.prototype.isComposite = function () { return this._compression.isComposite() } + +// https://github.com/elastic/apm/blob/main/specs/agents/tracing-api-otel.md#span-kind +// @param {String} kind +GenericSpan.prototype._setOTelKind = function (kind) { + this._otelKind = kind +} + +// This returns the internal OTel attributes object so it can be mutated. +GenericSpan.prototype._getOTelAttributes = function () { + if (!this._otelAttributes) { + this._otelAttributes = {} + } + return this._otelAttributes +} + +// Serialize OTel-related fields into the given payload, if any. +GenericSpan.prototype._serializeOTel = function (payload) { + if (this._otelKind) { + payload.otel = { + span_kind: this._otelKind + } + if (this._otelAttributes) { + // Though the spec allows it ("MAY"), we are opting *not* to report OTel + // span attributes as labels for older (<7.16) versions of APM server. + // This is to avoid the added complexity of guarding allowed attribute + // value types to those supported by the APM server intake API. + payload.otel.attributes = this._otelAttributes + } + } +} diff --git a/lib/instrumentation/index.js b/lib/instrumentation/index.js index 5058b9f470..1469386b39 100644 --- a/lib/instrumentation/index.js +++ b/lib/instrumentation/index.js @@ -9,7 +9,6 @@ var { Ids } = require('./ids') var NamedArray = require('./named-array') var Transaction = require('./transaction') const { - RunContext, BasicRunContextManager, AsyncHooksRunContextManager } = require('./run-context') @@ -160,7 +159,14 @@ Instrumentation.prototype.clearPatches = function (modules) { Instrumentation.modules = Object.freeze(MODULES) -Instrumentation.prototype.start = function () { +// Start the instrumentation system. +// +// @param {RunContext} [runContextClass] - A class to use for the core object +// that is used to track run context. It defaults to `RunContext`. If given, +// it must be `RunContext` (the typical case) or a subclass of it. The OTel +// Bridge uses this to provide a subclass that bridges to OpenTelemetry +// `Context` usage. +Instrumentation.prototype.start = function (runContextClass) { if (this._started) return this._started = true @@ -168,9 +174,9 @@ Instrumentation.prototype.start = function () { this._log = this._agent.logger if (this._agent._conf.asyncHooks) { - this._runCtxMgr = new AsyncHooksRunContextManager(this._log) + this._runCtxMgr = new AsyncHooksRunContextManager(this._log, runContextClass) } else { - this._runCtxMgr = new BasicRunContextManager(this._log) + this._runCtxMgr = new BasicRunContextManager(this._log, runContextClass) require('./patch-async')(this) } @@ -294,7 +300,7 @@ Instrumentation.prototype.addEndedTransaction = function (transaction) { if (rc.currTransaction() === transaction) { // Replace the active run context with an empty one. I.e. there is now // no active transaction or span (at least in this async task). - this._runCtxMgr.supersedeRunContext(new RunContext()) + this._runCtxMgr.supersedeRunContext(this._runCtxMgr.root()) this._log.debug({ ctxmgr: this._runCtxMgr.toString() }, 'addEndedTransaction(%s)', transaction.name) } @@ -407,7 +413,7 @@ Instrumentation.prototype._encodeAndSendSpan = function (span) { // current. Instrumentation.prototype.supersedeWithTransRunContext = function (trans) { if (this._started) { - const rc = new RunContext(trans) + const rc = this._runCtxMgr.root().enterTrans(trans) this._runCtxMgr.supersedeRunContext(rc) this._log.debug({ ctxmgr: this._runCtxMgr.toString() }, 'supersedeWithTransRunContext()', trans.id) } @@ -426,12 +432,17 @@ Instrumentation.prototype.supersedeWithSpanRunContext = function (span) { // created in this run context until a subsequent `startTransaction()`. Instrumentation.prototype.supersedeWithEmptyRunContext = function () { if (this._started) { - const rc = new RunContext() - this._runCtxMgr.supersedeRunContext(rc) + this._runCtxMgr.supersedeRunContext(this._runCtxMgr.root()) this._log.debug({ ctxmgr: this._runCtxMgr.toString() }, 'supersedeWithEmptyRunContext()') } } +// Create a new transaction, but do *not* replace the current run context to +// make this the "current" transaction. Compare to `startTransaction`. +Instrumentation.prototype.createTransaction = function (name, ...args) { + return new Transaction(this._agent, name, ...args) +} + Instrumentation.prototype.startTransaction = function (name, ...args) { const trans = new Transaction(this._agent, name, ...args) this.supersedeWithTransRunContext(trans) @@ -540,7 +551,7 @@ Instrumentation.prototype.bindFunctionToEmptyRunContext = function (fn) { if (!this._started) { return fn } - return this._runCtxMgr.bindFn(new RunContext(), fn) + return this._runCtxMgr.bindFn(this._runCtxMgr.root(), fn) } // Bind the given EventEmitter to the current run context. diff --git a/lib/instrumentation/run-context/AsyncHooksRunContextManager.js b/lib/instrumentation/run-context/AsyncHooksRunContextManager.js index 94376188ed..6ddcf66abd 100644 --- a/lib/instrumentation/run-context/AsyncHooksRunContextManager.js +++ b/lib/instrumentation/run-context/AsyncHooksRunContextManager.js @@ -9,8 +9,8 @@ const { BasicRunContextManager } = require('./BasicRunContextManager') // // (Adapted from https://github.com/open-telemetry/opentelemetry-js/blob/main/packages/opentelemetry-context-async-hooks/src/AsyncHooksContextManager.ts) class AsyncHooksRunContextManager extends BasicRunContextManager { - constructor (log) { - super(log) + constructor (log, runContextClass) { + super(log, runContextClass) this._runContextFromAsyncId = new Map() this._asyncHook = asyncHooks.createHook({ init: this._init.bind(this), @@ -22,6 +22,7 @@ class AsyncHooksRunContextManager extends BasicRunContextManager { } enable () { + super.enable() this._asyncHook.enable() return this } diff --git a/lib/instrumentation/run-context/BasicRunContextManager.js b/lib/instrumentation/run-context/BasicRunContextManager.js index 2176efba6b..9e8479c67a 100644 --- a/lib/instrumentation/run-context/BasicRunContextManager.js +++ b/lib/instrumentation/run-context/BasicRunContextManager.js @@ -10,12 +10,22 @@ const { RunContext } = require('./RunContext') // // (Adapted from https://github.com/open-telemetry/opentelemetry-js/blob/main/packages/opentelemetry-context-async-hooks/src/AsyncHooksContextManager.ts) class BasicRunContextManager extends AbstractRunContextManager { - constructor (log) { + constructor (log, runContextClass = RunContext) { super(log) - this._root = new RunContext() // The root context always stays empty. + this._runContextClass = runContextClass + this._root = new this._runContextClass() this._stack = [] // Top of stack is the current run context. } + // Get the root run context. This is always empty (no current trans or span). + // + // This is the equivalent of OTel JS API's `ROOT_CONTEXT` constant. Ours + // is not a top-level constant, because the RunContext class can be + // overriden. + root () { + return this._root + } + // A string representation useful for debug logging. For example, // BasicRunContextManager( // RC(Trans(685ead, manual), [Span(9dd31c, GET httpstat.us, ended)]), diff --git a/lib/instrumentation/run-context/RunContext.js b/lib/instrumentation/run-context/RunContext.js index 6ea5164f4f..cb73bcbb55 100644 --- a/lib/instrumentation/run-context/RunContext.js +++ b/lib/instrumentation/run-context/RunContext.js @@ -6,8 +6,10 @@ // Module instrumentation code interacts with run contexts via a number of // methods on the `Instrumentation` instance at `agent._instrumentation`. // -// User code is not exposed to RunContexts. The Agent API, Transaction API, -// and Span API hide those details. +// User code using the agent's API (the Agent API, Transaction API, and Span API) +// are not exposes to RunContext instances. However users of the OpenTelemetry +// API, provided by the OpenTelemetry Bridge, *are* exposed to OpenTelemetry +// `Context` instances -- which RunContext implements. // // A RunContext holds: // - a current Transaction, which can be null; and @@ -19,6 +21,9 @@ // var s2 = apm.startSpan('s2') // s2.end() // assert(apm.currentSpan === s1, 's1 is now the current span') +// - a mapping of "values". This is an arbitrary key-value mapping, but exists +// primarily to implement OpenTelemetry `interface Context` +// https://github.com/open-telemetry/opentelemetry-js-api/blob/v1.1.0/src/context/types.ts#L17-L41 // // A RunContext is immutable. This means that `runContext.enterSpan(span)` and // other similar methods return a new/separate RunContext instance. This is @@ -26,12 +31,15 @@ // anything for other code bound to the original RunContext (e.g. via // `ins.bindFunction` or `ins.bindEmitter`). // -// RunContext is roughly equivalent to OTel's `Context` interface in concept. -// https://github.com/open-telemetry/opentelemetry-js-api/blob/main/src/context/types.ts +// Warning: Agent code should never using the `RunContext` class directly +// because a subclass can be provided for the `Instrumentation` to use. +// Instead new instances should be built from an existing one, typically the +// active one (`_runCtxMgr.active()`) or the root one (`_runCtxMgr.root()`). class RunContext { - constructor (trans, spans) { + constructor (trans, spans, parentValues) { this._trans = trans || null this._spans = spans || [] + this._values = parentValues ? new Map(parentValues) : new Map() } currTransaction () { @@ -47,12 +55,23 @@ class RunContext { } } + // Return a new RunContext for a newly active/current Transaction. + enterTrans (trans) { + return new this.constructor(trans, null, this._values) + } + // Return a new RunContext with the given span added to the top of the spans // stack. enterSpan (span) { const newSpans = this._spans.slice() newSpans.push(span) - return new RunContext(this._trans, newSpans) + return new this.constructor(this._trans, newSpans, this._values) + } + + // Return a new RunContext with the given transaction (and hence all of its + // spans) removed. + exitTrans () { + return new this.constructor(null, null, this._values) } // Return a new RunContext with the given span removed, or null if there is @@ -70,12 +89,12 @@ class RunContext { if (lastSpan && lastSpan.id === span.id) { // Fast path for common case: `span` is top of stack. newSpans = this._spans.slice(0, this._spans.length - 1) - newRc = new RunContext(this._trans, newSpans) + newRc = new this.constructor(this._trans, newSpans, this._values) } else { const stackIdx = this._spans.findIndex(s => s.id === span.id) if (stackIdx !== -1) { newSpans = this._spans.slice(0, stackIdx).concat(this._spans.slice(stackIdx + 1)) - newRc = new RunContext(this._trans, newSpans) + newRc = new this.constructor(this._trans, newSpans, this._values) } } return newRc @@ -83,22 +102,41 @@ class RunContext { // A string representation useful for debug logging. // For example: - // RC(Trans(abc123, trans name), [Span(def456, span name, ended)) - // ^^^^^^^-- if the span has ended - // ^^^^^^ ^^^^^^-- 6-char prefix of .id - // ^^^^^-- abbreviated Transaction - // ^^-- abbreviated RunContext + // RunContext(Transaction(abc123, 'trans name'), [Span(def456, 'span name', ended)]) + // ^^^^^^^-- if the span has ended + // ^^^^^^ ^^^^^^-- 6-char prefix of .id + // ^^^^^^^^^^^-- Transaction class name + // ^^^^^^^^^^-- the class name, typically "RunContext", but can be overriden toString () { const bits = [] if (this._trans) { - bits.push(`Trans(${this._trans.id.slice(0, 6)}, ${this._trans.name}${this._trans.ended ? ', ended' : ''})`) + bits.push(`${this._trans.constructor.name}(${this._trans.id.slice(0, 6)}, '${this._trans.name}'${this._trans.ended ? ', ended' : ''})`) } if (this._spans.length > 0) { const spanStrs = this._spans.map( - s => `Span(${s.id.slice(0, 6)}, ${s.name}${s.ended ? ', ended' : ''})`) + s => `Span(${s.id.slice(0, 6)}, '${s.name}'${s.ended ? ', ended' : ''})`) bits.push('[' + spanStrs + ']') } - return `RC(${bits.join(', ')})` + return `${this.constructor.name}<${bits.join(', ')}>` + } + + // ---- The following implements the OTel Context interface. + // https://github.com/open-telemetry/opentelemetry-js-api/blob/v1.0.4/src/context/types.ts#L17 + + getValue (key) { + return this._values.get(key) + } + + setValue (key, value) { + const rc = new this.constructor(this._trans, this._spans, this._values) + rc._values.set(key, value) + return rc + } + + deleteValue (key) { + const rc = new this.constructor(this._trans, this._spans, this._values) + rc._values.delete(key) + return rc } } diff --git a/lib/instrumentation/span.js b/lib/instrumentation/span.js index fe5a12c7b7..b0ba3321eb 100644 --- a/lib/instrumentation/span.js +++ b/lib/instrumentation/span.js @@ -254,6 +254,8 @@ Span.prototype._encode = function (cb) { payload.duration = self._compression.duration } + this._serializeOTel(payload) + if (this._stackObj) { this._stackObj.then( value => done(null, value), diff --git a/lib/instrumentation/transaction.js b/lib/instrumentation/transaction.js index 97582809a8..9412b1d073 100644 --- a/lib/instrumentation/transaction.js +++ b/lib/instrumentation/transaction.js @@ -219,6 +219,8 @@ Transaction.prototype.toJSON = function () { payload.sample_rate = sampleRate } + this._serializeOTel(payload) + return payload } diff --git a/lib/opentelemetry-bridge/OTelBridgeNonRecordingSpan.js b/lib/opentelemetry-bridge/OTelBridgeNonRecordingSpan.js new file mode 100644 index 0000000000..ae0cda31fe --- /dev/null +++ b/lib/opentelemetry-bridge/OTelBridgeNonRecordingSpan.js @@ -0,0 +1,138 @@ +'use strict' + +const otel = require('@opentelemetry/api') + +const agent = require('../..') +const { OUTCOME_UNKNOWN } = require('../constants') +const { traceparentStrFromOTelSpanContext } = require('./otelutils') + +// This class is used to handle OTel's concept of a `NonRecordingSpan` -- a +// span that is never sent/exported, but can carry SpanContext (i.e. W3C +// trace-context) that should be propagated. For a use case, see: +// "test/opentelemetry-bridge/fixtures/nonrecordingspan-parent.js" +// +// This masquerades as a Transaction on the agent's internal run-context +// tracking. Therefore it needs to support enough of Transaction's interface +// for that to work. +// +// This also needs to support enough of OTel API's `interface Span` -- mostly +// mimicking the behavior of OTel's internal `NonRecordingSpan`: +// https://github.com/open-telemetry/opentelemetry-js-api/blob/main/src/trace/NonRecordingSpan.ts +class OTelBridgeNonRecordingSpan { + constructor (otelNonRecordingSpan) { + this._spanContext = otelNonRecordingSpan.spanContext() + this.name = '' + this.type = null + this.subtype = null + this.action = null + this.outcome = OUTCOME_UNKNOWN + this.ended = false + this.result = '' + } + + get id () { + return this._spanContext.spanId + } + + get traceparent () { + return traceparentStrFromOTelSpanContext(this._spanContext) + } + + get ids () { + return { + 'trace.id': this._spanContext.traceId, + 'transaction.id': this._spanContext.spanId + } + } + + setType () { + } + + setLabel (_key, _value, _stringify) { + return false + } + + addLabels (_labels, _stringify) { + return false + } + + setOutcome (_outcome) { + } + + startSpan () { + return null + } + + ensureParentId () { + return '' + } + + // ---- private class Transaction API + // Only the parts of that API that are used on instances of this class. + + createSpan () { + return null + } + + // GenericSpan#propagateTraceContextHeaders() + // + // Implementation adapted from OTel's W3CTraceContextPropagator#inject(). + propagateTraceContextHeaders (carrier, setter) { + if (!carrier || !setter) { + return + } + if (!this._spanContext || !otel.isSpanContextValid(this._spanContext)) { + return + } + + const traceparentStr = traceparentStrFromOTelSpanContext(this._spanContext) + setter(carrier, 'traceparent', traceparentStr) + if (agent._conf.useElasticTraceparentHeader) { + setter(carrier, 'elastic-apm-traceparent', traceparentStr) + } + + if (this._spanContext.traceState) { + setter(carrier, 'tracestate', this._spanContext.traceState.serialize()) + } + } + + // ---- OTel interface Span + // Implementation adapted from opentelemetry-js-api/src/trace/NonRecordingSpan.ts + + spanContext () { + return this._spanContext + } + + setAttribute (_key, _value) { + return this + } + + setAttributes (_attributes) { + return this + } + + addEvent (_name, _attributes) { + return this + } + + setStatus (_status) { + return this + } + + updateName (_name) { + return this + } + + end (_endTime) {} + + // isRecording always returns false for NonRecordingSpan. + isRecording () { + return false + } + + recordException (_exception, _time) {} +} + +module.exports = { + OTelBridgeNonRecordingSpan +} diff --git a/lib/opentelemetry-bridge/OTelBridgeRunContext.js b/lib/opentelemetry-bridge/OTelBridgeRunContext.js new file mode 100644 index 0000000000..0bea3e77d2 --- /dev/null +++ b/lib/opentelemetry-bridge/OTelBridgeRunContext.js @@ -0,0 +1,113 @@ +'use strict' + +const otel = require('@opentelemetry/api') + +const oblog = require('./oblog') +const { OTelBridgeNonRecordingSpan } = require('./OTelBridgeNonRecordingSpan') +const { OTelSpan } = require('./OTelSpan') +const { RunContext } = require('../instrumentation/run-context') +const Span = require('../instrumentation/span') + +const OTEL_CONTEXT_KEY = otel.createContextKey('Elastic APM Context Key OTEL CONTEXT') +let SPAN_KEY = null + +// `fetchSpanKey()` is called once during OTel SDK setup to get the `SPAN_KEY` +// that will be used by the OTel JS API during tracing -- when +// `otel.trace.setSpan(context, span)` et al are called. +// +// The fetched SPAN_KEY is used later by OTelBridgeRunContext to intercept +// `Context.{get,set,delete}Value` and translate to the agent's internal +// RunContext semantics for controlling the active/current span. +function fetchSpanKey () { + const capturingContext = { + spanKey: null, + setValue (key, _value) { + this.spanKey = key + } + } + const fakeSpan = {} + otel.trace.setSpan(capturingContext, fakeSpan) + SPAN_KEY = capturingContext.spanKey + if (!SPAN_KEY) { + throw new Error('could not fetch OTel API "SPAN_KEY"') + } +} + +// This is a subclass of RunContext that is used when the agent's OTel SDK +// is enabled. It bridges between the OTel API's `Context` and the agent's +// `RunContext`. +// +// 1. It bridges between `.setValue(SPAN_KEY, ...)`, `.getValue(SPAN_KEY)` +// used by the OTel API and the RunContext methods used to track the current +// transaction and span. +// 2. It can propagate an OTel API `Context` instance (e.g. the internal +// `BaseContext` that is exposed by `otel.ROOT_CONTEXT`) and proxy +// `.getValue(key)` calls to it. See `OTEL_CONTEXT_KEY` below. +class OTelBridgeRunContext extends RunContext { + setOTelContext (otelContext) { + // First, save the `Context` instance in case it holds keys other than SPAN_KEY. + let runContext = this.setValue(OTEL_CONTEXT_KEY, otelContext) + // Second, if the `Context` holds a span, then pass that to our `setValue` + // that knows how to translate that to RunContext semantics. + const span = otel.trace.getSpan(otelContext) + if (span) { + runContext = runContext.setValue(SPAN_KEY, span) + } + return runContext + } + + getValue (key) { + oblog.apicall('OTelBridgeRunContext.getValue(%o)', key) + if (key === SPAN_KEY) { + const curr = this.currSpan() || this.currTransaction() + if (!curr) { + return undefined + } else if (curr instanceof OTelBridgeNonRecordingSpan) { + return curr + } else { + return new OTelSpan(curr) + } + } + const value = super.getValue(key) + if (value !== undefined) { + return value + } else { + // Fallback to possibly-stashed OTel API Context instance. + const otelContext = super.getValue(OTEL_CONTEXT_KEY) + if (otelContext) { + return otelContext.getValue(key) + } + } + } + + setValue (key, value) { + oblog.apicall('OTelBridgeRunContext.setValue(%o, %s)', key, value) + if (key === SPAN_KEY) { + if (value instanceof OTelSpan) { + if (value._span instanceof Span) { + return this.enterSpan(value._span) + } else { + // assert(value._span instanceof Transaction || value._span instanceof OTelBridgeNonRecordingSpan) + return this.enterTrans(value._span) + } + } else if (typeof value.isRecording === 'function' && !value.isRecording()) { + return this.enterTrans(new OTelBridgeNonRecordingSpan(value)) + } + } + return super.setValue(key, value) + } + + deleteValue (key) { + oblog.apicall('OTelBridgeRunContext.deleteValue(%o)', key) + if (key === SPAN_KEY) { + return this.exitTrans() + } + // TODO: Should perhaps proxy deleteValue(key) to the possible underlying OTEL_CONTEXT_KEY entry. + return super.deleteValue(key) + } +} + +module.exports = { + fetchSpanKey, + OTelBridgeRunContext +} diff --git a/lib/opentelemetry-bridge/OTelContextManager.js b/lib/opentelemetry-bridge/OTelContextManager.js new file mode 100644 index 0000000000..fe549bdb3a --- /dev/null +++ b/lib/opentelemetry-bridge/OTelContextManager.js @@ -0,0 +1,68 @@ +'use strict' + +const EventEmitter = require('events') +const oblog = require('./oblog') +const { OTelBridgeRunContext } = require('./OTelBridgeRunContext') + +// Implements interface ContextManager from: +// https://github.com/open-telemetry/opentelemetry-js-api/blob/v1.0.4/src/context/types.ts#L43 +class OTelContextManager { + constructor (agent) { + this._agent = agent + this._ins = agent._instrumentation + } + + active () { + oblog.apicall('OTelContextManager.active()') + return this._ins.currRunContext() + } + + _runContextFromOTelContext (otelContext) { + let runContext + if (otelContext instanceof OTelBridgeRunContext) { + runContext = otelContext + } else { + // `otelContext` is some object implementing OTel's `interface Context` + // (typically a `BaseContext` from @opentelemetry/api). We derive a new + // OTelBridgeRunContext from the root run-context that properly uses + // the Context. + runContext = this._ins._runCtxMgr.root().setOTelContext(otelContext) + } + return runContext + } + + with (otelContext, fn, thisArg, ...args) { + oblog.apicall('OTelContextManager.with(%s<...>, function %s, ...)', otelContext.constructor.name, fn.name || '') + const runContext = this._runContextFromOTelContext(otelContext) + return this._ins._runCtxMgr.with(runContext, fn, thisArg, ...args) + } + + bind (otelContext, target) { + oblog.apicall('OTelContextManager.bind(%s, %s type)', otelContext, typeof target) + if (target instanceof EventEmitter) { + const runContext = this._runContextFromOTelContext(otelContext) + return this._ins._runCtxMgr.bindEE(runContext, target) + } + if (typeof target === 'function') { + const runContext = this._runContextFromOTelContext(otelContext) + return this._ins._runCtxMgr.bindFn(runContext, target) + } + return target + } + + enable () { + oblog.apicall('OTelContextManager.enable()') + this._ins._runCtxMgr.enable() + return this + } + + disable () { + oblog.apicall('OTelContextManager.disable()') + this._ins._runCtxMgr.disable() + return this + } +} + +module.exports = { + OTelContextManager +} diff --git a/lib/opentelemetry-bridge/OTelSpan.js b/lib/opentelemetry-bridge/OTelSpan.js new file mode 100644 index 0000000000..cbb8db7386 --- /dev/null +++ b/lib/opentelemetry-bridge/OTelSpan.js @@ -0,0 +1,321 @@ +'use strict' + +const assert = require('assert') +const URL = require('url').URL + +const otel = require('@opentelemetry/api') + +const GenericSpan = require('../instrumentation/generic-span') +const oblog = require('./oblog') +const { otelSpanContextFromTraceContext, epochMsFromOTelTimeInput } = require('./otelutils') +const { RESULT_SUCCESS, OUTCOME_UNKNOWN, OUTCOME_SUCCESS, RESULT_FAILURE, OUTCOME_FAILURE } = require('../constants') +const Span = require('../instrumentation/span') +const Transaction = require('../instrumentation/transaction') + +// Based on `isHomogeneousAttributeValueArray` from +// packages/opentelemetry-core/src/common/attributes.ts +function isHomogeneousArrayOfStrNumBool (arr) { + const len = arr.length + let elemType = null + for (let i = 0; i < len; i++) { + const elem = arr[i] + if (elem === undefined || elem === null) { + continue + } + if (!elemType) { + elemType = typeof elem + if (!(elemType === 'string' || elemType === 'number' || elemType === 'boolean')) { + return false + } + } else if (typeof elem !== elemType) { // eslint-disable-line valid-typeof + return false + } + } + return true +} + +// Set the given attribute key `k` and `v` according to these OTel rules: +// https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/common/README.md#attribute +function maybeSetOTelAttr (attrs, k, v) { + if (Array.isArray(v)) { + // Is it homogeneous? Nulls and undefineds are allowed. + if (isHomogeneousArrayOfStrNumBool(v)) { + attrs[k] = v.slice() + } + } else { + switch (typeof v) { + case 'number': + case 'boolean': + attrs[k] = v + break + case 'string': + // Truncation (at 1024 bytes) is done in elastic-apm-http-client. + attrs[k] = v + break + } + } +} + +// This wraps a core Transaction or Span in the OTel API's `inteface Span`. +class OTelSpan { + constructor (span) { + assert(span instanceof GenericSpan) + this._span = span + this._spanContext = null + } + + toString () { + return `OTelSpan<${this._span.constructor.name}<${this._span.id}, "${this._span.name}">>` + } + + // ---- OTel interface Span + // https://github.com/open-telemetry/opentelemetry-js-api/blob/v1.0.4/src/trace/span.ts + + spanContext () { + oblog.apicall('%s.spanContext()', this) + if (!this._spanContext) { + this._spanContext = otelSpanContextFromTraceContext(this._span._context) + } + return this._spanContext + } + + setAttribute (key, value) { + if (this._span.ended || !key || typeof key !== 'string') { + return this + } + + const attrs = this._span._getOTelAttributes() + maybeSetOTelAttr(attrs, key, value) + + return this + } + + setAttributes (attributes) { + if (this._span.ended || !attributes || typeof attributes !== 'object') { + return this + } + + const attrs = this._span._getOTelAttributes() + for (const k in attributes) { + if (k.length === 0) continue + maybeSetOTelAttr(attrs, k, attributes[k]) + } + + return this + } + + // Span events are not currently supported. + addEvent (name, attributesOrStartTime, startTime) { + return this + } + + setStatus (otelSpanStatus) { + if (this._span.ended) { + return this + } + switch (otelSpanStatus) { + case otel.SpanStatusCode.ERROR: + this._span.setOutcome(OUTCOME_FAILURE) + break + case otel.SpanStatusCode.OK: + this._span.setOutcome(OUTCOME_SUCCESS) + break + case otel.SpanStatusCode.UNSET: + this._span.setOutcome(OUTCOME_UNKNOWN) + break + } + // Also set transaction.result, similar to the Java APM agent. + if (this._span instanceof Transaction) { + switch (otelSpanStatus) { + case otel.SpanStatusCode.ERROR: + this._span.result = RESULT_FAILURE + break + case otel.SpanStatusCode.OK: + this._span.result = RESULT_SUCCESS + break + } + } + return this + } + + updateName (name) { + if (this._span.ended) { + return this + } + this._span.name = name + return this + } + + end (otelEndTime) { + oblog.apicall('%s.end(endTime=%s)', this, otelEndTime) + const endTime = otelEndTime === undefined + ? undefined + : epochMsFromOTelTimeInput(otelEndTime) + if (this._span instanceof Transaction) { + this._transCompatMapping() + this._span.end(undefined, endTime) + } else { + assert(this._span instanceof Span) + this._spanCompatMapping() + this._span.end(endTime) + } + } + + // https://github.com/elastic/apm/blob/main/specs/agents/tracing-api-otel.md#compatibility-mapping + _transCompatMapping () { + const attrs = this._span._otelAttributes + let type = 'unknown' + if (!attrs) { + this._span.type = type + return + } + + const otelKind = otel.SpanKind[this._span._otelKind] // map from string to int form + const isRpc = attrs['rpc.system'] !== undefined + const isHttp = attrs['http.url'] !== undefined || attrs['http.scheme'] !== undefined + const isMessaging = attrs['messaging.system'] !== undefined + if (otelKind === otel.SpanKind.SERVER && (isRpc || isHttp)) { + type = 'request' + } else if (otelKind === otel.SpanKind.CONSUMER && isMessaging) { + type = 'messaging' + } else { + type = 'unknown' + } + this._span.type = type + } + + // https://github.com/elastic/apm/blob/main/specs/agents/tracing-api-otel.md#compatibility-mapping + _spanCompatMapping () { + const attrs = this._span._otelAttributes + const otelKind = otel.SpanKind[this._span._otelKind] // map from string to int form + if (!attrs) { + if (otelKind === otel.SpanKind.INTERNAL) { + this._span.type = 'app' + this._span.subtype = 'internal' + } else { + this._span.type = 'unknown' + } + return + } + + let type + let subtype + let resource + + const httpPortFromScheme = function (scheme) { + if (scheme === 'http') { + return 80 + } else if (scheme === 'https') { + return 443 + } + return -1 + } + + // Extracts 'host:port' from URL. + const parseNetName = function (url) { + let u + try { + u = new URL(url) // https://developer.mozilla.org/en-US/docs/Web/API/URL + } catch (_err) { + return undefined + } + if (u.port !== '') { + return u.host // host:port already in URL + } else { + var port = httpPortFromScheme(u.protocol.substring(0, u.protocol.length - 1)) + return port > 0 ? u.hostname + ':' + port : u.hostname + } + } + + let netPort = attrs['net.peer.port'] || -1 + const netPeer = attrs['net.peer.name'] || attrs['net.peer.ip'] + let netName = netPeer // netName includes port, if provided + if (netName && netPort > 0) { + netName += ':' + netPort + } + + if (attrs['db.system']) { + type = 'db' + subtype = attrs['db.system'] + resource = netName || subtype + if (attrs['db.name']) { + resource += '/' + resource += attrs['db.name'] + } + } else if (attrs['messaging.system']) { + type = 'messaging' + subtype = attrs['messaging.system'] + if (!netName && attrs['messaging.url']) { + netName = parseNetName(attrs['messaging.url']) + } + resource = netName || subtype + if (attrs['messaging.destination']) { + resource += '/' + attrs['messaging.destination'] + } + } else if (attrs['rpc.system']) { + type = 'external' + subtype = attrs['rpc.system'] + resource = netName || subtype + if (attrs['rpc.service']) { + resource += '/' + attrs['rpc.service'] + } + } else if (attrs['http.url'] || attrs['http.scheme']) { + type = 'external' + subtype = 'http' + const httpHost = attrs['http.host'] || netPeer + if (httpHost) { + if (netPort < 0) { + netPort = httpPortFromScheme(attrs['http.scheme']) + } + resource = netPort < 0 ? httpHost : httpHost + ':' + netPort + } else if (attrs['http.url']) { + resource = parseNetName(attrs['http.url']) + } + } + + if (type === undefined) { + if (otelKind === otel.SpanKind.INTERNAL) { + type = 'app' + subtype = 'internal' + } else { + type = 'unknown' + } + } + + this._span.type = type + if (subtype) { + this._span.subtype = subtype + } + if (resource) { + this._span.setDestinationContext({ + service: { + resource, + // Empty strings per https://github.com/elastic/apm/blob/main/specs/agents/tracing-spans-destination.md#contextdestinationservicenamecontextdestinationservicetype + name: '', + type: '' + } + }) + } + } + + isRecording () { + return !this._span.ended && this._span.sampled + } + + recordException (otelException, otelTime) { + const errOpts = { + parent: this._span, + captureAttributes: false, + skipOutcome: true + } + if (otelTime !== undefined) { + errOpts.timestamp = epochMsFromOTelTimeInput(otelTime) + } + + this._span._agent.captureError(otelException, errOpts) + } +} + +module.exports = { + OTelSpan +} diff --git a/lib/opentelemetry-bridge/OTelTracer.js b/lib/opentelemetry-bridge/OTelTracer.js new file mode 100644 index 0000000000..9653cf5ade --- /dev/null +++ b/lib/opentelemetry-bridge/OTelTracer.js @@ -0,0 +1,147 @@ +'use strict' + +const otel = require('@opentelemetry/api') + +const oblog = require('./oblog') +const { OTelBridgeRunContext } = require('./OTelBridgeRunContext') +const { OTelSpan } = require('./OTelSpan') +const Transaction = require('../instrumentation/transaction') +const { OTelBridgeNonRecordingSpan } = require('./OTelBridgeNonRecordingSpan') +const { + epochMsFromOTelTimeInput, + otelSpanContextFromTraceContext, + traceparentStrFromOTelSpanContext +} = require('./otelutils') +const { OUTCOME_UNKNOWN } = require('../constants') + +// Implements interface Tracer from: +// https://github.com/open-telemetry/opentelemetry-js-api/blob/v1.0.4/src/trace/tracer.ts +class OTelTracer { + constructor (agent) { + this._agent = agent + this._ins = agent._instrumentation + } + + /** + * Starts a new {@link Span}. Start the span without setting it on context. + * + * This method do NOT modify the current Context. + * + * @param name The name of the span + * @param [options] SpanOptions used for span creation + * @param [context] Context to use to extract parent + * @returns Span The newly created span + * @example + * const span = tracer.startSpan('op'); + * span.setAttribute('key', 'value'); + * span.end(); + */ + startSpan (name, otelSpanOptions = {}, otelContext = otel.context.active()) { + oblog.apicall('OTelTracer.startSpan(name=%s, options=%j, context=%s)', name, otelSpanOptions, otelContext) + + // Get the parent info for the new span. + // We want to get a core Transaction or Span as a parent, when possible, + // because that is required to support the span compression feature. + let parentGenericSpan + let parentOTelSpanContext + if (otelSpanOptions.root) { + // Pass through: explicitly want no parent. + } else if (otelContext instanceof OTelBridgeRunContext) { + parentGenericSpan = otelContext.currSpan() || otelContext.currTransaction() + if (parentGenericSpan instanceof OTelBridgeNonRecordingSpan) { + // This isn't a real Transaction we can use. It is a placeholder + // to propagate its SpanContext. Grab just that. + parentOTelSpanContext = parentGenericSpan.spanContext() + parentGenericSpan = null + } + } else { + // `otelContext` is any object that is meant to satisfy `interface + // Context`. This may hold an OTel `SpanContext` that should be + // propagated. + parentOTelSpanContext = otel.trace.getSpanContext(otelContext) + } + + // Create the new Span/Transaction. + let newTransOrSpan = null + if (parentGenericSpan) { + // New child span. + const trans = parentGenericSpan instanceof Transaction ? parentGenericSpan : parentGenericSpan.transaction + const spanOpts = { + childOf: parentGenericSpan + } + if (otelSpanOptions.startTime) { + spanOpts.startTime = epochMsFromOTelTimeInput(otelSpanOptions.startTime) + } + newTransOrSpan = trans.createSpan(name, spanOpts) + + // There might be no span, e.g. if transactionMaxSpans was hit. We have + // to return some OTelSpan, and we also want to propagate the parent's + // trace-context, if any. + if (!newTransOrSpan) { + return otel.trace.wrapSpanContext(otelSpanContextFromTraceContext(parentGenericSpan._context)) + } + } else if (parentOTelSpanContext && otel.isSpanContextValid(parentOTelSpanContext)) { + // New continuing transaction. + // Note: This is *not* using `SpanContext.isRemote`. I am not sure if it + // is relevant unless using something, like @opentelemetry/core's + // `W3CTraceContextPropagator`, that sets `isRemote = true`. Nothing in + // @opentelemetry/api itself sets isRemote. + const transOpts = { + childOf: traceparentStrFromOTelSpanContext(parentOTelSpanContext) + } + if (parentOTelSpanContext.traceState) { + transOpts.tracestate = parentOTelSpanContext.traceState.serialize() + } + if (otelSpanOptions.startTime !== undefined) { + transOpts.startTime = epochMsFromOTelTimeInput(otelSpanOptions.startTime) + } + newTransOrSpan = this._ins.createTransaction(name, transOpts) + } else { + // New root transaction. + const transOpts = otelSpanOptions.startTime === undefined + ? {} + : { startTime: epochMsFromOTelTimeInput(otelSpanOptions.startTime) } + newTransOrSpan = this._ins.createTransaction(name, transOpts) + } + + newTransOrSpan._setOTelKind(otel.SpanKind[otelSpanOptions.kind || otel.SpanKind.INTERNAL]) + + // Explicitly use the higher-priority user outcome API to prevent the agent + // inferring the outcome from any reported errors or HTTP status code. + newTransOrSpan.setOutcome(OUTCOME_UNKNOWN) + + const otelSpan = new OTelSpan(newTransOrSpan) + otelSpan.setAttributes(otelSpanOptions.attributes) + + return otelSpan + } + + // startActiveSpan(name[, options[, context]], fn) + // + // Interface: https://github.com/open-telemetry/opentelemetry-js-api/blob/main/src/trace/tracer.ts#L41 + // Adapted from: https://github.com/open-telemetry/opentelemetry-js/blob/main/packages/opentelemetry-sdk-trace-base/src/Tracer.ts + startActiveSpan (name, otelSpanOptions, otelContext, fn) { + oblog.apicall('OTelTracer.startActiveSpan(name=%s, options=%j, context=%s, fn)', name, otelSpanOptions, otelContext) + + if (arguments.length < 2) { + return + } else if (arguments.length === 2) { + fn = otelSpanOptions + otelSpanOptions = undefined + otelContext = undefined + } else if (arguments.length === 3) { + fn = otelContext + otelContext = undefined + } + + const parentContext = otelContext || otel.context.active() + const span = this.startSpan(name, otelSpanOptions, parentContext) + const contextWithSpanSet = otel.trace.setSpan(parentContext, span) + + return otel.context.with(contextWithSpanSet, fn, undefined, span) + } +} + +module.exports = { + OTelTracer +} diff --git a/lib/opentelemetry-bridge/OTelTracerProvider.js b/lib/opentelemetry-bridge/OTelTracerProvider.js new file mode 100644 index 0000000000..b16518c492 --- /dev/null +++ b/lib/opentelemetry-bridge/OTelTracerProvider.js @@ -0,0 +1,19 @@ +'use strict' + +const oblog = require('./oblog') + +class OTelTracerProvider { + // @param {OTelTracer} tracer + constructor (tracer) { + this._tracer = tracer + } + + getTracer (_name, _version, _options) { + oblog.apicall('OTelTracerProvider.getTracer(...)') + return this._tracer + } +} + +module.exports = { + OTelTracerProvider +} diff --git a/lib/opentelemetry-bridge/README.md b/lib/opentelemetry-bridge/README.md new file mode 100644 index 0000000000..ec6f73c49c --- /dev/null +++ b/lib/opentelemetry-bridge/README.md @@ -0,0 +1,247 @@ +# OpenTelemetry Bridge + +This document includes design / developer / maintenance notes for the +Node.js APM Agent *OpenTelemetry Bridge*. + +Spec: https://github.com/elastic/apm/blob/main/specs/agents/tracing-api-otel.md + +## Maintenance + +- We should release a new agent version with an updated "@opentelemetry/api" + dependency relatively soon after any new *minor* release. Otherwise a user + upgrading their "@opentelemetry/api" dep to "1.x+1", e.g. "1.2.0", will find + that the OTel Bridge which uses version "1.x", e.g. "1.1.0" or lower, does + not work. + + The reason is that the OTel Bridge registers global providers (e.g. + `otel.trace.setGlobalTracerProvider`) with its version of the OTel API. When + user code attempts to *get* a tracer with **its version** of the OTel API, the + [OTel API compatibility logic](https://github.com/open-telemetry/opentelemetry-js-api/blob/v1.1.0/src/internal/semver.ts#L24-L33) + decides that using a v1.1.x Tracer with a v1.2.0 Tracer API is not compatible + and falls back to a noop implementation. + + +## Development / Debugging + +When doing development on, or debugging the OTel Bridge, it might be helpful to +enable logging of (almost) every `@opentelemetry/api` call into the bridge. +This is done by setting this in `lib/opentelemetry-bridge/setup.js`. + + const LOG_OTEL_API_CALLS = true + +It looks like this: + +``` +% cd test/opentelemetry-bridge/fixtures +% ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true node -r ../../../start.js start-span.js +otelapi: OTelTracerProvider.getTracer(...) +otelapi: OTelContextManager.active() +otelapi: OTelTracer.startSpan(name=mySpan, options={}, context=OTelBridgeRunContext<>) +otelapi: OTelContextManager.active() +otelapi: OTelBridgeRunContext.getValue(Symbol(OpenTelemetry Context Key SPAN)) +otelapi: OTelSpan>.end(endTime=undefined) +``` + +Together with the agent's usual debug logging, this can help show how the bridge +is working. + +``` +% ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true \ + ELASTIC_APM_LOG_LEVEL=debug \ + node -r ../../../start.js start-span.js | ecslog +... +``` + + +## Naming + +In general, the following variable/class/file naming is used: + +- A class that implements an OTel interface is prefixed with "OTel". For + example `class OTelSpan` implements OTel `interface Span`. +- A class that bridges between an OTel interface and an object in the APM + agent is prefixed with `OTelBridge`. For example `OTelBridgeRunContext` + bridges between an OTel `interface Context` and the APM agent's `RunContext`, + i.e. it implements both interfaces/APIs. +- A variable that holds an OpenTelemetry object is prefixed with `otel`, or + `...OTel...` if it in the middle of the var name. Some examples: + - `otelSpanOptions` holds an OTel `SpanOptions` instance + - `parentOTelSpanContext` + - `epochMsFromOTelTimeInput()` converts from an OTel `TimeInput` to a number + of milliseconds since the Unix epoch + + +## Design Overview + +The OpenTelemetry API is, currently, [these four interfaces](https://github.com/open-telemetry/opentelemetry-js-api/tree/main/src/api/): + +- `otel.context.*` - API for managing Context, i.e. what the APM agent calls + "run context". More below. +- `otel.trace.*` - API for manipulating spans, and getting a `Tracer` to + create spans. More below. +- `otel.diag.*` - This is used to hook into internal OpenTelemetry diagnostics, + i.e. internal logging. There is very little `otel.diag` usage in + `@opentelemetry/api`, more in the SDK. The APM agent hooks up `otel.diag` + logging to its own logger **if `logLevel=trace`**. +- `otel.propagation.*` - Used for abstracting trace-context propagation + (reading/writing "traceparent" et al headers) and Baggage handling. This + isn't touched by the OTel Bridge, and shouldn't be necessary until either + the bridge supports Baggage or TextMapPropagator implementations like + `W3CTraceContextPropagator`. The APM agent implements its own internally. + +In `Agent#start()`, if the `opentelemetryBridgeEnabled` config is true, then +a global [`ContextManager`](./OTelContextManager.js) and a global [`TracerProvider`](./OTelTracerProvider.js) are registered, which "enables" the bridge. + +From the OTel Bridge spec: + +> In order to avoid potentially complex and tedious synchronization issues +> between OTel and our existing agent implementations, the bridge implementation +> SHOULD provide an abstraction to have a single "active context" storage. + +For this bridge, the agent's `RunContext` class was extended to support the +small [`interface Context`](https://github.com/open-telemetry/opentelemetry-js-api/blob/v1.1.0/src/context/types.ts#L17-L41) +API and the agent's run context managers were updated to allow passing in a +subclass of `RunContext` to use. So the "single active context storage" is +instances of [`OTelBridgeRunContext`](./OTelBridgeRunContext.js) in the agent's +usual run context managers. + +The way the "active span" is tracked by the OTel API is to call +`context.setValue(SPAN_KEY, span)`. The `OTelBridgeRunContext` class translates +calls using `SPAN_KEY` into the API that the agent's RunContext class uses. +Roughly this: + +- `context.setValue(SPAN_KEY, span)` -> `this.enterSpan(span)` +- `context.getValue(SPAN_KEY)` -> `return new OTelSpan(this.currSpan())` + +Otherwise the `*RunContextManager` classes in the agent map very well to the +OpenTelemetry `ContextManager` interface: the [`OTelContextManager`](./OTelContextManager.js) +implementation is very straightforward. + +The `@opentelemetry/api` supports two ways to create objects that are internally +implemented and do not call the registered global providers. + +1. `otel.trace.wrapSpanContext(...)` supports creating a `NonRecordingSpan` (a + class that isn't exported) instance that implements `interface Span`. [This + test fixture](../../test/opentelemetry-bridge/fixtures/nonrecordingspan-parent.js) + shows a use case. The bridge wraps this in an `OTelBridgeNonRecordingSpan` + that implements both OTel `interface Span` and the agent's Transaction API. +2. `otel.ROOT_CONTEXT` is a singleton object (an internal `BaseContext` class + instance) that implements `interface Context` but is not created via any + bridge API. That means bridge code cannot rely on a given `context` argument + being an instance of its `OTelBridgeRunContext` class. + [This test fixtures](../../test/opentelemetry-bridge/fixtures/using-root-context.js) + shows an example. + +The trickiest part of the bridge is handling these two cases, especially at +the top of `startSpan` in [`OTelTracer`](./OTelTracer.js) + + +## Limitations / Differences with OpenTelemetry SDK + +- The OpenTelemetry SDK defines [SpanLimits](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/sdk.md#span-limits). + This OpenTelemetry Bridge differs as follows: + - Attribute count is not limited. The OTel SDK defaults to a limit of 128. + (To implement this, start at `maybeSetOTelAttr` in "OTelSpan.js".) + - Attribute value strings are truncated at 1024 bytes. The OpenTelemetry SDK + uses `AttributeValueLengthLimit (Default=Infinity)`. + (We could consider using the configurable `longFieldMaxLength` for the + attribute value truncation limit, if there is a need.) + - Span links and events are not current supported by this bridge. + +- The OpenTelemetry Bridge spec says APM agents + ["MAY"](https://github.com/elastic/apm/blob/main/specs/agents/tracing-api-otel.md#attributes-mapping) + report OTel span attributes as spad and transaction *labels* if the upstream + APM Server is less than version 7.16. This implementation opts *not* to do + that. The OTel spec allows a larger range of types for span attributes values + than is allowed for "tags" (aka labels) in the APM Server intake API, so some + further filtering of attributes would be required. + +- There is a known issue with the `asyncHooks: false` config option and + `tracer.startActiveSpan(name, async function fn () { ... })` where run + context is lost after the first `await ...` usage in that given `fn`. + See https://github.com/elastic/apm-agent-nodejs/issues/2679. + +- There is a semantic difference between this OTel Bridge and the OpenTelemetry + SDK with `span.end()` that could impact parent/child relationships of spans. + This demonstrates the different: + + ```js + const otel = require('@opentelemetry/api') + const tracer = otel.trace.getTracer() + tracer.startActiveSpan('s1', s1 => { + tracer.startActiveSpan('s2', s2 => { + s2.end() + }) + s1.end() + tracer.startActiveSpan('s3', s3 => { + s3.end() + }) + }) + ``` + + With the OTel SDK that will yield: + + ``` + span s1 + `- span s2 + `- span s3 + ``` + + With the Elastic APM agent: + + ``` + transaction s1 + `- span s2 + transaction s3 + ``` + + In current Elastic APM semantics, when a span is ended (e.g. `s1` above) it is + *no longer the current/active span in that async context*. This is historical + and allows a stack of current spans in sync code, e.g.: + + ```js + const t1 = apm.startTransaction('t1') + const s2 = apm.startSpan('s2') + const s3 = apm.startSpan('s3') // s3 is a child of s2 + s3.end() // s3 is no longer active (popped off the stack) + const s4 = apm.startSpan('s4') // s4 is a child of s2 + s4.end() + s2.end() + t1.end() + ``` + + This semantic difference is not expected to be common, because it is expected + that typically OTel API user code will end a span only at the end of its + function: + + ```js + tracer.startActiveSpan('mySpan', mySpan => { + // ... + mySpan.end() // .end() only at end of function block + }) + ``` + + Note that active span context *is* properly maintained when a new async task + is created (e.g. with `setTimeout`, etc.), so the following code produces + the expected trace: + + ```js + tracer.startActiveSpan('s1', s1 => { + setImmediate(() => { + tracer.startActiveSpan('s2', s2 => { + s2.end() + }) + setTimeout(() => { // s1 is bound as the active span in this async task. + tracer.startActiveSpan('s3', s3 => { + s3.end() + }) + }, 100) + s1.end() + }) + ``` + + If this *does* turn out to be a common issue, the OTel semantics for span.end() + can likely be accommodated. + + + diff --git a/lib/opentelemetry-bridge/index.js b/lib/opentelemetry-bridge/index.js new file mode 100644 index 0000000000..5812854889 --- /dev/null +++ b/lib/opentelemetry-bridge/index.js @@ -0,0 +1,9 @@ +'use strict' + +const { OTelBridgeRunContext } = require('./OTelBridgeRunContext') +const { setupOTelBridge } = require('./setup') + +module.exports = { + OTelBridgeRunContext, + setupOTelBridge +} diff --git a/lib/opentelemetry-bridge/oblog.js b/lib/opentelemetry-bridge/oblog.js new file mode 100644 index 0000000000..7849970175 --- /dev/null +++ b/lib/opentelemetry-bridge/oblog.js @@ -0,0 +1,17 @@ +'use strict' + +// This is the (O)penTelemetry (B)ridge (LOG) facility. +// +// It is used for development/debugging of the OTel Bridge to emit a log line +// for (almost) every OTel API call. OTel Bridge implementations typically +// call `oblog.apicall(...)`. During development/debugging there is a block in +// "setup.js" that is enabled to turn this logging on. This should always be +// disabled for any release code. + +module.exports = { + setApiCallLogFn (logFn) { + module.exports.apicall = logFn + }, + + apicall () {} +} diff --git a/lib/opentelemetry-bridge/opentelemetry-core-mini/README.md b/lib/opentelemetry-bridge/opentelemetry-core-mini/README.md new file mode 100644 index 0000000000..4c54e9e7b7 --- /dev/null +++ b/lib/opentelemetry-bridge/opentelemetry-core-mini/README.md @@ -0,0 +1,3 @@ +This holds a very small subset of the `@opentelemetry/core` package, instead of +having a dependency on it. "Very small" here is just the `TraceState` class, as +opposed to a ~2.6M dependency. diff --git a/lib/opentelemetry-bridge/opentelemetry-core-mini/internal/validators.js b/lib/opentelemetry-bridge/opentelemetry-core-mini/internal/validators.js new file mode 100644 index 0000000000..0a7d534c85 --- /dev/null +++ b/lib/opentelemetry-bridge/opentelemetry-core-mini/internal/validators.js @@ -0,0 +1,47 @@ +/* + * Adapted from @opentelemetry/core. + */ +"use strict"; +/* + * Copyright The OpenTelemetry Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +const VALID_KEY_CHAR_RANGE = '[_0-9a-z-*/]'; +const VALID_KEY = `[a-z]${VALID_KEY_CHAR_RANGE}{0,255}`; +const VALID_VENDOR_KEY = `[a-z0-9]${VALID_KEY_CHAR_RANGE}{0,240}@[a-z]${VALID_KEY_CHAR_RANGE}{0,13}`; +const VALID_KEY_REGEX = new RegExp(`^(?:${VALID_KEY}|${VALID_VENDOR_KEY})$`); +const VALID_VALUE_BASE_REGEX = /^[ -~]{0,255}[!-~]$/; +const INVALID_VALUE_COMMA_EQUAL_REGEX = /,|=/; +/** + * Key is opaque string up to 256 characters printable. It MUST begin with a + * lowercase letter, and can only contain lowercase letters a-z, digits 0-9, + * underscores _, dashes -, asterisks *, and forward slashes /. + * For multi-tenant vendor scenarios, an at sign (@) can be used to prefix the + * vendor name. Vendors SHOULD set the tenant ID at the beginning of the key. + * see https://www.w3.org/TR/trace-context/#key + */ +function validateKey(key) { + return VALID_KEY_REGEX.test(key); +} +exports.validateKey = validateKey; +/** + * Value is opaque string up to 256 characters printable ASCII RFC0020 + * characters (i.e., the range 0x20 to 0x7E) except comma , and =. + */ +function validateValue(value) { + return (VALID_VALUE_BASE_REGEX.test(value) && + !INVALID_VALUE_COMMA_EQUAL_REGEX.test(value)); +} +exports.validateValue = validateValue; +//# sourceMappingURL=validators.js.map diff --git a/lib/opentelemetry-bridge/opentelemetry-core-mini/trace/TraceState.js b/lib/opentelemetry-bridge/opentelemetry-core-mini/trace/TraceState.js new file mode 100644 index 0000000000..7b00daa0e6 --- /dev/null +++ b/lib/opentelemetry-bridge/opentelemetry-core-mini/trace/TraceState.js @@ -0,0 +1,104 @@ +/* + * Adapted from @opentelemetry/core. + */ +"use strict"; +/* + * Copyright The OpenTelemetry Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +const validators_1 = require("../internal/validators"); +const MAX_TRACE_STATE_ITEMS = 32; +const MAX_TRACE_STATE_LEN = 512; +const LIST_MEMBERS_SEPARATOR = ','; +const LIST_MEMBER_KEY_VALUE_SPLITTER = '='; +/** + * TraceState must be a class and not a simple object type because of the spec + * requirement (https://www.w3.org/TR/trace-context/#tracestate-field). + * + * Here is the list of allowed mutations: + * - New key-value pair should be added into the beginning of the list + * - The value of any key can be updated. Modified keys MUST be moved to the + * beginning of the list. + */ +class TraceState { + constructor(rawTraceState) { + this._internalState = new Map(); + if (rawTraceState) + this._parse(rawTraceState); + } + set(key, value) { + // TODO: Benchmark the different approaches(map vs list) and + // use the faster one. + const traceState = this._clone(); + if (traceState._internalState.has(key)) { + traceState._internalState.delete(key); + } + traceState._internalState.set(key, value); + return traceState; + } + unset(key) { + const traceState = this._clone(); + traceState._internalState.delete(key); + return traceState; + } + get(key) { + return this._internalState.get(key); + } + serialize() { + return this._keys() + .reduce((agg, key) => { + agg.push(key + LIST_MEMBER_KEY_VALUE_SPLITTER + this.get(key)); + return agg; + }, []) + .join(LIST_MEMBERS_SEPARATOR); + } + _parse(rawTraceState) { + if (rawTraceState.length > MAX_TRACE_STATE_LEN) + return; + this._internalState = rawTraceState + .split(LIST_MEMBERS_SEPARATOR) + .reverse() // Store in reverse so new keys (.set(...)) will be placed at the beginning + .reduce((agg, part) => { + const listMember = part.trim(); // Optional Whitespace (OWS) handling + const i = listMember.indexOf(LIST_MEMBER_KEY_VALUE_SPLITTER); + if (i !== -1) { + const key = listMember.slice(0, i); + const value = listMember.slice(i + 1, part.length); + if ((0, validators_1.validateKey)(key) && (0, validators_1.validateValue)(value)) { + agg.set(key, value); + } + else { + // TODO: Consider to add warning log + } + } + return agg; + }, new Map()); + // Because of the reverse() requirement, trunc must be done after map is created + if (this._internalState.size > MAX_TRACE_STATE_ITEMS) { + this._internalState = new Map(Array.from(this._internalState.entries()) + .reverse() // Use reverse same as original tracestate parse chain + .slice(0, MAX_TRACE_STATE_ITEMS)); + } + } + _keys() { + return Array.from(this._internalState.keys()).reverse(); + } + _clone() { + const traceState = new TraceState(); + traceState._internalState = new Map(this._internalState); + return traceState; + } +} +exports.TraceState = TraceState; +//# sourceMappingURL=TraceState.js.map diff --git a/lib/opentelemetry-bridge/otelutils.js b/lib/opentelemetry-bridge/otelutils.js new file mode 100644 index 0000000000..3724b5357f --- /dev/null +++ b/lib/opentelemetry-bridge/otelutils.js @@ -0,0 +1,93 @@ +'use strict' + +const otel = require('@opentelemetry/api') +const semver = require('semver') +const timeOrigin = require('perf_hooks').performance.timeOrigin + +// Note: This is *OTel's* TraceState class, which differs from our TraceState +// class in "lib/tracecontext/...". +const { TraceState } = require('./opentelemetry-core-mini/trace/TraceState') + +const haveUsablePerformanceNow = semver.satisfies(process.version, '>=8.12.0') + +function isTimeInputHrTime (value) { + return ( + Array.isArray(value) && + value.length === 2 && + typeof value[0] === 'number' && + typeof value[1] === 'number' + ) +} + +// Convert an OTel `TimeInput` to a number of milliseconds since the Unix epoch. +// +// The latter is the time format used for `SpanOptions.startTime` and the +// `endTime` arg to `Span.end()` and `Transaction.end()`. +// +// `TimeInput` is defined as: +// // hrtime, epoch milliseconds, performance.now() or Date +// export type TimeInput = HrTime | number | Date; +// +// This implementation is adapted from of TimeInput parsing in +// "@opentelemetry/core/src/common/time.ts". Some notes: +// - @opentelemetry/core base supported node is 8.12.0. The APM agent's is +// currently 8.6.0. Before 8.12.0, node's `performance.now()` did *not* +// return a value relative to `performance.timeOrigin()`. Therefore it was +// not useful to specify an absolute time value. +// - Allowing both epoch milliseconds and performance.now() in the same arg +// is inherently ambiguous. To disambiguate, the following code relies on an +// *assumption* (the same made by @opentelemetry/core) that one never wants to +// provide a TimeInput value that is before the process started. Woe be the +// code that attempts to set a retroactive span startTime for, say, an +// incoming message from an out of process queue. +function epochMsFromOTelTimeInput (otelTimeInput) { + if (isTimeInputHrTime(otelTimeInput)) { + // OTel's HrTime is `[, ]` + return otelTimeInput[0] * 1e3 + otelTimeInput[1] / 1e6 + } else if (typeof otelTimeInput === 'number') { + // Assume a performance.now() if it's smaller than process start time. + if (haveUsablePerformanceNow && otelTimeInput < timeOrigin) { + return timeOrigin + otelTimeInput + } else { + return otelTimeInput + } + } else if (otelTimeInput instanceof Date) { + return otelTimeInput.getTime() + } else { + throw TypeError(`Invalid OTel TimeInput: ${otelTimeInput}`) + } +} + +// Convert an OTel SpanContext to a traceparent string. +// +// Adapted from W3CTraceContextPropagator in @opentelemetry/core. +// https://github.com/open-telemetry/opentelemetry-js/blob/83355af4999c2d1ca660ce2499017d19642742bc/packages/opentelemetry-core/src/trace/W3CTraceContextPropagator.ts#L83-L85 +function traceparentStrFromOTelSpanContext (spanContext) { + return `00-${spanContext.traceId}-${ + spanContext.spanId + }-0${Number(spanContext.traceFlags || otel.TraceFlags.NONE).toString(16)}` +} + +// Convert an Elastic TraceContext instance to an OTel SpanContext. +// These are the Elastic and OTel classes for storing W3C trace-context data. +function otelSpanContextFromTraceContext (traceContext) { + const traceparent = traceContext.traceparent + const otelSpanContext = { + traceId: traceparent.traceId, + spanId: traceparent.id, + // `traceparent.flags` is a two-char hex string. `traceFlags` is a number. + // This conversion assumes `traceparent.flags` are valid. + traceFlags: parseInt(traceparent.flags, 16) + } + const traceStateStr = traceContext.toTraceStateString() + if (traceStateStr) { + otelSpanContext.traceState = new TraceState(traceStateStr) + } + return otelSpanContext +} + +module.exports = { + epochMsFromOTelTimeInput, + otelSpanContextFromTraceContext, + traceparentStrFromOTelSpanContext +} diff --git a/lib/opentelemetry-bridge/setup.js b/lib/opentelemetry-bridge/setup.js new file mode 100644 index 0000000000..360ce33c2f --- /dev/null +++ b/lib/opentelemetry-bridge/setup.js @@ -0,0 +1,65 @@ +'use strict' + +const util = require('util') +const otel = require('@opentelemetry/api') + +const logging = require('../logging') +const { fetchSpanKey } = require('./OTelBridgeRunContext') +const oblog = require('./oblog') +const { OTelContextManager } = require('./OTelContextManager') +const { OTelTracerProvider } = require('./OTelTracerProvider') +const { OTelTracer } = require('./OTelTracer') + +function setupOTelBridge (agent) { + let success + + const log = (logging.isLoggerCustom(agent.logger) + ? agent.logger + : agent.logger.child({ 'event.module': 'otelbridge' })) + + // `otel.diag` is "the OpenTelemetry internal diagnostic API". If *trace* + // level logging is enabled, then hook into diag. + if (log.isLevelEnabled('trace')) { + success = otel.diag.setLogger({ + verbose: log.trace.bind(log), + debug: log.debug.bind(log), + info: log.info.bind(log), + warn: log.warn.bind(log), + error: log.error.bind(log) + }, otel.DiagLogLevel.ALL) + if (!success) { + log.error('could not register OpenTelemetry bridge diag logger') + return + } + } + + // For development/debugging-only, set `LOG_OTEL_API_CALLS = true` to get log + // (almost) every call into the OpenTelemetry API. See docs in "oblog.js". + const LOG_OTEL_API_CALLS = false + if (LOG_OTEL_API_CALLS) { + // oblog.setApiCallLogFn(log.debug.bind(log)) // Alternative, to use our ecs logger. + oblog.setApiCallLogFn((...args) => { + const s = util.format(...args) + console.log('\x1b[90motelapi:\x1b[39m \x1b[32m' + s + '\x1b[39m') + }) + } + + success = otel.trace.setGlobalTracerProvider(new OTelTracerProvider(new OTelTracer(agent))) + if (!success) { + log.error('could not register OpenTelemetry bridge TracerProvider') + return + } + + // The OTelBridgeRunContext class needs to get the SPAN_KEY before it can + // be used. + fetchSpanKey() + + success = otel.context.setGlobalContextManager(new OTelContextManager(agent)) + if (!success) { + log.error('could not register OpenTelemetry bridge ContextManager') + } +} + +module.exports = { + setupOTelBridge +} diff --git a/package.json b/package.json index 8ac8491c94..38916eb62b 100644 --- a/package.json +++ b/package.json @@ -80,6 +80,7 @@ "homepage": "https://github.com/elastic/apm-agent-nodejs", "dependencies": { "@elastic/ecs-pino-format": "^1.2.0", + "@opentelemetry/api": "^1.1.0", "after-all-results": "^2.0.0", "async-cache": "^1.1.0", "async-value-promise": "^1.1.1", diff --git a/test/opentelemetry-bridge/OTelBridgeNonRecordingSpan.test.js b/test/opentelemetry-bridge/OTelBridgeNonRecordingSpan.test.js new file mode 100644 index 0000000000..c910957ba7 --- /dev/null +++ b/test/opentelemetry-bridge/OTelBridgeNonRecordingSpan.test.js @@ -0,0 +1,94 @@ +'use strict' + +const apm = require('../..').start({ + opentelemetryBridgeEnabled: true, + // Make the agent quiet. + disableSend: true, + centralConfig: false, + cloudProvider: 'none', + metricsInterval: '0s', + captureExceptions: false, + logLevel: 'off' +}) + +const otel = require('@opentelemetry/api') +const tape = require('tape') +const { OUTCOME_UNKNOWN } = require('../../lib/constants') +const { OTelBridgeNonRecordingSpan } = require('../../lib/opentelemetry-bridge/OTelBridgeNonRecordingSpan') + +tape.test('OTelBridgeNonRecordingSpan', suite => { + const parentSpanContext = { + traceId: 'd4cda95b652f4a1592b449dd92ffda3b', + spanId: '6e0c63ffe4e34c42', + traceFlags: otel.TraceFlags.SAMPLED + } + let nrsOTelSpan + let nrsTrans + + suite.test('setup', t => { + // `nrs` is an instance of the @opentelemetry/api NonRecordingSpan. + const nrs = otel.trace.wrapSpanContext(parentSpanContext) + + // If we set that span on a Context and use the ContextManager to run in that + // context (via `otel.context.with()`) ... + otel.context.with(otel.trace.setSpan(otel.context.active(), nrs), () => { + // ... then that span passes through the OTel Bridge context management + // and comes out as an `OTelBridgeNonRecordingSpan` instance. + nrsOTelSpan = otel.trace.getSpan(otel.context.active()) + t.ok(nrsOTelSpan instanceof OTelBridgeNonRecordingSpan) + + // In Elastic APM terms, that "span" is the current transaction. + nrsTrans = apm.currentTransaction + t.ok(nrsTrans instanceof OTelBridgeNonRecordingSpan) + t.strictEqual(nrsOTelSpan, nrsTrans) + + t.end() + + // This object must handle: + // - the full OTel `interface Span` + // - the full Elastic APM public API `interface Transaction`, and + // - any internal `class Transaction` API used by the APM agent. + }) + }) + + suite.test('OTel interface Span', t => { + t.deepEqual(nrsOTelSpan.spanContext(), parentSpanContext, 'spanContext') + t.equal(nrsOTelSpan.setAttribute('foo', 'bar'), nrsOTelSpan, 'setAttribute') + t.equal(nrsOTelSpan.setAttributes({ foo: 'bar' }), nrsOTelSpan, 'setAttributes') + t.equal(nrsOTelSpan.addEvent('anEvent'), nrsOTelSpan, 'addEvent') + t.equal(nrsOTelSpan.setStatus(otel.SpanStatusCode.OK), nrsOTelSpan, 'setStatus') + t.equal(nrsOTelSpan.updateName('anotherName'), nrsOTelSpan, 'updateName') + t.equal(nrsOTelSpan.end(), undefined, 'end') + t.equal(nrsOTelSpan.isRecording(), false, 'isRecording') + t.equal(nrsOTelSpan.recordException(new Error('boom')), undefined, 'recordException') + t.end() + }) + + suite.test('public interface Transaction API', t => { + t.equal(nrsTrans.name, '', 'name') + t.equal(nrsTrans.type, null, 'type') + t.equal(nrsTrans.subtype, null, 'subtype') + t.equal(nrsTrans.action, null, 'action') + t.equal(nrsTrans.traceparent, + '00-d4cda95b652f4a1592b449dd92ffda3b-6e0c63ffe4e34c42-01', + 'traceparent') + t.equal(nrsTrans.outcome, OUTCOME_UNKNOWN, 'outcome') + t.equal(nrsTrans.result, '', 'result') + t.deepEqual(nrsTrans.ids, + { 'trace.id': 'd4cda95b652f4a1592b449dd92ffda3b', 'transaction.id': '6e0c63ffe4e34c42' }, + 'ids') + + t.equal(nrsTrans.setType('aType', 'aSubtype', 'anAction'), undefined, 'setType') + t.equal(nrsTrans.setLabel('foo', 'bar'), false, 'setLabel') + t.equal(nrsTrans.addLabels({ foo: 'bar' }), false, 'addLabels') + t.equal(nrsTrans.setOutcome(OUTCOME_UNKNOWN), undefined, 'setOutcome') + t.equal(nrsTrans.startSpan('aSpan', {}), null, 'setSpan') + + t.equal(nrsTrans.ensureParentId(), '', 'ensureParentId') + t.equal(nrsTrans.end('aResult', 42), undefined, 'end') + + t.end() + }) + + suite.end() +}) diff --git a/test/opentelemetry-bridge/OTelBridgeRunContext.test.js b/test/opentelemetry-bridge/OTelBridgeRunContext.test.js new file mode 100644 index 0000000000..8b30845a86 --- /dev/null +++ b/test/opentelemetry-bridge/OTelBridgeRunContext.test.js @@ -0,0 +1,65 @@ +'use strict' + +require('../..').start({ + opentelemetryBridgeEnabled: true, + // Make the agent quiet. + disableSend: true, + centralConfig: false, + cloudProvider: 'none', + metricsInterval: '0s', + captureExceptions: false, + logLevel: 'off' +}) + +const otel = require('@opentelemetry/api') +const tape = require('tape') +const { OTelBridgeRunContext } = require('../../lib/opentelemetry-bridge') + +const tracer = otel.trace.getTracer() +const FOO_KEY = otel.createContextKey('foo') + +function parentIdFromSpan (span) { + return ( + span.parentSpanId || // OTel SDK + (span._span && span._span.parentId) || // Elastic APM + undefined + ) +} + +tape.test('OTelBridgeRunContext', t => { + const ctx = otel.context.active() + t.ok(ctx instanceof OTelBridgeRunContext) + + const ctx2 = ctx.setValue(FOO_KEY, 'bar') + t.ok(ctx2 !== ctx, 'setValue returns a new instance') + t.equal(ctx2.getValue(FOO_KEY), 'bar') + t.equal(ctx.getValue(FOO_KEY), undefined) + + const ctx3 = ctx2.deleteValue(FOO_KEY) + t.ok(ctx3 !== ctx2, 'deleteValue returns a new instance') + t.equal(ctx3.getValue(FOO_KEY), undefined) + t.equal(ctx2.getValue(FOO_KEY), 'bar') + + t.end() +}) + +// The point of OTelBridgeRunContext is to specially handle getting/setting +// the active span via the span key (a Symbol), so we should test the code +// paths for that. `setValue(SPAN_KEY, ...)` and `getValue(SPAN_KEY)` are well +// tested in other tests. That leaves `deleteValue(SPAN_KEY)` +tape.test('OTelBridgeRunContext.deleteValue(SPAN_KEY)', t => { + tracer.startActiveSpan('s1', s1 => { + let ctx = otel.context.active() + ctx = ctx.setValue(FOO_KEY, 'bar') + ctx = otel.trace.deleteSpan(ctx) // this calls `ctx.deleteValue(SPAN_KEY)` + t.equal(ctx.getValue(FOO_KEY), 'bar', 'FOO_KEY survived the deleteSpan') + + tracer.startActiveSpan('s2', {}, ctx, s2 => { + t.equal(parentIdFromSpan(s2), undefined, 's2 is not a child of s1') + s2.end() + }) + s1.end() + }) + + t.end() +}) diff --git a/test/opentelemetry-bridge/active-span-and-context-interop.test.js b/test/opentelemetry-bridge/active-span-and-context-interop.test.js new file mode 100644 index 0000000000..970b6686b6 --- /dev/null +++ b/test/opentelemetry-bridge/active-span-and-context-interop.test.js @@ -0,0 +1,78 @@ +'use strict' + +// Test interoperation of active spans and context between the Agent API and +// the OTel API. Cases are described here: +// https://github.com/elastic/apm/blob/main/specs/agents/tracing-api-otel.md#active-spans-and-context + +const apm = require('../..').start({ + opentelemetryBridgeEnabled: true, + // Make the agent quiet. + disableSend: true, + centralConfig: false, + cloudProvider: 'none', + metricsInterval: '0s', + captureExceptions: false, + logLevel: 'off' +}) + +const otel = require('@opentelemetry/api') +const tape = require('tape') + +const tracer = otel.trace.getTracer() + +function parentIdFromOTelSpan (span) { + return ( + span.parentSpanId || // OTel SDK + (span._span && span._span.parentId) || // Elastic APM + undefined + ) +} +function idFromOTelSpan (span) { + return span.spanContext().spanId +} + +// After activating an Elastic span via the agent's API, the Context returned +// via the get current context API should contain that Elastic span +tape.test('curr Elastic span is contained in OTel Context', t => { + const t1 = apm.startTransaction('t1') + const otelSpan = otel.trace.getSpan(otel.context.active()) + t.strictEqual(otelSpan._span, t1, 'active OTel span contains the Elastic API-started transaction') + t1.end() + t.end() +}) + +// When an OTel context is attached (aka activated), the get current context API +// should return the same Context instance. +tape.test('OTel context attachment works', t => { + const KEY = otel.createContextKey('myKey') + const ctx = otel.context.active().setValue(KEY, 'foo') + otel.context.with(ctx, function () { + t.strictEqual(otel.context.active(), ctx, 'active context is the same Context instance as was activated') + t.strictEqual(otel.context.active().getValue(KEY), 'foo') + t.end() + }) +}) + +// Starting an OTel span in the scope of an active Elastic span should make the +// OTel span a child of the Elastic span. +tape.test('OTel span in an Elastic span', t => { + const t3 = apm.startTransaction('t3') + const s3 = tracer.startSpan('s3') + t.strictEqual(parentIdFromOTelSpan(s3), t3.id, + 'OTel span created in context of Elastic transaction is a child of it') + s3.end() + t3.end() + t.end() +}) + +// Starting an Elastic span in the scope of an active OTel span should make the +// Elastic span a child of the OTel span. +tape.test('Elastic span in an OTel span', t => { + tracer.startActiveSpan('t4', t4 => { + const s4 = apm.startSpan('s4') + t.strictEqual(s4.parentId, idFromOTelSpan(t4), 'Elastic span created in context of OTel span is a child of it') + s4.end() + t4.end() + t.end() + }) +}) diff --git a/test/opentelemetry-bridge/fixtures.test.js b/test/opentelemetry-bridge/fixtures.test.js new file mode 100644 index 0000000000..b4acac022e --- /dev/null +++ b/test/opentelemetry-bridge/fixtures.test.js @@ -0,0 +1,454 @@ +'use strict' + +// Thes tests below execute a script from "fixtures/" something like: +// +// ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true \ +// node -r ../../start.js fixtures/start-span.js +// +// and assert that (a) it exits successfully (passing internal `assert(...)`s), +// and (b) the mock APM server got the expected trace data. +// +// The scripts can be run independent of the test suite. Also, they can be +// run using the *OpenTelemetry SDK* for comparison. E.g.: +// node -r ../../examples/otel/otel-sdk.js fixtures/start-span.js + +const { execFile } = require('child_process') +const path = require('path') +const semver = require('semver') +const tape = require('tape') +const { RESULT_SUCCESS, OUTCOME_UNKNOWN, OUTCOME_SUCCESS, RESULT_FAILURE, OUTCOME_FAILURE } = require('../../lib/constants') + +const { MockAPMServer } = require('../_mock_apm_server') +const { findObjInArray } = require('../_utils') + +const haveUsablePerformanceNow = semver.satisfies(process.version, '>=8.12.0') + +const cases = [ + { + // Expect: + // transaction "mySpan" + script: 'start-span.js', + check: (t, events) => { + t.equal(events.length, 2, 'exactly 2 events') + t.ok(events[0].metadata, 'APM server got event metadata object') + const mySpan = findObjInArray(events, 'transaction.name', 'mySpan').transaction + t.ok(mySpan, 'transaction.name') + t.strictEqual(mySpan.outcome, OUTCOME_UNKNOWN, 'transaction.outcome') + t.strictEqual(mySpan.otel.span_kind, 'INTERNAL', 'transaction.otel.span_kind') + t.strictEqual(mySpan.parent_id, undefined, 'transaction.parent_id') + } + }, + + { + // Expect: + // transaction "s1" (outcome=unknown) + // `- span "s2" (outcome=unknown) + script: 'start-active-span.js', + check: (t, events) => { + t.equal(events.length, 3, 'exactly 3 events') + const s1 = findObjInArray(events, 'transaction.name', 's1').transaction + t.ok(s1, 'transaction.name') + t.strictEqual(s1.outcome, OUTCOME_UNKNOWN, 'transaction.outcome') + const s2 = findObjInArray(events, 'span.name', 's2').span + t.ok(s2, 'span.name') + t.strictEqual(s2.outcome, OUTCOME_UNKNOWN, 'span.outcome') + t.strictEqual(s2.parent_id, s1.id, 'span.parent_id') + } + }, + + { + // Expect: + // transaction "s2" (trace_id=d4cda95b652f4a1592b449dd92ffda3b, parent_id=6e0c63ffe4e34c42) + script: 'nonrecordingspan-parent.js', + check: (t, events) => { + t.equal(events.length, 2, 'exactly 2 events') + t.ok(events[0].metadata, 'APM server got event metadata object') + const s2 = findObjInArray(events, 'transaction.name', 's2').transaction + t.ok(s2, 'transaction.name') + t.equal(s2.trace_id, 'd4cda95b652f4a1592b449dd92ffda3b', 'transaction.trace_id') + t.ok(s2.parent_id, '6e0c63ffe4e34c42', 'transaction.parent_id') + } + }, + + { + // Expect: + // transaction "s2" (trace_id=d4cda95b652f4a1592b449dd92ffda3b, parent_id=6e0c63ffe4e34c42) + script: 'using-root-context.js', + check: (t, events) => { + t.equal(events.length, 2, 'exactly 2 events') + t.ok(events[0].metadata, 'APM server got event metadata object') + const s2 = findObjInArray(events, 'transaction.name', 's2').transaction + t.ok(s2, 'transaction.name') + t.equal(s2.trace_id, 'd4cda95b652f4a1592b449dd92ffda3b', 'transaction.trace_id') + t.ok(s2.parent_id, '6e0c63ffe4e34c42', 'transaction.parent_id') + } + }, + + { + // Expect: + // transaction "callServiceA" + // `- span "GET localhost:$portA" (context.http.url=http://localhost:$portA/a-ping) + // `- transaction "GET unknown route" (context.request.headers.{traceparent,tracestate}) + // `- span "GET localhost:$portB" (context.http.url=http://localhost:$portB/b-ping) + // `- transaction "GET unknown route" (context.request.headers.{traceparent,tracestate}) + script: 'distributed-trace.js', + check: (t, events) => { + t.equal(events.length, 6, 'exactly 6 events') + t.ok(events[0].metadata, 'APM server got event metadata object') + // All the transactions and spans, in timestamp order. + const tas = events.slice(1) + .sort((a, b) => (a.transaction || a.span).timestamp - (b.transaction || b.span).timestamp) + // transaction "callServiceA" + t.equal(tas[0].transaction.name, 'callServiceA') + // `- span "GET localhost:$portA" (context.http.url=http://localhost:$portA/a-ping) + const portA = tas[1].span.context.destination.port + t.equal(tas[1].span.parent_id, tas[0].transaction.id) + t.equal(tas[1].span.name, `GET localhost:${portA}`) + t.ok(tas[1].span.context.http.url, `http://localhost:${portA}/a-ping`) + // `- transaction "GET unknown route" (context.request.headers.{traceparent,tracestate}) + t.equal(tas[2].transaction.parent_id, tas[1].span.id) + t.equal(tas[2].transaction.name, 'GET unknown route') + t.ok(tas[2].transaction.context.request.headers.traceparent) + t.equal(tas[2].transaction.context.request.headers.tracestate, 'es=s:1') + // `- span "GET localhost:$portB" (context.http.url=http://localhost:$portB/b-ping) + const portB = tas[3].span.context.destination.port + t.equal(tas[3].span.parent_id, tas[2].transaction.id) + t.equal(tas[3].span.name, `GET localhost:${portB}`) + t.ok(tas[3].span.context.http.url, `http://localhost:${portB}/b-ping`) + // `- transaction "GET unknown route" (context.request.headers.{traceparent,tracestate}) + t.equal(tas[4].transaction.parent_id, tas[3].span.id) + t.equal(tas[4].transaction.name, 'GET unknown route') + t.ok(tas[4].transaction.context.request.headers.traceparent) + t.equal(tas[4].transaction.context.request.headers.tracestate, 'es=s:1') + } + }, + + { + // Expect: + // trace + // `- transaction "s1" + // `- span "s3" + // `- span "s5" + // `- transaction "s4" + // `- span "s6" + // trace + // `- transaction "s2" + script: 'start-span-with-context.js', + check: (t, events) => { + t.equal(events.length, 7, 'exactly 7 events') + t.ok(events[0].metadata, 'APM server got event metadata object') + // All the transactions and spans, in order of creation. + // (Because of https://github.com/elastic/apm-agent-nodejs/issues/2180 + // we cannot use "timestamp" for sorting.) + const tas = events.slice(1) + .sort((a, b) => (a.transaction || a.span).name > (b.transaction || b.span).name ? 1 : -1) + t.equal(tas[0].transaction.name, 's1', 's1.name') + t.equal(tas[0].transaction.parent_id, undefined, 's1 has no parent') + const traceId = tas[0].transaction.trace_id + t.equal(tas[1].transaction.name, 's2', 's2.name') + t.equal(tas[1].transaction.parent_id, undefined, 's2 has no parent') + t.notEqual(tas[1].transaction.trace_id, traceId, 's2 has a separate trace id') + t.equal(tas[2].span.name, 's3', 's3.name') + t.equal(tas[2].span.parent_id, tas[0].transaction.id, 's3 is a child of s1') + t.equal(tas[3].transaction.name, 's4', 's4.name') + t.equal(tas[3].transaction.parent_id, tas[0].transaction.id, 's4 is a child of s1') + t.equal(tas[4].span.name, 's5', 's5.name') + t.equal(tas[4].span.parent_id, tas[2].span.id, 's5 is a child of s3') + t.equal(tas[5].span.name, 's6', 's6.name') + t.equal(tas[5].span.parent_id, tas[0].transaction.id, 's4 is a child of s1') + } + }, + + { + // Expected trace: + // trace $traceId + // `- transaction $myTransId "myTrans" + // `- span "s0" + // `- span "GET localhost:$port" (http) + // `- transaction "GET unknown route" + // `- span "s1" // This is the 3rd (max) span. + // `- transaction "GET unknown route" + // `- transaction "GET unknown route" + // `- transaction "GET unknown route" + // `- transaction "GET unknown route" + script: 'hit-transaction-max-spans.js', + testOpts: { + // - This fixture fails with node.js [10.0, 10.4) due to an async context + // issue. See https://github.com/nodejs/node/issues/20274 + // - This fixture hits a limitation/bug with asyncHooks=false. + // See https://github.com/elastic/apm-agent-nodejs/issues/2679 + skip: (semver.satisfies(process.version, '>=10.0.0 <10.4') || + process.env.ELASTIC_APM_ASYNC_HOOKS === 'false') + }, + env: { + ELASTIC_APM_TRANSACTION_MAX_SPANS: '3' + }, + check: (t, events) => { + t.equal(events.length, 10, 'exactly 10 events') + t.ok(events[0].metadata, 'APM server got event metadata object') + + function assertIncomingHttpTrans (trans, parentId) { + t.equal(trans.name, 'GET unknown route', 'incoming http transaction.name') + t.equal(trans.parent_id, parentId, 'incoming http transaction.parent_id') + t.ok(trans.context.request.headers.traceparent, 'incoming http "traceparent" header') + t.ok(trans.context.request.headers['elastic-apm-traceparent'], 'incoming http "elastic-apm-traceparent" header') + t.ok((trans.context.request.headers.tracestate || '').indexOf('es=s:1') !== -1, + 'incoming http "tracestate" header has expected "es=" section') + } + + // All the transactions and spans, in order of creation. + const tas = events.slice(1) + .sort((a, b) => (a.transaction || a.span).timestamp > (b.transaction || b.span).timestamp ? 1 : -1) + // trace $traceId + const traceId = tas[0].transaction.trace_id + tas.forEach(s => { + t.equal((s.transaction || s.span).trace_id, traceId, 'traceId') + }) + // `- transaction $myTransId "myTrans" + const myTrans = tas[0].transaction + t.equal(myTrans.name, 'myTrans', 'myTrans.name') + t.deepEqual(myTrans.span_count, { started: 3, dropped: 4 }, 'myTrans.span_count') + // `- span "s0" + const s0 = tas[1].span + t.equal(s0.name, 's0', 's0') + t.equal(s0.parent_id, myTrans.id, 's0.parent_id') + // `- span "GET localhost:$port" (http) + t.equal(tas[2].span.subtype, 'http', 'http span.subtype') + t.equal(tas[2].span.parent_id, s0.id, 'http span.parent_id') + // `- transaction "GET unknown route" + assertIncomingHttpTrans(tas[3].transaction, tas[2].span.id) + // `- span "s1" // This is the 3rd (max) span. + const s1 = tas[4].span + t.equal(s1.name, 's1', 's1') + t.equal(s1.parent_id, myTrans.id, 's1.parent_id') + // `- transaction "GET unknown route" + assertIncomingHttpTrans(tas[5].transaction, tas[4].span.id) + // `- transaction "GET unknown route" + // `- transaction "GET unknown route" + // `- transaction "GET unknown route" + for (let i = 6; i < 9; i++) { + assertIncomingHttpTrans(tas[i].transaction, myTrans.id) + } + } + }, + + { + script: 'interface-span.js', + check: (t, events) => { + // Span#setAttribute, Span#setAttributes + const expectedAttributes = { + 'a.string': 'hi', + 'a.number': 42, + 'a.boolean': true, + 'an.array.of.strings': ['one', 'two', 'three'], + 'an.array.of.numbers': [1, 2, 3], + 'an.array.of.booleans': [true, false], + 'an.array.that.will.be.modified': ['hello', 'bob'], + 'a.zero': 0, + 'a.false': false, + 'an.empty.string': '', + 'an.empty.array': [], + 'an.array.with.nulls': ['one', null, 'three'], + 'an.array.with.undefineds': ['one', null, 'three'] + } + t.deepEqual(findObjInArray(events, 'transaction.name', 'sSetAttribute').transaction.otel.attributes, + expectedAttributes, 'sSetAttribute') + t.deepEqual(findObjInArray(events, 'transaction.name', 'sSetAttributes').transaction.otel.attributes, + expectedAttributes, 'sSetAttributes') + + // Span#addEvent + t.ok(findObjInArray(events, 'transaction.name', 'sAddEvent').transaction, 'sAddEvent') + + // Span#setStatus + const sSetStatusDoNotSet = findObjInArray(events, 'transaction.name', 'sSetStatusDoNotSet').transaction + t.equal(sSetStatusDoNotSet.result, RESULT_SUCCESS, 'sSetStatusDoNotSet.result') + t.equal(sSetStatusDoNotSet.outcome, OUTCOME_UNKNOWN, 'sSetStatusDoNotSet.outcome') + const sSetStatusUNSET = findObjInArray(events, 'transaction.name', 'sSetStatusUNSET').transaction + t.equal(sSetStatusUNSET.result, RESULT_SUCCESS, 'sSetStatusUNSET.result') + t.equal(sSetStatusUNSET.outcome, OUTCOME_UNKNOWN, 'sSetStatusUNSET.outcome') + const sSetStatusOK = findObjInArray(events, 'transaction.name', 'sSetStatusOK').transaction + t.equal(sSetStatusOK.result, RESULT_SUCCESS, 'sSetStatusOK.result') + t.equal(sSetStatusOK.outcome, OUTCOME_SUCCESS, 'sSetStatusOK.outcome') + const sSetStatusERROR = findObjInArray(events, 'transaction.name', 'sSetStatusERROR').transaction + t.equal(sSetStatusERROR.result, RESULT_FAILURE, 'sSetStatusERROR.result') + t.equal(sSetStatusERROR.outcome, OUTCOME_FAILURE, 'sSetStatusERROR.outcome') + const sSetStatusMulti = findObjInArray(events, 'transaction.name', 'sSetStatusMulti').transaction + t.equal(sSetStatusMulti.result, RESULT_SUCCESS, 'sSetStatusMulti.result') + t.equal(sSetStatusMulti.outcome, OUTCOME_SUCCESS, 'sSetStatusMulti.outcome') + const sSetStatusChildERROR = findObjInArray(events, 'span.name', 'sSetStatusChildERROR').span + t.equal(sSetStatusChildERROR.outcome, OUTCOME_FAILURE, 'sSetStatusChildERROR.outcome') + + t.strictEqual(findObjInArray(events, 'transaction.otel.attributes.testId', 'sUpdateName').transaction.name, + 'three', 'sUpdateName') + + // Span#end + function spanEndTimeIsApprox (transOrSpanName, t = Date.now()) { + const foundTrans = findObjInArray(events, 'transaction.name', transOrSpanName) + const genericSpan = (foundTrans + ? foundTrans.transaction + : findObjInArray(events, 'span.name', transOrSpanName).span) + const endTimeMs = genericSpan.timestamp / 1000 + genericSpan.duration + const msFromT = Math.abs(t - endTimeMs) + return msFromT < 30 * 1000 // within 30s + } + t.ok(spanEndTimeIsApprox('sEndTimeNotSpecified'), 'sEndTimeNotSpecified') + t.ok(spanEndTimeIsApprox('sEndTimeHrTime'), 'sEndTimeHrTime') + t.ok(spanEndTimeIsApprox('sEndTimeEpochMs'), 'sEndTimeEpochMs') + if (haveUsablePerformanceNow) { + t.ok(spanEndTimeIsApprox('sEndTimePerformanceNow'), 'sEndTimePerformanceNow') + } + t.ok(spanEndTimeIsApprox('sEndTimeDate'), 'sEndTimeDate') + t.ok(spanEndTimeIsApprox('sEndChildTimeDate'), 'sEndChildTimeDate') + const HOUR = 1 * 60 * 60 * 1000 // an hour in milliseconds + t.ok(spanEndTimeIsApprox('sEndOneHourAgo', Date.now() - HOUR), 'sEndOneHourAgo end time is 1h ago') + const sEndOneHourAgo = findObjInArray(events, 'transaction.name', 'sEndOneHourAgo').transaction + t.equal(sEndOneHourAgo.duration, HOUR, `sEndOneHourAgo duration is 1h: ${sEndOneHourAgo.duration}`) + t.ok(spanEndTimeIsApprox('sEndOneHourFromNow', Date.now() + HOUR), 'sEndOneHourFromNow end time is 1h from now') + const sEndOneHourFromNow = findObjInArray(events, 'transaction.name', 'sEndOneHourFromNow').transaction + t.equal(sEndOneHourFromNow.duration, HOUR, `sEndOneHourFromNow duration is 1h: ${sEndOneHourFromNow.duration}`) + + // Span#isRecording() + t.ok(findObjInArray(events, 'transaction.name', 'sIsRecordingSampled'), 'sIsRecordingSampled') + + // Span#recordException() + function errorTimestampIsApprox (error, t = Date.now()) { + const msFromT = Math.abs(t - error.timestamp / 1e3) + return msFromT < 30 * 1000 // within 30s + } + const now = Date.now() + const sRecordException = findObjInArray(events, 'transaction.name', 'sRecordException').transaction + // - new Error('an Error') + const eAnError = findObjInArray(events, 'error.exception.message', 'an Error').error + t.strictEqual(eAnError.parent_id, sRecordException.id, 'eAnError.parent_id') + t.ok(errorTimestampIsApprox(eAnError, now), 'eAnError.timestamp') + // - fsErr + const eFsErr = findObjInArray(events, 'error.exception.code', 'ENOENT').error + t.strictEqual(eFsErr.parent_id, sRecordException.id, 'eFsErr.parent_id') + t.ok(errorTimestampIsApprox(eFsErr, now), 'eFsErr.timestamp') + // - 'a string' + const eAString = findObjInArray(events, 'error.log.message', 'a string').error + t.strictEqual(eAString.parent_id, sRecordException.id, 'eAString.parent_id') + t.ok(errorTimestampIsApprox(eAString, now), 'eAString.timestamp') + // - new Error('one hour ago') + const eOneHourAgo = findObjInArray(events, 'error.exception.message', 'one hour ago').error + t.strictEqual(eOneHourAgo.parent_id, sRecordException.id, 'eOneHourAgo.parent_id') + t.ok(errorTimestampIsApprox(eOneHourAgo, now - HOUR), 'eOneHourAgo.timestamp') + // - new Error('after span end works') + const aAfterEnd = findObjInArray(events, 'error.exception.message', 'after span end works').error + t.strictEqual(aAfterEnd.parent_id, sRecordException.id, 'aAfterEnd.parent_id') + t.ok(errorTimestampIsApprox(aAfterEnd, now), 'aAfterEnd.timestamp') + } + }, + + { + script: 'interface-tracer.js', + check: (t, events) => { + // SpanOptions.kind + t.equal(findObjInArray(events, 'transaction.name', 'sKindDefault').transaction.otel.span_kind, 'INTERNAL', 'sKindDefault') + t.equal(findObjInArray(events, 'transaction.name', 'sKindInternal').transaction.otel.span_kind, 'INTERNAL', 'sKindInternal') + t.equal(findObjInArray(events, 'transaction.name', 'sKindServer').transaction.otel.span_kind, 'SERVER', 'sKindServer') + t.equal(findObjInArray(events, 'transaction.name', 'sKindClient').transaction.otel.span_kind, 'CLIENT', 'sKindClient') + t.equal(findObjInArray(events, 'transaction.name', 'sKindProducer').transaction.otel.span_kind, 'PRODUCER', 'sKindProducer') + t.equal(findObjInArray(events, 'transaction.name', 'sKindConsumer').transaction.otel.span_kind, 'CONSUMER', 'sKindConsumer') + + // SpanOptions.attributes + t.equal(findObjInArray(events, 'transaction.name', 'sAttributesNone').transaction.otel.attributes, undefined, 'sAttributesNone') + t.deepEqual(findObjInArray(events, 'transaction.name', 'sAttributesLots').transaction.otel.attributes, { + 'a.string': 'hi', + 'a.number': 42, + 'a.boolean': true, + 'an.array.of.strings': ['one', 'two', 'three'], + 'an.array.of.numbers': [1, 2, 3], + 'an.array.of.booleans': [true, false], + 'an.array.that.will.be.modified': ['hello', 'bob'], + 'a.zero': 0, + 'a.false': false, + 'an.empty.string': '', + 'an.empty.array': [], + 'an.array.with.nulls': ['one', null, 'three'], + 'an.array.with.undefineds': ['one', null, 'three'] + }, 'sAttributesLots') + + // SpanOptions.links (not yet supported) + t.equal(findObjInArray(events, 'transaction.name', 'sLinksNone').transaction.links, undefined, 'sLinksNone') + t.equal(findObjInArray(events, 'transaction.name', 'sLinksEmptyArray').transaction.links, undefined, 'sLinksEmptyArray') + t.equal(findObjInArray(events, 'transaction.name', 'sLinksInvalid').transaction.links, undefined, 'sLinksInvalid') + t.equal(findObjInArray(events, 'transaction.name', 'sLinks').transaction.links, undefined, 'sLinks') + t.equal(findObjInArray(events, 'transaction.name', 'sLinksWithAttrs').transaction.links, undefined, 'sLinksWithAttrs') + + // SpanOptions.startTime + function transTimestampIsRecent (name) { + const trans = findObjInArray(events, 'transaction.name', name).transaction + const msFromNow = Math.abs(Date.now() - trans.timestamp / 1000) + return msFromNow < 30 * 1000 // within 30s + } + t.ok(transTimestampIsRecent('sStartTimeHrTime'), 'sStartTimeHrTime') + t.ok(transTimestampIsRecent('sStartTimeEpochMs'), 'sStartTimeEpochMs') + if (haveUsablePerformanceNow) { + t.ok(transTimestampIsRecent('sStartTimePerformanceNow'), 'sStartTimePerformanceNow') + } + t.ok(transTimestampIsRecent('sStartTimeDate'), 'sStartTimeDate') + + // SpanOptions.root + const sParent = findObjInArray(events, 'transaction.name', 'sParent').transaction + const sRootNotSpecified = findObjInArray(events, 'span.name', 'sRootNotSpecified').span + t.equal(sRootNotSpecified.trace_id, sParent.trace_id, 'sRootNotSpecified.trace_id') + t.equal(sRootNotSpecified.parent_id, sParent.id, 'sRootNotSpecified.parent_id') + const sRoot = findObjInArray(events, 'transaction.name', 'sRoot').transaction + t.notEqual(sRoot.trace_id, sParent.trace_id, 'sRoot.trace_id') + t.strictEqual(sRoot.parent_id, undefined, 'sRoot.parent_id') + + // tracer.startActiveSpan() + t.ok(findObjInArray(events, 'transaction.name', 'sActiveRetval').transaction, 'sActiveRetval') + t.ok(findObjInArray(events, 'transaction.name', 'sActiveThrows').transaction, 'sActiveThrows') + t.ok(findObjInArray(events, 'transaction.name', 'sActiveAsync').transaction, 'sActiveAsync') + const sActiveWithOptions = findObjInArray(events, 'transaction.name', 'sActiveWithOptions').transaction + t.strictEqual(sActiveWithOptions.otel.span_kind, 'CLIENT', 'sActiveWithOptions span_kind') + t.deepEqual(sActiveWithOptions.otel.attributes, { 'a.string': 'hi' }, 'sActiveWithOptions attributes') + t.ok(findObjInArray(events, 'transaction.name', 'sActiveWithContext').transaction, 'sActiveWithContext') + } + } +] + +cases.forEach(c => { + tape.test(`opentelemetry-bridge/fixtures/${c.script}`, c.testOpts || {}, t => { + const server = new MockAPMServer() + const scriptPath = path.join('fixtures', c.script) + server.start(function (serverUrl) { + execFile( + process.execPath, + ['-r', '../../start.js', scriptPath], + { + cwd: __dirname, + timeout: 10000, // guard on hang, 3s is sometimes too short for CI + env: Object.assign( + {}, + process.env, + c.env, + { + ELASTIC_APM_SERVER_URL: serverUrl, + ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED: 'true', + // Silence optional features of the agent. Removing metrics + // allows some of the above tests to make assumptions about + // which events the APM server receives. + ELASTIC_APM_CENTRAL_CONFIG: 'false', + ELASTIC_APM_CLOUD_PROVIDER: 'none', + ELASTIC_APM_METRICS_INTERVAL: '0s', + ELASTIC_APM_LOG_UNCAUGHT_EXCEPTIONS: 'true' + } + ) + }, + function done (err, _stdout, _stderr) { + t.error(err, `${scriptPath} exited non-zero`) + if (err) { + t.comment('skip checks because script errored out') + } else { + c.check(t, server.events) + } + server.close() + t.end() + } + ) + }) + }) +}) diff --git a/test/opentelemetry-bridge/fixtures/distributed-trace.js b/test/opentelemetry-bridge/fixtures/distributed-trace.js new file mode 100644 index 0000000000..836647e5e3 --- /dev/null +++ b/test/opentelemetry-bridge/fixtures/distributed-trace.js @@ -0,0 +1,90 @@ +'use strict' + +// Expect: +// transaction "callServiceA" +// `- span "GET localhost:$portA" (context.http.url=http://localhost:$portA/a-ping) +// `- transaction "GET unknown route" (context.request.headers.{traceparent,tracestate}) +// `- span "GET localhost:$portB" (context.http.url=http://localhost:$portB/b-ping) +// `- transaction "GET unknown route" (context.request.headers.{traceparent,tracestate}) +// +// This scripts starts two HTTP servers, `serviceA` and `serviceB`, then makes +// an HTTP client "GET /a-ping" to serviceA. Service A will always call service +// B before responding. +// +// This tests that the automatic instrumentation for distributed traces is working. + +// const assert = require('assert') +const http = require('http') + +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('play') + +const serviceA = http.createServer(function onARequest (req, res) { + console.log('serviceA request: %s %s %s', req.method, req.url, req.headers) + req.resume() + req.on('end', function () { + // Make a client request to service B... + http.get({ + host: 'localhost', + port: serviceB.address().port, + path: '/b-ping' + }, (cRes) => { + console.log('serviceB response status:', cRes.statusCode) + console.log('serviceB response headers:', cRes.headers) + const body = [] + cRes.on('data', (chunk) => body.push(chunk)) + cRes.on('end', () => { + console.log('serviceB response body:', body.toString()) + + // ... then respond. + const resBody = JSON.stringify({ ping: 'pong', server: 'A' }) + res.writeHead(200, { + 'content-type': 'application/json', + 'content-length': Buffer.byteLength(resBody) + }) + res.end(resBody) + }) + }) + }) +}) + +const serviceB = http.createServer(function onBRequest (req, res) { + console.log('serviceB request: %s %s %s', req.method, req.url, req.headers) + req.resume() + req.on('end', function () { + const resBody = JSON.stringify({ ping: 'pong', server: 'B' }) + res.writeHead(200, { + 'content-type': 'application/json', + 'content-length': Buffer.byteLength(resBody) + }) + res.end(resBody) + }) +}) + +// 1. Start the HTTP services. +serviceA.listen(() => { + serviceB.listen(() => { + // 2. Call service A. + const span = tracer.startSpan('callServiceA') + otel.context.with(otel.trace.setSpan(otel.context.active(), span), () => { + http.get({ + host: 'localhost', + port: serviceA.address().port, + path: '/a-ping' + }, (res) => { + console.log('serviceA response status:', res.statusCode) + console.log('serviceA response headers:', res.headers) + const body = [] + res.on('data', (chunk) => body.push(chunk)) + res.on('end', () => { + console.log('serviceA response body:', body.toString()) + span.end() + + // 3. Shutdown. + serviceB.close() + serviceA.close() + }) + }) + }) + }) +}) diff --git a/test/opentelemetry-bridge/fixtures/hit-transaction-max-spans.js b/test/opentelemetry-bridge/fixtures/hit-transaction-max-spans.js new file mode 100644 index 0000000000..8f4a9bf766 --- /dev/null +++ b/test/opentelemetry-bridge/fixtures/hit-transaction-max-spans.js @@ -0,0 +1,79 @@ +'use strict' + +// This tests the OTel Bridge for the case when `transactionMaxSpans` is hit. +// +// This results in `.createSpan(...)` returning null. The OTel +// Bridge needs to cope by returning a non-recording span. It *also* needs +// to propagate W3C trace-context for outgoing HTTP requests. +// +// Usage: +// ELASTIC_APM_TRANSACTION_MAX_SPANS=3 \ +// ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true \ +// node -r ../../../start.js hit-transaction-max-spans.js +// +// Expected trace: +// trace $traceId +// `- transaction $myTransId "myTrans" +// `- span "s0" +// `- span "GET localhost:$port" (http) +// `- transaction "GET unknown route" +// `- span "s1" // This is the 3rd (max) span. +// `- transaction "GET unknown route" +// `- transaction "GET unknown route" +// `- transaction "GET unknown route" +// `- transaction "GET unknown route" + +const http = require('http') + +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('test-hit-transaction-max-spans') + +const server = http.createServer(function onRequest (req, res) { + console.log('server request: %s %s %s', req.method, req.url, req.headers) + req.resume() + req.on('end', function () { + const resBody = JSON.stringify({ ping: 'pong' }) + res.writeHead(200, { + 'content-type': 'application/json', + 'content-length': Buffer.byteLength(resBody) + }) + res.end(resBody) + }) +}) + +async function makeAClientRequest (i, port) { + console.log('\n-- make client request %d', i) + await tracer.startActiveSpan(`s${i}`, async (s) => { + return new Promise(resolve => { + http.get({ + host: 'localhost', + port: port, + path: `/ping-${i}` + }, (cRes) => { + console.log('client response status:', cRes.statusCode) + console.log('client response headers:', cRes.headers) + const body = [] + cRes.on('data', (chunk) => body.push(chunk)) + cRes.on('end', () => { + console.log('client response body:', body.toString()) + s.end() + resolve() + }) + }) + }) + }) +} + +server.listen(async () => { + const port = server.address().port + tracer.startActiveSpan('myTrans', async (myTrans) => { + // Make 5 client requests to `server` in sequence. Each of those requests + // involves two spans (a manual `s${i}` span and the auto-instrumented + // http.get() span). We expect to hit the `transactionMaxSpans` limit. + for (let i = 0; i < 5; i++) { + await makeAClientRequest(i, port) + } + myTrans.end() + server.close() + }) +}) diff --git a/test/opentelemetry-bridge/fixtures/interface-span.js b/test/opentelemetry-bridge/fixtures/interface-span.js new file mode 100644 index 0000000000..53d99255b7 --- /dev/null +++ b/test/opentelemetry-bridge/fixtures/interface-span.js @@ -0,0 +1,199 @@ +'use strict' + +// Exercise the full `interface Span`. +// +// Usage: +// ELASTIC_APM_OPENTELEMETRY_BRIDGE_ENABLED=true \ +// node -r ../../../start.js interface-span.js # with APM agent +// node -r ../../../examples/otel/otel-sdk.js interface-span.js # with OTel SDK + +const assert = require('assert') +const fs = require('fs') +const performance = require('perf_hooks').performance + +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('test-interface-span') +const semver = require('semver') + +const haveUsablePerformanceNow = semver.satisfies(process.version, '>=8.12.0') + +function parentIdFromSpan (span) { + return ( + span.parentSpanId || // OTel SDK + (span._span && span._span.parentId) || // Elastic APM + undefined + ) +} +function idFromSpan (span) { + return span.spanContext().spanId +} + +let rv + +// A parent OTel Span (i.e. a Transaction) to act as a parent for child spans +// so that we test the OTel Span API on both Elastic `Transaction`s and `Span`s. +const sParent = tracer.startSpan('sParent') +const ctxParent = otel.trace.setSpan(otel.context.active(), sParent) +sParent.end() + +// Span#spanContext() +const sSpanContext = tracer.startSpan('sSpanContext') +const spanContext = sSpanContext.spanContext() +sSpanContext.end() +assert.ok(otel.trace.isSpanContextValid(spanContext), 'spanContext is valid') +assert.strictEqual(spanContext.traceFlags, otel.TraceFlags.SAMPLED, 'spanContext.traceFlags') +assert.ok( + spanContext.traceState === undefined || /* OTel SDK */ + spanContext.traceState.serialize() === 'es=s:1', /* Elastic APM */ + 'spanContext.traceState') + +const ctx = otel.trace.setSpanContext(otel.context.active(), spanContext) +const sSpanContextChild = tracer.startSpan('sSpanContextChild', {}, ctx) +assert.strictEqual(parentIdFromSpan(sSpanContextChild), idFromSpan(sSpanContext), 'sSpanContextChild parent id') +sSpanContextChild.end() + +// Span#setAttribute, Span#setAttributes +const sSetAttribute = tracer.startSpan('sSetAttribute') +const sSetAttributes = tracer.startSpan('sSetAttributes') +const myArray = ['hello', 'bob'] +const attributesToTry = { + 'a.string': 'hi', + 'a.number': 42, + 'a.boolean': true, + 'an.array.of.strings': ['one', 'two', 'three'], + 'an.array.of.numbers': [1, 2, 3], + 'an.array.of.booleans': [true, false], + 'an.array.that.will.be.modified': myArray, // Testing that we take a slice. + // Empty/falsey values: + 'a.zero': 0, + 'a.false': false, + 'an.empty.string': '', + 'an.empty.array': [], + // From the OTel spec: + // > `null` values SHOULD NOT be allowed in arrays. However, ... + // The OTel JS SDK allows nulls and undefineds. + 'an.array.with.nulls': ['one', null, 'three'], + 'an.array.with.undefineds': ['one', undefined, 'three'], + // These are *not* allowed by the OTel API: + 'an.array.of.mixed.types': [1, true, 'three', undefined, null], + 'an.object': { foo: 'bar' }, + 'a.null': null, + 'a.undefined': undefined, + '': 'empty string key' +} +for (const [k, v] of Object.entries(attributesToTry)) { + rv = sSetAttribute.setAttribute(k, v) + assert.strictEqual(rv, sSetAttribute, 'setAttribute return value is the span') +} +rv = sSetAttributes.setAttributes(attributesToTry) +assert.strictEqual(rv, sSetAttributes, 'setAttributes return value is the span') +myArray[0] = 'goodbye' +sSetAttribute.setAttribute() // undefined key +sSetAttribute.setAttribute() // null key +sSetAttribute.setAttribute(42) // non-string key +sSetAttribute.end() +sSetAttributes.end() +sSetAttribute.setAttribute('a.string', 'after-end') // setAttribute after end should not take +sSetAttributes.setAttributes({ 'a.string': 'after-end' }) // setAttributes after end should not take + +// Span#addEvent (currently not supported, so this should no-op) +const sAddEvent = tracer.startSpan('sAddEvent') +assert.strictEqual(sAddEvent.addEvent(), sAddEvent) +assert.strictEqual(sAddEvent.addEvent('myEventName'), sAddEvent) +assert.strictEqual(sAddEvent.addEvent('myEventName', { 'a.string': 'hi' }), sAddEvent) +assert.strictEqual(sAddEvent.addEvent('myEventName', Date.now()), sAddEvent) +assert.strictEqual(sAddEvent.addEvent('myEventName', { 'a.string': 'hi' }, Date.now()), sAddEvent) +sAddEvent.end() + +// Span#setStatus +tracer.startSpan('sSetStatusDoNotSet').end() +tracer.startSpan('sSetStatusUNSET').setStatus(otel.SpanStatusCode.UNSET).end() +tracer.startSpan('sSetStatusOK').setStatus(otel.SpanStatusCode.OK).end() +tracer.startSpan('sSetStatusERROR').setStatus(otel.SpanStatusCode.ERROR).end() +const sSetStatusMulti = tracer.startSpan('sSetStatusMulti') +assert.strictEqual(sSetStatusMulti.setStatus(otel.SpanStatusCode.ERROR), sSetStatusMulti, 'setStatus retval is the span') +assert.strictEqual(sSetStatusMulti.setStatus(otel.SpanStatusCode.OK), sSetStatusMulti, 'setStatus retval is the span') +sSetStatusMulti.end() +sSetStatusMulti.setStatus(otel.SpanStatusCode.UNSET) // setStatus after end should not take +tracer.startSpan('sSetStatusChildERROR', {}, ctxParent).setStatus(otel.SpanStatusCode.ERROR).end() + +// Span#updateName +const sUpdateName = tracer.startSpan('one') +sUpdateName.setAttribute('testId', 'sUpdateName') // so test code can find this span +assert.strictEqual(sUpdateName.updateName('two'), sUpdateName, 'updateName retval is the span') +sUpdateName.updateName('three') +sUpdateName.end() +sUpdateName.updateName('four') // updateName after end should *not* take + +// Span#end +// Specify approximately "now" in each of the supported TimeInput formats. +// OTel HrTime is `[, ]`. +rv = tracer.startSpan('sEndTimeNotSpecified').end() +assert.strictEqual(rv, undefined, 'Span .end() retval is undefined') +const now = Date.now() +tracer.startSpan('sEndTimeHrTime').end([Math.floor(now / 1e3), (now % 1e3) * 1e6]) +tracer.startSpan('sEndTimeEpochMs').end(Date.now()) +if (haveUsablePerformanceNow) { + tracer.startSpan('sEndTimePerformanceNow').end(performance.now()) +} +tracer.startSpan('sEndTimeDate').end(new Date()) +tracer.startSpan('sEndChildTimeDate', {}, ctxParent).end(new Date()) +// Specify past and future endTime. Make the duration one hour for testing. +const t = Date.now() +const HOUR = 1 * 60 * 60 * 1000 +tracer.startSpan('sEndOneHourAgo', { startTime: new Date(t - 2 * HOUR) }).end(new Date(t - HOUR)) +tracer.startSpan('sEndOneHourFromNow', { startTime: t }).end(new Date(t + HOUR)) + +// Span#isRecording +const sIsRecordingSampled = tracer.startSpan('sIsRecordingSampled') +assert.ok(sIsRecordingSampled.spanContext().traceFlags & otel.TraceFlags.SAMPLED, 'sIsRecordingSampled is sampled') +assert.ok(sIsRecordingSampled.isRecording(), 'sIsRecordingSampled isRecording') +sIsRecordingSampled.end() +assert.ok(sIsRecordingSampled.isRecording() === false, 'sIsRecordingSampled isRecording is false after end') +// - Create an OTelSpan holding a Transaction that is not sampled, by creating +// a transaction in the context of a traceparent with the sampled flag false. +const ctxUnsampled = otel.trace.setSpan( + otel.context.active(), + otel.trace.wrapSpanContext({ + traceId: 'd4cda95b652f4a1592b449dd92ffda3b', + spanId: '6e0c63ffe4e34c42', + traceFlags: otel.TraceFlags.NONE + }) +) +const sIsRecordingNotSampled = tracer.startSpan('sIsRecordingNotSampled', {}, ctxUnsampled) +assert.strictEqual(sIsRecordingNotSampled.spanContext().traceFlags & otel.TraceFlags.SAMPLED, 0, 'sIsRecordingNotSampled is not sampled') +assert.strictEqual(sIsRecordingNotSampled.isRecording(), false, 'sIsRecordingNotSampled isRecording is false') +sIsRecordingNotSampled.end() +assert.strictEqual(sIsRecordingNotSampled.isRecording(), false, 'sIsRecordingNotSampled isRecording is false after end') + +// Span#recordException +const sRecordException = tracer.startSpan('sRecordException') +tracer.startActiveSpan('sRecordExceptionCurrTrans', sRecordExceptionCurrTrans => { + tracer.startActiveSpan('sRecordExceptionCurrSpan', sRecordExceptionCurrSpan => { + // The following errors should be children of `sRecordException` even + // though it is not the current span. + rv = sRecordException.recordException(new Error('an Error')) + assert.strictEqual(rv, undefined, 'recordException retval is undefined') + try { + fs.readFileSync('no-such-file') + } catch (fsErr) { + sRecordException.recordException(fsErr) // expect to get error.exception.code === 'ENOENT' + } + sRecordException.recordException('a string') + sRecordException.recordException(new Error('one hour ago'), new Date(Date.now() - HOUR)) + sRecordException.end() + sRecordException.recordException(new Error('after span end works')) + + sRecordExceptionCurrSpan.end() + sRecordExceptionCurrTrans.end() + }) +}) + +// /** +// * Sets exception as a span event +// * @param exception the exception the only accepted values are string or Error +// * @param [time] the time to set as Span's event time. If not provided, +// * use the current time. +// */ +// recordException(exception: Exception, time?: TimeInput): void; +// } diff --git a/test/opentelemetry-bridge/fixtures/interface-tracer.js b/test/opentelemetry-bridge/fixtures/interface-tracer.js new file mode 100644 index 0000000000..e203db518e --- /dev/null +++ b/test/opentelemetry-bridge/fixtures/interface-tracer.js @@ -0,0 +1,150 @@ +'use strict' + +// Exercise the full `interface Tracer`. + +const assert = require('assert') +const performance = require('perf_hooks').performance +const semver = require('semver') + +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('test-interface-tracer') + +const haveUsablePerformanceNow = semver.satisfies(process.version, '>=8.12.0') + +// SpanOptions.kind +// https://github.com/elastic/apm/blob/main/specs/agents/tracing-api-otel.md#span-kind +tracer.startSpan('sKindDefault').end() +tracer.startSpan('sKindInternal', { kind: otel.SpanKind.INTERNAL }).end() +tracer.startSpan('sKindServer', { kind: otel.SpanKind.SERVER }).end() +tracer.startSpan('sKindClient', { kind: otel.SpanKind.CLIENT }).end() +tracer.startSpan('sKindProducer', { kind: otel.SpanKind.PRODUCER }).end() +tracer.startSpan('sKindConsumer', { kind: otel.SpanKind.CONSUMER }).end() + +// SpanOptions.attributes +// https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/common/README.md#attribute +tracer.startSpan('sAttributesNone').end() +const myArray = ['hello', 'bob'] +tracer.startSpan('sAttributesLots', { + attributes: { + 'a.string': 'hi', + 'a.number': 42, + 'a.boolean': true, + 'an.array.of.strings': ['one', 'two', 'three'], + 'an.array.of.numbers': [1, 2, 3], + 'an.array.of.booleans': [true, false], + 'an.array.that.will.be.modified': myArray, + // Empty/falsey values: + 'a.zero': 0, + 'a.false': false, + 'an.empty.string': '', + 'an.empty.array': [], + // From the OTel spec: + // > `null` values SHOULD NOT be allowed in arrays. However, ... + // The OTel JS SDK allows nulls and undefineds. + 'an.array.with.nulls': ['one', null, 'three'], + 'an.array.with.undefineds': ['one', undefined, 'three'], + // These are *not* allowed by the OTel API: + 'an.array.of.mixed.types': [1, true, 'three', undefined, null], + 'an.object': { foo: 'bar' }, + 'a.null': null, + 'a.undefined': undefined, + '': 'empty string key' + } +}).end() +myArray[0] = 'goodbye' + +// SpanOptions.links +const s = tracer.startSpan('sLinksNone') +s.end() +tracer.startSpan('sLinksEmptyArray', { links: [] }).end() +tracer.startSpan('sLinksInvalid', { links: [{}] }).end() +tracer.startSpan('sLinks', { links: [{ context: s.spanContext() }] }).end() +tracer.startSpan('sLinksWithAttrs', { + links: [{ context: s.spanContext(), attributes: { 'a.string': 'hi', 'a.number': 42 } }] +}).end() + +// SpanOptions.startTime +// Specify approximately "now" in each of the supported TimeInput formats. +// OTel HrTime is `[, ]`. +const now = Date.now() +tracer.startSpan('sStartTimeHrTime', { startTime: [Math.floor(now / 1e3), (now % 1e3) * 1e6] }).end() +tracer.startSpan('sStartTimeEpochMs', { startTime: Date.now() }).end() +if (haveUsablePerformanceNow) { + tracer.startSpan('sStartTimePerformanceNow', { startTime: performance.now() }).end() +} +tracer.startSpan('sStartTimeDate', { startTime: new Date() }).end() + +// SpanOptions.root +const sParent = tracer.startSpan('sParent') +const parentCtx = otel.trace.setSpan(otel.context.active(), sParent) +otel.context.with(parentCtx, () => { + tracer.startSpan('sRootNotSpecified').end() + // This one should *not* have sParent as a parent. It should be a separate trace. + tracer.startSpan('sRoot', { root: true }).end() +}) +sParent.end() + +// tracer.startActiveSpan() +// - retval comes back +const retval = tracer.startActiveSpan('sActiveRetval', sActiveRetval => { + try { + return 42 + } finally { + sActiveRetval.end() + } +}) +assert.strictEqual(retval, 42, 'sActiveRetval') + +// - thrown error passes through +let thrownErr +try { + tracer.startActiveSpan('sActiveThrows', sActiveThrows => { + try { + throw new Error('inside sActiveThrows') + } finally { + sActiveThrows.end() + } + }) +} catch (err) { + thrownErr = err +} +assert.ok(thrownErr && thrownErr.message === 'inside sActiveThrows', 'sActiveThrows') + +// - async function +tracer.startActiveSpan('sActiveAsync', async (sActiveAsync) => { + await Promise.resolve() + sActiveAsync.end() + return 42 +}).then(rv => { + assert.strictEqual(rv, 42, 'sActiveAsync retval') +}) + +// - with options arg +tracer.startActiveSpan( + 'sActiveWithOptions', + { + kind: otel.SpanKind.CLIENT, + attributes: { + 'a.string': 'hi' + } + }, + sActiveWithOptions => { + try { + // ... + } finally { + sActiveWithOptions.end() + } + }) + +// - with context arg +const FOO_KEY = otel.createContextKey('foo') +const ctx = otel.context.active().setValue(FOO_KEY, 'bar') +tracer.startActiveSpan( + 'sActiveWithContext', + undefined, + ctx, + sActiveWithContext => { + assert.strictEqual(otel.context.active().getValue(FOO_KEY), 'bar', + 'FOO_KEY was passed through with context') + sActiveWithContext.end() + }) diff --git a/test/opentelemetry-bridge/fixtures/nonrecordingspan-parent.js b/test/opentelemetry-bridge/fixtures/nonrecordingspan-parent.js new file mode 100644 index 0000000000..f0f029337e --- /dev/null +++ b/test/opentelemetry-bridge/fixtures/nonrecordingspan-parent.js @@ -0,0 +1,44 @@ +'use strict' + +// Expect: +// transaction "s2" (trace_id=d4cda95b652f4a1592b449dd92ffda3b, parent_id=6e0c63ffe4e34c42) + +// This tests a case where the `Span` set on a Context is *not* an object +// created by the OTel Bridge code. Instead it is a `NonRecordingSpan` object +// created by `@opentelemetry/api` itself via: `otel.trace.wrapSpanContext()`. +// +// A practical use case is where user code is handling continuing a trace +// from manually extracted trace-context data. For example for bulk message +// reception: https://www.elastic.co/guide/en/apm/agent/nodejs/current/message-queues.html#message-queues-distributed-tracing + +const assert = require('assert') +const otel = require('@opentelemetry/api') +const { TraceState } = require('../../../lib/opentelemetry-bridge/opentelemetry-core-mini/trace/TraceState') + +const tracer = otel.trace.getTracer('test-nonrecordingspan-parent') + +// This creates a span `s1` that is a `NonRecordingSpan` -- an internal class +// in `@opentelemetry/api`. Notably, it isn't an `OTelSpan` instance created +// by our registered global Tracer. +const parentSpanContext = { + traceId: 'd4cda95b652f4a1592b449dd92ffda3b', + spanId: '6e0c63ffe4e34c42', + traceFlags: otel.TraceFlags.SAMPLED, + traceState: new TraceState('foo=bar') +} +const s1 = otel.trace.wrapSpanContext(parentSpanContext) // A "SAMPLED", but non-recording span. +assert(s1.isRecording() === false, 's1 is non-recording') +assert(s1.spanContext().traceFlags & otel.TraceFlags.SAMPLED, 's1 is sampled') + +// Then we use that NonRecordingSpan to test that the OTelBridge correctly +// propagates its SpanContext. +otel.context.with(otel.trace.setSpan(otel.context.active(), s1), () => { + const s2 = tracer.startSpan('s2') + assert(s2.isRecording(), 's2 is recording') + assert.strictEqual(s2.spanContext().traceId, parentSpanContext.traceId, 's2 traceId inherited from s1') + assert(s2.spanContext().traceFlags & otel.TraceFlags.SAMPLED, 's2 is sampled') + assert.strictEqual(s2.spanContext().traceState.get('foo'), 'bar', 's2 tracestate inherited from s1') + assert.strictEqual(s2.parentSpanId /* OTel SDK */ || s2._span.parentId /* Elastic APM */, + parentSpanContext.spanId, 's2 parent is s1') + s2.end() +}) diff --git a/test/opentelemetry-bridge/fixtures/start-active-span.js b/test/opentelemetry-bridge/fixtures/start-active-span.js new file mode 100644 index 0000000000..bee256f9ed --- /dev/null +++ b/test/opentelemetry-bridge/fixtures/start-active-span.js @@ -0,0 +1,22 @@ +// Expect: +// transaction "s1" (outcome=unknown) +// `- span "s2" (outcome=unknown) + +'use strict' +const assert = require('assert') +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('test-start-span') + +tracer.startActiveSpan('s1', s1 => { + assert.deepStrictEqual( + otel.trace.getSpan(otel.context.active()).spanContext(), + s1.spanContext(), 's1 is active') + + tracer.startActiveSpan('s2', s2 => { + assert.deepStrictEqual( + otel.trace.getSpan(otel.context.active()).spanContext(), + s2.spanContext(), 's2 is active') + s2.end() + }) + s1.end() +}) diff --git a/test/opentelemetry-bridge/fixtures/start-span-with-context.js b/test/opentelemetry-bridge/fixtures/start-span-with-context.js new file mode 100644 index 0000000000..45a83e9c3a --- /dev/null +++ b/test/opentelemetry-bridge/fixtures/start-span-with-context.js @@ -0,0 +1,64 @@ +'use strict' + +// Expect: +// trace +// `- transaction "s1" +// `- span "s3" +// `- span "s5" +// `- transaction "s4" +// `- span "s6" +// trace +// `- transaction "s2" + +// Test `Tracer.startSpan(...)` with various cases for the `context` argument. + +const assert = require('assert') + +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('test-start-span-with-context') + +function parentIdFromSpan (span) { + return ( + span.parentSpanId || // OTel SDK + (span._span && span._span.parentId) || // Elastic APM + undefined + ) +} +function idFromSpan (span) { + return span.spanContext().spanId +} + +const s1 = tracer.startSpan('s1') // Transaction 's1' +assert.strictEqual(parentIdFromSpan(s1), undefined, 's1 has no parent') + +const s2 = tracer.startSpan('s2') +assert.strictEqual(parentIdFromSpan(s2), undefined, 's2 has no parent') +s2.end() + +let ctx = otel.trace.setSpan(otel.context.active(), s1) +const s3 = tracer.startSpan('s3', {}, ctx) +assert.strictEqual(parentIdFromSpan(s3), idFromSpan(s1), 's3 is child of s1') +s3.end() + +// Create a context via `setSpanContext`, which under the hood is quite +// different. The "span" set on ctx here is *not* s1, but is a NonRecordingSpan +// with its same trace-context details. +// Note: With the OTel Bridge, s4 becomes a *transaction* rather than a span. +ctx = otel.trace.setSpanContext(otel.context.active(), s1.spanContext()) +const s4 = tracer.startSpan('s4', {}, ctx) +assert.strictEqual(parentIdFromSpan(s4), idFromSpan(s1), 's4 is child of s1') +s4.end() + +// Creating context and child span after parent s3 (a span) has ended. +ctx = otel.trace.setSpan(otel.context.active(), s3) +const s5 = tracer.startSpan('s5', {}, ctx) +assert.strictEqual(parentIdFromSpan(s5), idFromSpan(s3), 's5 is child of s3') +s5.end() + +s1.end() + +// Creating context and child span after parent s1 (a transaction) has ended. +ctx = otel.trace.setSpan(otel.context.active(), s1) +const s6 = tracer.startSpan('s6', {}, ctx) +assert.strictEqual(parentIdFromSpan(s6), idFromSpan(s1), 's6 is child of s1') +s6.end() diff --git a/test/opentelemetry-bridge/fixtures/start-span.js b/test/opentelemetry-bridge/fixtures/start-span.js new file mode 100644 index 0000000000..30d8d13b5a --- /dev/null +++ b/test/opentelemetry-bridge/fixtures/start-span.js @@ -0,0 +1,17 @@ +// Expect: +// transaction "mySpan" + +'use strict' +let assert = require('assert') +if (Number(process.versions.node.split('.')[0]) > 8) { + assert = assert.strict +} +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('test-start-span') + +const s = tracer.startSpan('mySpan') + +// OTel's startSpan does *not* make the span active/current. +assert.ok(otel.trace.getSpan(otel.context.active()) === undefined, 'no active span') + +s.end() diff --git a/test/opentelemetry-bridge/fixtures/using-root-context.js b/test/opentelemetry-bridge/fixtures/using-root-context.js new file mode 100644 index 0000000000..36b1a65844 --- /dev/null +++ b/test/opentelemetry-bridge/fixtures/using-root-context.js @@ -0,0 +1,43 @@ +'use strict' + +// Expect: +// transaction "s2" (trace_id=d4cda95b652f4a1592b449dd92ffda3b, parent_id=6e0c63ffe4e34c42) + +// This tests context propagation with direct usage of `otel.ROOT_CONTEXT`. +// +// This is an "interesting" case to test because `otel.ROOT_CONTEXT` and +// `Context` objects derived from it are a class implemented in +// `@opentelemetry/api` that cannot be overriden. This is as opposed to +// `Context` objects derived from `api.context.active()` -- which calls into +// the global ContextManager for creation. + +const assert = require('assert') +const otel = require('@opentelemetry/api') +const tracer = otel.trace.getTracer('test-using-root-context') + +const parentSpanContext = { + traceId: 'd4cda95b652f4a1592b449dd92ffda3b', + spanId: '6e0c63ffe4e34c42', + traceFlags: otel.TraceFlags.SAMPLED +} +const s1 = otel.trace.wrapSpanContext(parentSpanContext) + +let ctx +ctx = otel.trace.setSpan(otel.ROOT_CONTEXT, s1) // -> BaseContext + +// Also set an arbitrary value on the Context to test that it is properly +// propagated. +const FOO_KEY = otel.createContextKey('foo') +ctx = ctx.setValue(FOO_KEY, 'bar') + +otel.context.with(ctx, () => { + assert.strictEqual(otel.context.active().getValue(FOO_KEY), 'bar', + 'the active context has our FOO_KEY value') + + const s2 = tracer.startSpan('s2') + assert(s2.isRecording() === true, 's2 is recording') + assert.strictEqual(s2.spanContext().traceId, parentSpanContext.traceId, 's2 traceId inherited from s1') + assert.strictEqual(s2.parentSpanId /* OTel SDK */ || s2._span.parentId /* Elastic APM */, + parentSpanContext.spanId, 's2 parent is s1') + s2.end() +}) diff --git a/test/opentelemetry-bridge/interface-ContextManager.test.js b/test/opentelemetry-bridge/interface-ContextManager.test.js new file mode 100644 index 0000000000..e23988e117 --- /dev/null +++ b/test/opentelemetry-bridge/interface-ContextManager.test.js @@ -0,0 +1,121 @@ +'use strict' + +// Exercise the full `interface ContextManager`. + +require('../..').start({ + opentelemetryBridgeEnabled: true, + // Make the agent quiet. + disableSend: true, + centralConfig: false, + cloudProvider: 'none', + metricsInterval: '0s', + captureExceptions: false, + logLevel: 'off' +}) + +const otel = require('@opentelemetry/api') +const tape = require('tape') +const EventEmitter = require('events') + +const FOO_KEY = otel.createContextKey('FOO') +const tracer = otel.trace.getTracer('test-interface-ContextManager') + +tape.test('ContextManager.active()', t => { + tracer.startActiveSpan('aSpan', aSpan => { + const currSpan = otel.trace.getSpan(otel.context.active()) + t.deepEqual(currSpan.spanContext(), aSpan.spanContext()) + aSpan.end() + t.end() + }) +}) + +tape.test('ContextManager.with(context, fn, thisArg?, ...args)', t => { + const s1 = tracer.startSpan('s1') + const ctx = otel.trace.setSpan(otel.context.active(), s1).setValue(FOO_KEY, 'bar') + const thisArg = { aProp: 'aPropVal' } + const fn = function (one, two, three) { + const activeCtx = otel.context.active() + t.strictEqual(activeCtx, ctx, 'active context') + t.strictEqual(activeCtx.getValue(FOO_KEY), 'bar', 'FOO_KEY in active context') + t.strictEqual(this, thisArg, 'thisArg') + t.strictEqual(one, 1, 'arg 1') + t.strictEqual(two, 2, 'arg 2') + t.strictEqual(three, 3, 'arg 3') + t.strictEqual(arguments[3], 4, 'arg 4') + return 'theRetval' + } + + const retval = otel.context.with(ctx, fn, thisArg, 1, 2, 3, 4) + t.strictEqual(retval, 'theRetval', 'fn return value') + t.end() +}) + +tape.test('ContextManager.bind(context, fn)', suite => { + suite.test('should return the same thing if not a function or EventEmitter', t => { + const notAFn = { foo: 'bar' } + const bound = otel.context.bind(otel.context.active(), notAFn) + t.strictEqual(bound, notAFn) + t.end() + }) + + suite.test('should bind a function to given context', t => { + const ctx = otel.context.active().setValue(FOO_KEY, 'bar') + const fn = function () { + t.strictEqual(otel.context.active(), ctx, 'active context in bound fn') + return 'theRetval' + } + const bound = otel.context.bind(ctx, fn) + const retval = bound() + t.strictEqual(retval, 'theRetval', 'fn return value') + t.end() + }) + + suite.end() +}) + +tape.test('ContextManager.bind(context, eventEmitter)', suite => { + suite.test('should bind a function to given EventEmitter, removeListeners works', t => { + t.plan(2) + const ctx = otel.context.active().setValue(FOO_KEY, 'bar') + const ee = new EventEmitter() + const boundEE = otel.context.bind(ctx, ee) + const handler = () => { + t.strictEqual(otel.context.active(), ctx, 'active context in bound fn') + } + boundEE.on('anEvent', handler) + boundEE.emit('anEvent') + boundEE.emit('anEvent') + boundEE.removeListener('anEvent', handler) + boundEE.emit('anEvent') // should not call the handler, hence t.plan(2) + t.end() + }) + + suite.test('same handler on multiple events works', t => { + t.plan(2) + const ctx = otel.context.active().setValue(FOO_KEY, 'bar') + const ee = new EventEmitter() + const boundEE = otel.context.bind(ctx, ee) + const handler = () => { + t.strictEqual(otel.context.active(), ctx, 'active context in bound fn') + } + boundEE.on('event1', handler) + boundEE.on('event2', handler) + boundEE.emit('event1') + boundEE.emit('event2') + boundEE.removeListener('event1', handler) + boundEE.removeListener('event2', handler) + boundEE.emit('event1') + boundEE.emit('event2') + t.end() + }) + + suite.end() +}) + +// Basically just testing that this doesn't blow up. `ContextManager.enable()` +// isn't exposed in the public `@opentelemetry/api` directly, so that isn't +// tested here. +tape.test('ContextManager.disable()', t => { + otel.context.disable() + t.end() +}) diff --git a/test/opentelemetry-bridge/otel-bridge-feature.test.js b/test/opentelemetry-bridge/otel-bridge-feature.test.js new file mode 100644 index 0000000000..bd7096a0a1 --- /dev/null +++ b/test/opentelemetry-bridge/otel-bridge-feature.test.js @@ -0,0 +1,557 @@ +'use strict' + +// Test functionality described in: +// https://github.com/elastic/apm/blob/main/tests/agents/gherkin-specs/otel_bridge.feature#L30 +// https://github.com/elastic/apm/blob/main/specs/agents/tracing-api-otel.md#compatibility-mapping +// +// See https://github.com/elastic/apm-agent-nodejs/pull/2672 for why we aren't +// testing with the Gherkin .feature files directly. + +const otel = require('@opentelemetry/api') +const tape = require('tape') + +const Agent = require('../../lib/agent') +const { OUTCOME_UNKNOWN, OUTCOME_SUCCESS, OUTCOME_FAILURE } = require('../../lib/constants') +const { MockAPMServer } = require('../_mock_apm_server') + +tape.test('APM Server Handled in "nonrecordingspan-parent.js". + + // Scenario: Create root transaction from OTel span without parent + // -> Handled in "start-span.js". + + // Scenario: Create span from OTel span + // -> Handled in "start-active-span.js". + + suite.test('Scenario Outline: OTel span kind for spans & default span type & subtype', function (t) { + const examples = [ + { kind: otel.SpanKind.INTERNAL, type: 'app', subtype: 'internal' }, + { kind: otel.SpanKind.SERVER, type: 'unknown', subtype: null }, + { kind: otel.SpanKind.CLIENT, type: 'unknown', subtype: null }, + { kind: otel.SpanKind.PRODUCER, type: 'unknown', subtype: null }, + { kind: otel.SpanKind.CONSUMER, type: 'unknown', subtype: null } + ] + tracer.startActiveSpan('aTrans', aTrans => { + examples.forEach((ex, idx) => { + tracer.startSpan(`s${idx}`, { kind: ex.kind }).end() + }) + aTrans.end() + }) + + agent.flush(function () { + const spans = apmServer.events + .filter(e => e.span) + .map(e => e.span) + .sort((a, b) => a.name - b.name) // Cannot use "timestamp" for sorting, because #2180. + t.equal(spans.length, examples.length, `got ${examples.length} spans`) + for (let i = 0; i < examples.length; i++) { + const ex = examples[i] + const span = spans[i] + t.ok(span, 'Then Elastic bridged object is a span') + t.equal(span.otel.span_kind, otel.SpanKind[ex.kind], 'Then Elastic bridged span OTel kind is ""') + t.equal(span.type, ex.type, 'Then Elastic bridged span type is ""') + t.equal(span.subtype, ex.subtype, 'Then Elastic bridged span subtype is ""') + } + + apmServer.clear() + t.end() + }) + }) + + suite.test('Scenario Outline: OTel span kind for transactions & default transaction type', function (t) { + const examples = [ + { kind: otel.SpanKind.INTERNAL }, + { kind: otel.SpanKind.SERVER }, + { kind: otel.SpanKind.CLIENT }, + { kind: otel.SpanKind.PRODUCER }, + { kind: otel.SpanKind.CONSUMER } + ] + examples.forEach((ex, idx) => { + tracer.startSpan(`s${idx}`, { kind: ex.kind }).end() + }) + + agent.flush(function () { + const transactions = apmServer.events + .filter(e => e.transaction) + .map(e => e.transaction) + .sort((a, b) => a.name - b.name) // Cannot use "timestamp" for sorting, because #2180. + t.equal(transactions.length, examples.length, `got ${examples.length} transactions`) + for (let i = 0; i < examples.length; i++) { + const ex = examples[i] + const trans = transactions[i] + t.ok(trans, 'Then Elastic bridged object is a transaction') + t.equal(trans.otel.span_kind, otel.SpanKind[ex.kind], 'Then Elastic bridged transaction OTel kind is ""') + t.equal(trans.type, 'unknown', 'Then Elastic bridged transaction type is "unknown"') + } + + apmServer.clear() + t.end() + }) + }) + + suite.test('Scenario Outline: OTel span mapping with status for transactions', function (t) { + const examples = [ + { status: otel.SpanStatusCode.UNSET, outcome: OUTCOME_UNKNOWN }, + { status: otel.SpanStatusCode.OK, outcome: OUTCOME_SUCCESS }, + { status: otel.SpanStatusCode.ERROR, outcome: OUTCOME_FAILURE } + ] + examples.forEach((ex, idx) => { + tracer.startSpan(`s${idx}`).setStatus(ex.status).end() + }) + + agent.flush(function () { + const transactions = apmServer.events + .filter(e => e.transaction) + .map(e => e.transaction) + .sort((a, b) => a.name - b.name) // Cannot use "timestamp" for sorting, because #2180. + t.equal(transactions.length, examples.length, `got ${examples.length} transactions`) + for (let i = 0; i < examples.length; i++) { + const ex = examples[i] + const trans = transactions[i] + t.ok(trans, 'Then Elastic bridged object is a transaction') + t.equal(trans.outcome, ex.outcome, 'Then Elastic bridged transaction outcome is ""') + } + + apmServer.clear() + t.end() + }) + }) + + suite.test('Scenario Outline: OTel span mapping with status for spans', function (t) { + const examples = [ + { status: otel.SpanStatusCode.UNSET, outcome: OUTCOME_UNKNOWN }, + { status: otel.SpanStatusCode.OK, outcome: OUTCOME_SUCCESS }, + { status: otel.SpanStatusCode.ERROR, outcome: OUTCOME_FAILURE } + ] + tracer.startActiveSpan('aTrans', aTrans => { + examples.forEach((ex, idx) => { + tracer.startSpan(`s${idx}`).setStatus(ex.status).end() + }) + aTrans.end() + }) + + agent.flush(function () { + const spans = apmServer.events + .filter(e => e.span) + .map(e => e.span) + .sort((a, b) => a.name - b.name) // Cannot use "timestamp" for sorting, because #2180. + t.equal(spans.length, examples.length, `got ${examples.length} spans`) + for (let i = 0; i < examples.length; i++) { + const ex = examples[i] + const span = spans[i] + t.ok(span, 'Then Elastic bridged object is a span') + t.equal(span.outcome, ex.outcome, 'Then Elastic bridged span outcome is ""') + } + + apmServer.clear() + t.end() + }) + }) + + suite.test('Scenario Outline: HTTP server [ ]', function (t) { + const examples = [ + { attributes: { 'http.url': 'http://testing.invalid/' } }, + { attributes: { 'http.scheme': 'http' } } + ] + examples.forEach((ex, idx) => { + tracer.startSpan(`s${idx}`, { kind: otel.SpanKind.SERVER, attributes: ex.attributes }).end() + }) + + agent.flush(function () { + const transactions = apmServer.events + .filter(e => e.transaction) + .map(e => e.transaction) + .sort((a, b) => a.name - b.name) // Cannot use "timestamp" for sorting, because #2180. + t.equal(transactions.length, examples.length, `got ${examples.length} transactions`) + for (let i = 0; i < examples.length; i++) { + const trans = transactions[i] + t.ok(trans, 'Then Elastic bridged object is a transaction') + t.equal(trans.type, 'request', 'Then Elastic bridged transaction type is "request"') + } + + apmServer.clear() + t.end() + }) + }) + + // https://github.com/elastic/apm/blob/fc0a725/tests/agents/gherkin-specs/otel_bridge.feature#L111-L139 + suite.test('Scenario Outline: HTTP client [ ]', function (t) { + const examples = [ + { + attributes: { 'http.url': 'https://testing.invalid:8443/' }, + resource: 'testing.invalid:8443' + }, + { + attributes: { 'http.url': 'https://[::1]/' }, + resource: '[::1]:443' + }, + { + attributes: { 'http.url': 'http://testing.invalid/' }, + resource: 'testing.invalid:80' + }, + { + attributes: { 'http.scheme': 'http', 'http.host': 'testing.invalid' }, + resource: 'testing.invalid:80' + }, + { + attributes: { 'http.scheme': 'https', 'http.host': 'testing.invalid', 'net.peer.ip': '127.0.0.1' }, + resource: 'testing.invalid:443' + }, + { + attributes: { 'http.scheme': 'http', 'net.peer.ip': '127.0.0.1', 'net.peer.port': '81' }, + resource: '127.0.0.1:81' + }, + { + attributes: { 'http.scheme': 'https', 'net.peer.ip': '127.0.0.1', 'net.peer.port': '445' }, + resource: '127.0.0.1:445' + }, + { + attributes: { 'http.scheme': 'http', 'net.peer.ip': '127.0.0.1', 'net.peer.name': 'host1', 'net.peer.port': '445' }, + resource: 'host1:445' + }, + { + attributes: { 'http.scheme': 'https', 'net.peer.ip': '127.0.0.1', 'net.peer.name': 'host2', 'net.peer.port': '445' }, + resource: 'host2:445' + } + ] + tracer.startActiveSpan('aTrans', aTrans => { + examples.forEach((ex, idx) => { + tracer.startSpan(`s${idx}`, { kind: otel.SpanKind.CLIENT, attributes: ex.attributes }).end() + }) + aTrans.end() + }) + + agent.flush(function () { + const spans = apmServer.events + .filter(e => e.span) + .map(e => e.span) + .sort((a, b) => a.name - b.name) // Cannot use "timestamp" for sorting, because #2180. + t.equal(spans.length, examples.length, `got ${examples.length} spans`) + for (let i = 0; i < examples.length; i++) { + const ex = examples[i] + const span = spans[i] + t.equal(span.type, 'external', 'Then Elastic bridged span type is "external"') + t.equal(span.subtype, 'http', 'Then Elastic bridged span subtype is "http"') + t.deepEqual(span.otel.attributes, ex.attributes, 'Then Elastic bridged span OTel attributes are copied as-is') + t.equal(span.context.destination.service.resource, ex.resource, 'Then Elastic bridged span destination resource is set to ""') + } + + apmServer.clear() + t.end() + }) + }) + + suite.test('Scenario Outline: DB client [ ]', function (t) { + const examples = [ + { + attributes: { 'db.system': 'mysql' }, + resource: 'mysql' + }, + { + attributes: { 'db.system': 'oracle', 'net.peer.name': 'oracledb' }, + resource: 'oracledb' + }, + { + attributes: { 'db.system': 'oracle', 'net.peer.ip': '127.0.0.1' }, + resource: '127.0.0.1' + }, + { + attributes: { 'db.system': 'mysql', 'net.peer.ip': '127.0.0.1', 'net.peer.name': 'dbserver', 'net.peer.port': '3307' }, + resource: 'dbserver:3307' + }, + { + attributes: { 'db.system': 'mysql', 'db.name': 'myDb' }, + resource: 'mysql/myDb' + }, + { + attributes: { 'db.system': 'oracle', 'db.name': 'myDb', 'net.peer.name': 'oracledb' }, + resource: 'oracledb/myDb' + }, + { + attributes: { 'db.system': 'oracle', 'db.name': 'myDb', 'net.peer.ip': '127.0.0.1' }, + resource: '127.0.0.1/myDb' + }, + { + attributes: { 'db.system': 'mysql', 'db.name': 'myDb', 'net.peer.ip': '127.0.0.1', 'net.peer.name': 'dbserver', 'net.peer.port': '3307' }, + resource: 'dbserver:3307/myDb' + } + ] + tracer.startActiveSpan('aTrans', aTrans => { + examples.forEach((ex, idx) => { + tracer.startSpan(`s${idx}`, { kind: otel.SpanKind.CLIENT, attributes: ex.attributes }).end() + }) + aTrans.end() + }) + + agent.flush(function () { + const spans = apmServer.events + .filter(e => e.span) + .map(e => e.span) + .sort((a, b) => a.name - b.name) // Cannot use "timestamp" for sorting, because #2180. + t.equal(spans.length, examples.length, `got ${examples.length} spans`) + for (let i = 0; i < examples.length; i++) { + const ex = examples[i] + const span = spans[i] + t.equal(span.type, 'db', 'Then Elastic bridged span type is "db"') + t.equal(span.subtype, ex.attributes['db.system'], 'Then Elastic bridged span subtype is ""') + t.deepEqual(span.otel.attributes, ex.attributes, 'Then Elastic bridged span OTel attributes are copied as-is') + t.equal(span.context.destination.service.resource, ex.resource, 'Then Elastic bridged span destination resource is set to ""') + } + + apmServer.clear() + t.end() + }) + }) + + // Scenario: Messaging consumer + suite.test('Scenario: Messaging consumer', function (t) { + tracer.startSpan('aSpan', { + kind: otel.SpanKind.CONSUMER, + attributes: { 'messaging.system': 'anything' } + }).end() + + agent.flush(function () { + t.equal(apmServer.events.length, 2, 'got 2 events') + const trans = apmServer.events[1].transaction + t.equal(trans.type, 'messaging', 'Then Elastic bridged transaction type is "messaging"') + + apmServer.clear() + t.end() + }) + }) + + suite.test('Scenario Outline: Messaging producer [ ]', function (t) { + const examples = [ + { + attributes: { + 'messaging.system': 'rabbitmq', + 'messaging.url': 'amqp://carrot:4444/q1' + }, + resource: 'carrot:4444' + }, + { + attributes: { + 'messaging.system': 'rabbitmq', + 'net.peer.ip': '127.0.0.1', + 'net.peer.name': 'carrot-server', + 'net.peer.port': '7777' + }, + resource: 'carrot-server:7777' + }, + { + attributes: { + 'messaging.system': 'rabbitmq', + 'net.peer.name': 'carrot-server' + }, + resource: 'carrot-server' + }, + { + attributes: { + 'messaging.system': 'rabbitmq', + 'net.peer.ip': '127.0.0.1' + }, + resource: '127.0.0.1' + }, + { + attributes: { + 'messaging.system': 'rabbitmq', + 'messaging.destination': 'myQueue', + 'messaging.url': 'amqp://carrot:4444/q1 ' + }, + resource: 'carrot:4444/myQueue' + }, + { + attributes: { + 'messaging.system': 'rabbitmq', + 'messaging.destination': 'myQueue', + 'net.peer.ip': '127.0.0.1', + 'net.peer.name': 'carrot-server', + 'net.peer.port': '7777' + }, + resource: 'carrot-server:7777/myQueue' + }, + { + attributes: { + 'messaging.system': 'rabbitmq', + 'messaging.destination': 'myQueue', + 'net.peer.name': 'carrot-server' + }, + resource: 'carrot-server/myQueue' + }, + { + attributes: { + 'messaging.system': 'rabbitmq', + 'messaging.destination': 'myQueue', + 'net.peer.ip': '127.0.0.1' + }, + resource: '127.0.0.1/myQueue' + } + + ] + tracer.startActiveSpan('aTrans', aTrans => { + examples.forEach((ex, idx) => { + tracer.startSpan(`s${idx}`, { kind: otel.SpanKind.PRODUCER, attributes: ex.attributes }).end() + }) + aTrans.end() + }) + + agent.flush(function () { + const spans = apmServer.events + .filter(e => e.span) + .map(e => e.span) + .sort((a, b) => a.name - b.name) // Cannot use "timestamp" for sorting, because #2180. + t.equal(spans.length, examples.length, `got ${examples.length} spans`) + for (let i = 0; i < examples.length; i++) { + const ex = examples[i] + const span = spans[i] + t.equal(span.type, 'messaging', 'Then Elastic bridged span type is "messaging"') + t.equal(span.subtype, ex.attributes['messaging.system'], 'Then Elastic bridged span subtype is ""') + t.deepEqual(span.otel.attributes, ex.attributes, 'Then Elastic bridged span OTel attributes are copied as-is') + t.equal(span.context.destination.service.resource, ex.resource, 'Then Elastic bridged span destination resource is set to ""') + } + + apmServer.clear() + t.end() + }) + }) + + suite.test('Scenario Outline: RPC client [ ]', function (t) { + const examples = [ + { + attributes: { + 'rpc.system': 'grpc' + }, + resource: 'grpc' + }, + { + attributes: { + 'rpc.system': 'grpc', + 'rpc.service': 'myService' + }, + resource: 'grpc/myService' + }, + { + attributes: { + 'rpc.system': 'grpc', + 'rpc.service': 'myService', + 'net.peer.name': 'rpc-server' + }, + resource: 'rpc-server/myService' + }, + { + attributes: { + 'rpc.system': 'grpc', + 'rpc.service': 'myService', + 'net.peer.ip': '127.0.0.1', + 'net.peer.name': 'rpc-server' + }, + resource: 'rpc-server/myService' + }, + { + attributes: { + 'rpc.system': 'grpc', + 'net.peer.ip': '127.0.0.1', + 'net.peer.name': 'rpc-server', + 'net.peer.port': '7777' + }, + resource: 'rpc-server:7777' + }, + { + attributes: { + 'rpc.system': 'grpc', + 'rpc.service': 'myService', + 'net.peer.ip': '127.0.0.1', + 'net.peer.name': 'rpc-server', + 'net.peer.port': '7777' + }, + resource: 'rpc-server:7777/myService' + }, + { + attributes: { + 'rpc.system': 'grpc', + 'rpc.service': 'myService', + 'net.peer.ip': '127.0.0.1', + 'net.peer.port': '7777' + }, + resource: '127.0.0.1:7777/myService' + } + ] + tracer.startActiveSpan('aTrans', aTrans => { + examples.forEach((ex, idx) => { + tracer.startSpan(`s${idx}`, { kind: otel.SpanKind.CLIENT, attributes: ex.attributes }).end() + }) + aTrans.end() + }) + + agent.flush(function () { + const spans = apmServer.events + .filter(e => e.span) + .map(e => e.span) + .sort((a, b) => a.name - b.name) // Cannot use "timestamp" for sorting, because #2180. + t.equal(spans.length, examples.length, `got ${examples.length} spans`) + for (let i = 0; i < examples.length; i++) { + const ex = examples[i] + const span = spans[i] + t.equal(span.type, 'external', 'Then Elastic bridged span type is "external"') + t.equal(span.subtype, ex.attributes['rpc.system'], 'Then Elastic bridged span subtype is ""') + t.deepEqual(span.otel.attributes, ex.attributes, 'Then Elastic bridged span OTel attributes are copied as-is') + t.equal(span.context.destination.service.resource, ex.resource, 'Then Elastic bridged span destination resource is set to ""') + } + + apmServer.clear() + t.end() + }) + }) + + // Scenario: RPC server + suite.test('Scenario: RPC server', function (t) { + tracer.startSpan('aSpan', { + kind: otel.SpanKind.SERVER, + attributes: { 'rpc.system': 'grpc' } + }).end() + + agent.flush(function () { + t.equal(apmServer.events.length, 2, 'got 2 events') + const trans = apmServer.events[1].transaction + t.equal(trans.type, 'request', 'Then Elastic bridged transaction type is "request"') + + apmServer.clear() + t.end() + }) + }) + + suite.test('teardown', function (t) { + agent.destroy() + apmServer.close() + t.end() + }) + + suite.end() +})