Skip to content

@opentelemetry/[email protected] doesn't guard against an async resource attribute that rejects #5539

@trentm

Description

@trentm

This is a regression compared to 1.x.

If a Resource Detector has an async attribute and that attribute value rejects, then typical usage of resource detectors (with NodeSDK, or with auto-instrumentations-node) will not guard against that rejection. Currently the guard is only in .waitForAsyncAttributes(), which is typically only called some time later for the first export. If the attribute rejects before then, then there is an unhandledRejection, which can likely crash the app.

@david-luna found this here: open-telemetry/opentelemetry-js-contrib#2738 (review)

repro

This should work, but fails.

$ cd opentelemetry-js/experimental/packages/opentelemetry-sdk-node

$ cat foo.js
const otel = require('@opentelemetry/api');
const { NodeSDK } = require('./');
const { envDetector } = require('@opentelemetry/resources');

class DetectorRejects {
  detect() {
    return {
      attributes: {
        sync: 'fromsync',
        async: Promise.reject(new Error('reject')),
      },
    };
  }
}

const sdk = new NodeSDK({
  serviceName: 'foo',
  resourceDetectors: [envDetector, new DetectorRejects()],
});
sdk.start();

process.on('beforeExit', async () => {
  await sdk.shutdown();
  console.log('sdk shutdown');
});

const tracer = otel.trace.getTracer('example');
tracer.startActiveSpan('manual-span', async span => {
  span.end();
});

$ node foo.js
/Users/trentm/tm/opentelemetry-js4/experimental/packages/opentelemetry-sdk-node/foo.js:25
        async: Promise.reject(new Error('reject')),
                              ^

Error: reject
    at DetectorRejects.detect (/Users/trentm/tm/opentelemetry-js4/experimental/packages/opentelemetry-sdk-node/foo.js:25:31)
    at /Users/trentm/tm/opentelemetry-js4/packages/opentelemetry-resources/build/src/detect-resources.js:29:81
    at Array.map (<anonymous>)
    at detectResources (/Users/trentm/tm/opentelemetry-js4/packages/opentelemetry-resources/build/src/detect-resources.js:27:48)
    at NodeSDK.start (/Users/trentm/tm/opentelemetry-js4/experimental/packages/opentelemetry-sdk-node/build/src/sdk.js:225:83)
    at Object.<anonymous> (/Users/trentm/tm/opentelemetry-js4/experimental/packages/opentelemetry-sdk-node/foo.js:35:5)
    at Module._compile (node:internal/modules/cjs/loader:1364:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1422:10)
    at Module.load (node:internal/modules/cjs/loader:1203:32)
    at Module._load (node:internal/modules/cjs/loader:1019:12)

Node.js v18.20.4

behaviour in v1.x

The equiv case that worked with v1.x:

class DetectorRejects {
  detect() {
    return new Resource(
      { sync: 'fromsync' },
      Promise.reject(new Error('reject'))
    );
  }
}

const sdk = new NodeSDK({
  serviceName: 'foo',
  resourceDetectors: [envDetector, new DetectorRejects()],
});
sdk.start();

process.on('beforeExit', async () => {
  await sdk.shutdown();
  console.log('sdk shutdown');
});

const tracer = otel.trace.getTracer('example');
tracer.startActiveSpan('manual-span', async span => {
  span.end();
});

When run with OTEL_LOG_LEVEL=debug it emits the following diag.debug, and exits successfully.

a resource's async attributes promise rejected: Error: reject
    at DetectorRejects.detect (/Users/trentm/src/opentelemetry-js-1.x/experimental/packages/opentelemetry-sdk-node/foo.js:25:22)
    ...

test case addition

I started by trying to add a test case to test/detect-resources.test.ts but I've failed so far. Attempting to add a process.on('unhandleRejection' ... (or process.on('uncaughtExceptionMonitor', ...) for the test run is fraught because when run in the mocha process there are listeners that I think are in the way, as shown when dumping process._events:

XXX process._events [Object: null prototype] {
  newListener: [ [Function: startListeningIfSignal], [Function (anonymous)] ],
  removeListener: [ [Function: stopListeningIfSignal], [Function (anonymous)] ],
  warning: [Function: onWarning],
  SIGWINCH: [
    [Function: refreshStderrOnSigWinch],
    [Function: refreshStdoutOnSigWinch]
  ],
  SIGABRT: [Function: listener],
  SIGALRM: [Function: listener],
  SIGHUP: [Function: listener],
  SIGINT: [Function: listener],
  SIGTERM: [Function: listener],
  SIGVTALRM: [Function: listener],
  SIGXCPU: [Function: listener],
  SIGXFSZ: [Function: listener],
  SIGUSR2: [Function: listener],
  SIGTRAP: [Function: listener],
  SIGSYS: [Function: listener],
  SIGQUIT: [Function: listener],
  SIGIOT: [Function: listener],
  uncaughtException: [ [Function: domainUncaughtExceptionClear], [Function: bound ] ],
  unhandledRejection: [Function (anonymous)],
  uncaughtExceptionMonitor: [Function: ueMonitor]
}

At least I don't yet understand what is happening in my tests.

With this diff to the test file:

diff --git a/packages/opentelemetry-resources/test/detect-resources.test.ts b/packages/opentelemetry-resources/test/detect-resources.test.ts
index 47475d5e2..4ecc33d9e 100644
--- a/packages/opentelemetry-resources/test/detect-resources.test.ts
+++ b/packages/opentelemetry-resources/test/detect-resources.test.ts
@@ -21,7 +21,8 @@ import { detectResources, ResourceDetector } from '../src';
 import { isPromiseLike } from '../src/utils';
 import { describeNode } from './util';

-describe('detectResources', () => {
+// XXX only
+describe.only('detectResources', () => {
   afterEach(() => {
     sinon.restore();
   });
@@ -72,6 +73,7 @@ describe('detectResources', () => {
         detectors: [new DetectorRejects()],
       });

+      setImmediate(async () => {
         await resource.waitForAsyncAttributes?.();

         assert.ok(
@@ -86,3 +88,4 @@ describe('detectResources', () => {
       });
     });
   });
+});

A test run does show that there was an unhandleRejection event:

% npm test

> @opentelemetry/[email protected] test
> nyc mocha 'test/**/*.test.ts'



  detectResources
    ✔ reliably detects promises
    ✔ handles resource detectors which return Promise<Resource>
    Node.js: logging
      ✔ logs when a detector's async attributes promise rejects
(node:40653) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 16)
(Use `node --trace-warnings ...` to show where the warning was created)


  3 passing (4ms)

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions