Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat(shim-opentracing): update logging based on new spec #2282

Merged
merged 5 commits into from
Jun 30, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions examples/opentracing-shim/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,8 @@
"@opentelemetry/exporter-zipkin": "0.22.0",
"@opentelemetry/instrumentation": "0.22.0",
"@opentelemetry/node": "0.22.0",
"@opentelemetry/resources": "0.22.0",
"@opentelemetry/semantic-conventions": "0.22.0",
"@opentelemetry/shim-opentracing": "0.22.0",
"@opentelemetry/tracing": "0.22.0",
"opentracing": "^0.14.4"
Expand Down
2 changes: 1 addition & 1 deletion examples/opentracing-shim/server.js
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand Down
16 changes: 8 additions & 8 deletions examples/opentracing-shim/shim.js
Original file line number Diff line number Diff line change
@@ -1,33 +1,33 @@
'use strict';

const { registerInstrumentations } = require('@opentelemetry/instrumentation');
const { ResourceAttributes } = require('@opentelemetry/semantic-conventions');
const { Resource } = require('@opentelemetry/resources');
const { NodeTracerProvider } = require('@opentelemetry/node');
const { SimpleSpanProcessor } = require('@opentelemetry/tracing');
const { JaegerExporter } = require('@opentelemetry/exporter-jaeger');
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({
});

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;
1 change: 1 addition & 0 deletions packages/opentelemetry-shim-opentracing/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -57,6 +57,7 @@
},
"dependencies": {
"@opentelemetry/core": "0.22.0",
"@opentelemetry/semantic-conventions": "0.22.0",
"opentracing": "^0.14.4"
}
}
65 changes: 52 additions & 13 deletions packages/opentelemetry-shim-opentracing/src/shim.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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[] = [];
Expand Down Expand Up @@ -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;
}

Expand Down Expand Up @@ -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") {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

string is the only "exception" type that's possible here, since the override method takes SpanAttributes, meaning shim consumers can't log an attribute like error.object: new Error(), if they're using type safety

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You are correct, recordException can take an Error object, but the log function itself takes SpanAttributes which don't allow objects as attribute values:

override log(keyValuePairs: SpanAttributes, _timestamp?: number): this {

The issue here is that the shim restricts the types more than the OpenTracing lib: https://github.com/opentracing/opentracing-javascript/blob/111ea4f7939c8f8f538333330d72115e5b28bcce/src/span.ts#L143 where you can pass any as attribute values, including objects.

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
Expand Down
97 changes: 86 additions & 11 deletions packages/opentelemetry-shim-opentracing/test/Shim.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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({
Expand Down Expand Up @@ -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', () => {
Expand Down
3 changes: 3 additions & 0 deletions packages/opentelemetry-shim-opentracing/tsconfig.json
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,9 @@
{
"path": "../opentelemetry-propagator-jaeger"
},
{
"path": "../opentelemetry-semantic-conventions"
},
{
"path": "../opentelemetry-tracing"
}
Expand Down