From f891a4d3b1983d0bfebbf0a995a4e22e8d8f02ae Mon Sep 17 00:00:00 2001 From: Vera Reynolds Date: Sat, 12 Jun 2021 17:45:28 -0600 Subject: [PATCH 1/2] feat(shim-opentracing): update logging based on new spec * use event name when available * map error attributes to semantic conventions * use provided timestamp * fix shim example: runtime error and missing service.name --- examples/opentracing-shim/package.json | 2 + examples/opentracing-shim/server.js | 2 +- examples/opentracing-shim/shim.js | 15 +-- .../package.json | 1 + .../src/shim.ts | 65 ++++++++++--- .../test/Shim.test.ts | 97 ++++++++++++++++--- .../tsconfig.json | 3 + 7 files changed, 154 insertions(+), 31 deletions(-) diff --git a/examples/opentracing-shim/package.json b/examples/opentracing-shim/package.json index 4eac185b91..3b082ad20f 100644 --- a/examples/opentracing-shim/package.json +++ b/examples/opentracing-shim/package.json @@ -33,6 +33,8 @@ "@opentelemetry/exporter-zipkin": "0.21.0", "@opentelemetry/instrumentation": "0.21.0", "@opentelemetry/node": "0.21.0", + "@opentelemetry/resources": "0.21.0", + "@opentelemetry/semantic-conventions": "0.21.0", "@opentelemetry/shim-opentracing": "0.21.0", "@opentelemetry/tracing": "0.21.0", "opentracing": "^0.14.4" diff --git a/examples/opentracing-shim/server.js b/examples/opentracing-shim/server.js index cf54c646fb..a21f93a149 100644 --- a/examples/opentracing-shim/server.js +++ b/examples/opentracing-shim/server.js @@ -37,7 +37,7 @@ async function handleRequest(req, res) { res.writeHead(200, { 'Content-Type': 'application/json' }); res.write( - JSON.stringify({ status: 'OK', traceId: span.spanContext().toTraceId() }), + JSON.stringify({ status: 'OK', traceId: span.context().toTraceId() }), ); res.end(); diff --git a/examples/opentracing-shim/shim.js b/examples/opentracing-shim/shim.js index 31a71d9a21..729f7165b5 100644 --- a/examples/opentracing-shim/shim.js +++ b/examples/opentracing-shim/shim.js @@ -1,5 +1,7 @@ 'use strict'; +const { ResourceAttributes } = require('@opentelemetry/semantic-conventions'); +const { Resource } = require('@opentelemetry/resources'); const { registerInstrumentations } = require('@opentelemetry/instrumentation'); const { NodeTracerProvider } = require('@opentelemetry/node'); const { SimpleSpanProcessor } = require('@opentelemetry/tracing'); @@ -8,26 +10,27 @@ const { ZipkinExporter } = require('@opentelemetry/exporter-zipkin'); const { TracerShim } = require('@opentelemetry/shim-opentracing'); function shim(serviceName) { - const provider = new NodeTracerProvider(); + const provider = new NodeTracerProvider({ + resource: new Resource({ [ResourceAttributes.SERVICE_NAME]: serviceName }), + }); provider.addSpanProcessor(new SimpleSpanProcessor(getExporter(serviceName))); // Initialize the OpenTelemetry APIs to use the NodeTracerProvider bindings provider.register(); - registerInstrumentations({ - }); + registerInstrumentations({}); return new TracerShim(provider.getTracer('opentracing-shim')); } -function getExporter(serviceName) { +function getExporter() { const type = process.env.EXPORTER.toLowerCase() || 'jaeger'; if (type.startsWith('z')) { - return new ZipkinExporter({ serviceName }); + return new ZipkinExporter(); } - return new JaegerExporter({ serviceName, flushInterval: 100 }); + return new JaegerExporter(); } exports.shim = shim; diff --git a/packages/opentelemetry-shim-opentracing/package.json b/packages/opentelemetry-shim-opentracing/package.json index a7f5c25afe..d86f08d38c 100644 --- a/packages/opentelemetry-shim-opentracing/package.json +++ b/packages/opentelemetry-shim-opentracing/package.json @@ -57,6 +57,7 @@ }, "dependencies": { "@opentelemetry/core": "0.21.0", + "@opentelemetry/semantic-conventions": "0.21.0", "opentracing": "^0.14.4" } } diff --git a/packages/opentelemetry-shim-opentracing/src/shim.ts b/packages/opentelemetry-shim-opentracing/src/shim.ts index 0e4a890b6b..482fe9c56c 100644 --- a/packages/opentelemetry-shim-opentracing/src/shim.ts +++ b/packages/opentelemetry-shim-opentracing/src/shim.ts @@ -15,13 +15,9 @@ */ import * as api from '@opentelemetry/api'; +import { SpanAttributes, SpanAttributeValue, SpanStatusCode, TextMapPropagator } from '@opentelemetry/api'; import * as opentracing from 'opentracing'; -import { - SpanAttributes, - SpanAttributeValue, - SpanStatusCode, - TextMapPropagator, -} from '@opentelemetry/api'; +import { SemanticAttributes } from "@opentelemetry/semantic-conventions"; function translateReferences(references: opentracing.Reference[]): api.Link[] { const links: api.Link[] = []; @@ -96,14 +92,14 @@ export class SpanContextShim extends opentracing.SpanContext { /** * Returns the trace ID as a string. */ - override toTraceId(): string { + override toTraceId(): string { return this._spanContext.traceId; } /** * Returns the span ID as a string. */ - override toSpanId(): string { + override toSpanId(): string { return this._spanContext.spanId; } @@ -281,19 +277,62 @@ export class SpanShim extends opentracing.Span { * @param payload an arbitrary object to be attached to the event. */ override logEvent(eventName: string, payload?: SpanAttributes): void { - this._span.addEvent(eventName, payload); + this._logInternal(eventName, payload); } /** * Logs a set of key value pairs. Since OpenTelemetry only supports events, - * the KV pairs are used as attributes on an event named "log". + * the KV pairs are used as attributes on a Span event. + * @param keyValuePairs a set of key-value pairs to be used as event attributes + * @param timestamp optional timestamp for the event */ - override log(keyValuePairs: SpanAttributes, _timestamp?: number): this { - // @todo: Handle timestamp - this._span.addEvent('log', keyValuePairs); + override log(keyValuePairs: SpanAttributes, timestamp?: number): this { + const entries = Object.entries(keyValuePairs); + const eventEntry = entries.find(([key, _]) => key === 'event'); + const eventName = eventEntry?.[1] || 'log'; + const name = eventName.toString(); + + this._logInternal(name, keyValuePairs, timestamp); return this; } + private _logInternal(eventName: string, attributes: SpanAttributes | undefined, timestamp?: number): void { + if (attributes && eventName === 'error') { + const entries = Object.entries(attributes); + const errorEntry = entries.find(([key]) => key === 'error.object'); + const error = errorEntry?.[1]; + if (typeof error === "string") { + this._span.recordException(error, timestamp); + return; + } + + const mappedAttributes: api.SpanAttributes = {}; + for (const [k, v] of entries) { + switch (k) { + case "error.kind": { + mappedAttributes[SemanticAttributes.EXCEPTION_TYPE] = v; + break; + } + case "message": { + mappedAttributes[SemanticAttributes.EXCEPTION_MESSAGE] = v; + break; + } + case "stack": { + mappedAttributes[SemanticAttributes.EXCEPTION_STACKTRACE] = v; + break; + } + default: { + mappedAttributes[k] = v; + break; + } + } + } + this._span.addEvent('exception', mappedAttributes, timestamp); + return; + } + this._span.addEvent(eventName, attributes, timestamp); + } + /** * Adds a set of tags to the span. * @param keyValueMap set of KV pairs representing tags diff --git a/packages/opentelemetry-shim-opentracing/test/Shim.test.ts b/packages/opentelemetry-shim-opentracing/test/Shim.test.ts index c8bcd2f92b..882ebe3ca1 100644 --- a/packages/opentelemetry-shim-opentracing/test/Shim.test.ts +++ b/packages/opentelemetry-shim-opentracing/test/Shim.test.ts @@ -36,6 +36,7 @@ import { import { performance } from 'perf_hooks'; import { B3Propagator } from '@opentelemetry/propagator-b3'; import { JaegerPropagator } from '@opentelemetry/propagator-jaeger'; +import { SemanticAttributes } from "@opentelemetry/semantic-conventions"; describe('OpenTracing Shim', () => { const compositePropagator = new CompositePropagator({ @@ -355,18 +356,92 @@ describe('OpenTracing Shim', () => { }); }); - it('logs KV pairs', () => { - const kvLogs = { key: 'value', error: 'not a valid span' }; - span.log(kvLogs); - assert.strictEqual(otSpan.events[0].name, 'log'); - assert.strictEqual(otSpan.events[0].attributes, kvLogs); - }); + describe('logging', () => { + describe('event with payload', () => { + it('logs an event with a payload', () => { + const payload = { user: 'payload', request: 1 }; + span.logEvent('some log', payload); + assert.strictEqual(otSpan.events[0].name, 'some log'); + assert.deepStrictEqual(otSpan.events[0].attributes, payload); + }); + + it('records an exception', () => { + const payload = { + 'error.object': 'boom', fault: 'meow' + }; + span.logEvent('error', payload); + assert.strictEqual(otSpan.events[0].name, 'exception'); + const expectedAttributes = { + [SemanticAttributes.EXCEPTION_MESSAGE]: 'boom', + }; + assert.deepStrictEqual(otSpan.events[0].attributes, expectedAttributes); + }); + + it('maps to exception semantic conventions', () => { + const payload = { + fault: 'meow', 'error.kind': 'boom', message: 'oh no!', stack: 'pancakes' + }; + span.logEvent('error', payload); + assert.strictEqual(otSpan.events[0].name, 'exception'); + const expectedAttributes = { + fault: 'meow', + [SemanticAttributes.EXCEPTION_TYPE]: 'boom', + [SemanticAttributes.EXCEPTION_MESSAGE]: 'oh no!', + [SemanticAttributes.EXCEPTION_STACKTRACE]: 'pancakes' + }; + assert.deepStrictEqual(otSpan.events[0].attributes, expectedAttributes); + }); + }); + + describe('key-value pairs', () => { + const tomorrow = new Date().setDate(new Date().getDate() + 1); - it('logs an event with a payload', () => { - const payload = { user: 'payload', request: 1 }; - span.logEvent('some log', payload); - assert.strictEqual(otSpan.events[0].name, 'some log'); - assert.deepStrictEqual(otSpan.events[0].attributes, payload); + it('names event after event attribute', () => { + const kvLogs = { event: 'fun-time', user: 'meow', value: 123 }; + span.log(kvLogs, tomorrow); + assert.strictEqual(otSpan.events[0].name, 'fun-time'); + assert.strictEqual(otSpan.events[0].time[0], Math.trunc(tomorrow / 1000)); + assert.strictEqual(otSpan.events[0].attributes, kvLogs); + }); + + it('names event log, as a fallback', () => { + const kvLogs = { user: 'meow', value: 123 }; + span.log(kvLogs, tomorrow); + assert.strictEqual(otSpan.events[0].name, 'log'); + assert.strictEqual(otSpan.events[0].time[0], Math.trunc(tomorrow / 1000)); + assert.strictEqual(otSpan.events[0].attributes, kvLogs); + }); + + it('records an exception', () => { + const kvLogs = { + event: 'error', 'error.object': 'boom', fault: 'meow' + }; + span.log(kvLogs, tomorrow); + assert.strictEqual(otSpan.events[0].name, 'exception'); + assert.strictEqual(otSpan.events[0].time[0], Math.trunc(tomorrow / 1000)); + const expectedAttributes = { + [SemanticAttributes.EXCEPTION_MESSAGE]: 'boom', + }; + assert.deepStrictEqual(otSpan.events[0].attributes, expectedAttributes); + }); + + it('maps to exception semantic conventions', () => { + const kvLogs = { + event: 'error', fault: 'meow', 'error.kind': 'boom', message: 'oh no!', stack: 'pancakes' + }; + span.log(kvLogs, tomorrow); + assert.strictEqual(otSpan.events[0].name, 'exception'); + assert.strictEqual(otSpan.events[0].time[0], Math.trunc(tomorrow / 1000)); + const expectedAttributes = { + event: 'error', + fault: 'meow', + [SemanticAttributes.EXCEPTION_TYPE]: 'boom', + [SemanticAttributes.EXCEPTION_MESSAGE]: 'oh no!', + [SemanticAttributes.EXCEPTION_STACKTRACE]: 'pancakes' + }; + assert.deepStrictEqual(otSpan.events[0].attributes, expectedAttributes); + }); + }); }); it('updates the name', () => { diff --git a/packages/opentelemetry-shim-opentracing/tsconfig.json b/packages/opentelemetry-shim-opentracing/tsconfig.json index 343988c19f..8fbd0e4307 100644 --- a/packages/opentelemetry-shim-opentracing/tsconfig.json +++ b/packages/opentelemetry-shim-opentracing/tsconfig.json @@ -18,6 +18,9 @@ { "path": "../opentelemetry-propagator-jaeger" }, + { + "path": "../opentelemetry-semantic-conventions" + }, { "path": "../opentelemetry-tracing" } From 8cc0ddd1a7fb3faccb600815f7eb1643a0b1d132 Mon Sep 17 00:00:00 2001 From: Vera Reynolds Date: Wed, 30 Jun 2021 09:05:26 -0600 Subject: [PATCH 2/2] chore: remove noop registration from example --- examples/opentracing-shim/shim.js | 3 --- 1 file changed, 3 deletions(-) diff --git a/examples/opentracing-shim/shim.js b/examples/opentracing-shim/shim.js index 729f7165b5..f6c325a649 100644 --- a/examples/opentracing-shim/shim.js +++ b/examples/opentracing-shim/shim.js @@ -2,7 +2,6 @@ const { ResourceAttributes } = require('@opentelemetry/semantic-conventions'); const { Resource } = require('@opentelemetry/resources'); -const { registerInstrumentations } = require('@opentelemetry/instrumentation'); const { NodeTracerProvider } = require('@opentelemetry/node'); const { SimpleSpanProcessor } = require('@opentelemetry/tracing'); const { JaegerExporter } = require('@opentelemetry/exporter-jaeger'); @@ -18,8 +17,6 @@ function shim(serviceName) { // Initialize the OpenTelemetry APIs to use the NodeTracerProvider bindings provider.register(); - registerInstrumentations({}); - return new TracerShim(provider.getTracer('opentracing-shim')); }