feat: remove injection options (#312)

.github/workflows/ci.yml

@@ -85,6 +85,10 @@ jobs:
       - name: Test mixed example
         working-directory: test/examples
         run: docker-compose -f e2e.docker-compose.yml -f mixed.override.yml -f published.override.yml up --exit-code-from test
+      # Should be enabled when 0.13 is released with exposing defaultLogHook
+      # - name: Test log-injection example
+      #   working-directory: test/examples
+      #   run: docker-compose -f e2e.docker-compose.yml -f log-injection.override.yml -f published.override.yml up --exit-code-from test
 
   e2e:
     runs-on: ubuntu-latest
@@ -101,3 +105,6 @@ jobs:
       - name: Test mixed example
         working-directory: test/examples
         run: docker-compose -f e2e.docker-compose.yml -f mixed.override.yml up --exit-code-from test
+      - name: Test log-injection example
+        working-directory: test/examples
+        run: docker-compose -f e2e.docker-compose.yml -f log-injection.override.yml up --exit-code-from test

change/@splunk-otel-8acd8087-05ea-418e-9fa8-cd0cf4298f73.json

@@ -0,0 +1,7 @@
+{
+  "type": "major",
+  "comment": "feat: remove logInjectionEnabled and SPLUNK_LOGS_INJECTION options",
+  "packageName": "@splunk/otel",
+  "email": "[email protected]",
+  "dependentChangeType": "patch"
+}

examples/log-injection/.dockerignore

@@ -0,0 +1,2 @@
+node_modules
+package-lock.json

examples/log-injection/index.js

@@ -0,0 +1,30 @@
+const { trace, SpanStatusCode, context } = require('@opentelemetry/api');
+
+const log = require('pino')();
+const doWork = () => {
+	log.info('before work');
+	while (Date.now() - start < 500) {}
+	log.info('after work work');
+};
+
+// There is no active span right now so no trace id to report.
+// Following log event will not have trace data injected.
+log.info('starting...');
+
+const start = Date.now();
+const tracer = trace.getTracer('splunk-otel-example-log-injection');
+const span = tracer.startSpan('main');
+const spanContext = trace.setSpan(context.active(), span);
+
+// This will run a function inside a context which has an active span.
+context.with(spanContext, doWork);
+
+// Even though the span has not ended yet it's not active in current context
+// anymore and thus will not be logged.
+log.info('done!');
+span.end();
+
+setTimeout(() => {
+	// wait for the spans to be flushed
+	console.log('Spans flushed');
+}, 5000);

examples/log-injection/log-injection.tracer.js

@@ -0,0 +1,27 @@
+const { getInstrumentations } = require('@splunk/otel/lib/instrumentations');
+const { defaultLogHook } = require('@splunk/otel/lib/instrumentations/logging');
+const { PinoInstrumentation } = require('@opentelemetry/instrumentation-pino');
+
+// an example logHook to add common resource attributes to every log message
+const logHook = (span, logRecord) => {
+	// thrown errors in logHooks are ignored to avoid crashing due to instrumentation
+	// logic. Deciding on using a try-catch comes down to the usecase and performance requirements.
+	try {
+		// defaultLogHook does the default behavior of adding service.[name, version] and deployment.environment
+		// defaultLogHook(span, logRecord); // supported from 0.13
+		logRecord['my.attribute'] = 'my.value';
+	} catch (e) {
+		console.error(e);
+		throw e;
+	}
+};
+
+require('@splunk/otel').startTracing({
+	serviceName: 'example',
+	instrumentations: [
+		...getInstrumentations(),
+		new PinoInstrumentation({
+			logHook: logHook,
+		}),
+	],
+});

examples/log-injection/package.json

@@ -0,0 +1,16 @@
+{
+  "name": "splunk-otel-example-log-injection",
+  "private": true,
+  "version": "1.0.0",
+  "main": "index.js",
+  "scripts": {
+    "start": "node -r ./log-injection.tracer.js index.js",
+    "basic": "node -r @splunk/otel/instrument index.js"
+  },
+  "dependencies": {
+    "@opentelemetry/api": "^1.0.3",
+    "@opentelemetry/instrumentation-pino": "^0.23.0",
+    "@splunk/otel": "^0.12.0",
+    "pino": "^6.13.3"
+  }
+}

src/instrumentations/logging.ts

@@ -14,61 +14,48 @@
  * limitations under the License.
  */
 
-import { Options } from '../options';
 import { Span } from '@opentelemetry/sdk-trace-base';
 import { SemanticResourceAttributes } from '@opentelemetry/semantic-conventions';
 
 // eslint-disable-next-line @typescript-eslint/no-explicit-any
 type LogRecord = Record<string, any>;
 
+export const defaultLogHook = (span: Span, record: LogRecord) => {
+  record['service.name'] =
+    span.resource.attributes[SemanticResourceAttributes.SERVICE_NAME];
+
+  const version =
+    span.resource.attributes[SemanticResourceAttributes.SERVICE_VERSION];
+  if (version !== undefined) {
+    record['service.version'] = version;
+  }
+
+  const environment =
+    span.resource.attributes[SemanticResourceAttributes.DEPLOYMENT_ENVIRONMENT];
+  if (environment !== undefined) {
+    record['service.environment'] = environment;
+  }
+};
+
 export function configureLogInjection(
   // eslint-disable-next-line @typescript-eslint/no-explicit-any
-  instrumentation: any,
-  options: Options
+  instrumentation: any
 ) {
-  if (!options.logInjectionEnabled) {
-    return;
-  }
-
   if (
     typeof instrumentation['setConfig'] !== 'function' ||
     typeof instrumentation['getConfig'] !== 'function'
   ) {
     return;
   }
 
-  const logHook = (span: Span, record: LogRecord) => {
-    record['service.name'] =
-      span.resource.attributes[SemanticResourceAttributes.SERVICE_NAME];
-
-    const version =
-      span.resource.attributes[SemanticResourceAttributes.SERVICE_VERSION];
-    if (version !== undefined) {
-      record['service.version'] = version;
-    }
-
-    const environment =
-      span.resource.attributes[
-        SemanticResourceAttributes.DEPLOYMENT_ENVIRONMENT
-      ];
-    if (environment !== undefined) {
-      record['service.environment'] = environment;
-    }
-  };
-
-  let config = instrumentation.getConfig();
+  const config = instrumentation.getConfig();
 
   if (config === undefined) {
-    config = { logHook };
-  } else if (config.logHook !== undefined) {
-    const original = config.logHook;
-    config.logHook = function (this: unknown, span: Span, record: LogRecord) {
-      logHook(span, record);
-      original.call(this, span, record);
-    };
-  } else {
-    config.logHook = logHook;
+    return instrumentation.setConfig({ logHook: defaultLogHook });
   }
 
-  instrumentation.setConfig(config);
+  if (config.logHook === undefined) {
+    config.logHook = defaultLogHook;
+    return instrumentation.setConfig(config);
+  }
 }

src/options.ts

@@ -57,7 +57,6 @@ export interface Options {
   accessToken: string;
   maxAttrLength: number;
   serverTimingEnabled: boolean;
-  logInjectionEnabled: boolean;
   instrumentations: InstrumentationOption[];
   tracerConfig: NodeTracerConfig;
   spanExporterFactory: SpanExporterFactory;
@@ -86,10 +85,6 @@ export function _setDefaultOptions(options: Partial<Options> = {}): Options {
     );
   }
 
-  if (options.logInjectionEnabled === undefined) {
-    options.logInjectionEnabled = getEnvBoolean('SPLUNK_LOGS_INJECTION', false);
-  }
-
   const extraTracerConfig = options.tracerConfig || {};
 
   let resource = new EnvResourceDetector().detect();
@@ -138,7 +133,6 @@ export function _setDefaultOptions(options: Partial<Options> = {}): Options {
     accessToken: options.accessToken,
     maxAttrLength: options.maxAttrLength,
     serverTimingEnabled: options.serverTimingEnabled,
-    logInjectionEnabled: options.logInjectionEnabled,
     instrumentations: options.instrumentations,
     tracerConfig: tracerConfig,
     spanExporterFactory: options.spanExporterFactory,

src/tracing.ts

@@ -96,7 +96,7 @@ function configureInstrumentations(options: Options) {
       case '@opentelemetry/instrumentation-bunyan':
       case '@opentelemetry/instrumentation-pino':
       case '@opentelemetry/instrumentation-winston':
-        configureLogInjection(instr, options);
+        configureLogInjection(instr);
         break;
     }
   }

test/examples/Dockerfile

@@ -17,6 +17,7 @@ FROM base as published
 
 RUN cd examples/basic && npm install
 RUN cd examples/express && npm install
+RUN cd examples/log-injection && npm install
 RUN cd examples/mixed && npm install
 
 ## Project root doesn't have start script defined
@@ -31,4 +32,5 @@ RUN npm run compile
 RUN mv `npm pack` /tmp/splunk-otel.tgz
 RUN cd examples/basic && npm i /tmp/splunk-otel.tgz
 RUN cd examples/express && npm i /tmp/splunk-otel.tgz
+RUN cd examples/log-injection && npm i /tmp/splunk-otel.tgz
 RUN cd examples/mixed && npm i /tmp/splunk-otel.tgz

test/examples/e2e.docker-compose.yml

@@ -14,6 +14,8 @@ services:
       dockerfile: test/examples/Dockerfile
     working_dir: /home/node/app/examples/basic
     env_file: ./basic/app.env
+    depends_on:
+      - collector
   test:
     build:
       context: .

test/examples/log-injection.override.yml

@@ -0,0 +1,8 @@
+services:
+  app:
+    working_dir: /home/node/app/examples/log-injection
+    env_file: ./log-injection/app.env
+  test:
+    command: node ./log-injection
+    environment:
+      COLLECTOR_URL: http://collector:8378

test/examples/log-injection/app.env

@@ -0,0 +1,4 @@
+OTEL_SERVICE_NAME='log-injection-example'
+OTEL_RESOURCE_ATTRIBUTES='deployment.environment=dev'
+OTEL_LOG_LEVEL='DEBUG'
+OTEL_EXPORTER_OTLP_ENDPOINT=http://collector:55681/v1/traces

test/examples/log-injection/index.js

@@ -0,0 +1,14 @@
+const {
+  assertSpans,
+  logSpanTable,
+  request,
+  waitSpans,
+} = require('../utils.js');
+const snapshot = require('./snapshot.js');
+
+waitSpans(snapshot.length).then((data) => {
+	logSpanTable(data);
+	assertSpans(data, snapshot);
+}).then(() => {
+  console.log(`${snapshot.length} span(s) validated.`);
+});

test/examples/log-injection/snapshot.js

@@ -0,0 +1,19 @@
+// a console.log from a previous run
+module.exports = [
+  {
+    traceId: 'DUaJffuwfAqa53DY7yipHA==',
+    id: 'QD8nT/PZGF8=',
+    startTime: '2021-09-28T08:23:37.842474752Z',
+    name: 'main',
+    kind: 'internal',
+    parentSpanId: undefined,
+    parent: undefined,
+    references: undefined,
+    status: { code: undefined },
+    attributes: {
+      'otel.library.name': 'splunk-otel-example-log-injection',
+      'span.kind': 'internal',
+      'status.code': undefined
+    }
+  }
+];