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

Co-authored-by: Daniel Dyla <[email protected]>

Author: vreynolds

examples/opentracing-shim/package.json

@@ -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"

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();

examples/opentracing-shim/shim.js

@@ -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;

packages/opentelemetry-shim-opentracing/package.json

@@ -57,6 +57,7 @@
   },
   "dependencies": {
     "@opentelemetry/core": "0.22.0",
+    "@opentelemetry/semantic-conventions": "0.22.0",
     "opentracing": "^0.14.4"
   }
 }

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

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', () => {

packages/opentelemetry-shim-opentracing/tsconfig.json

@@ -18,6 +18,9 @@
     {
       "path": "../opentelemetry-propagator-jaeger"
     },
+    {
+      "path": "../opentelemetry-semantic-conventions"
+    },
     {
       "path": "../opentelemetry-tracing"
     }