Version 0.35.1 of @opentelemetry/sdk-node broke http instrumentation

[mkrudele]

What happened?

Steps to Reproduce

Using this monitoring.js file:

/**
 * Autoinstrument node.js express app and export to prometheus
 */
const api = require('@opentelemetry/api');
const opentelemetry = require('@opentelemetry/sdk-node');
const { PrometheusExporter } = require('@opentelemetry/exporter-prometheus');
const { HttpInstrumentation } = require('@opentelemetry/instrumentation-http');

const pPort = PrometheusExporter.DEFAULT_OPTIONS.port;
const pEndpoint = PrometheusExporter.DEFAULT_OPTIONS.endpoint;

const prometheusExporter = new PrometheusExporter(
    { preventServerStart: false, prefix: 'ghost' },
    () => { console.log(`>>>> Prometheus scrape endpoint: http://localhost:${pPort}${pEndpoint}`); }
);

const sdk = new opentelemetry.NodeSDK({
    metricReader: prometheusExporter,

    instrumentations: [ new HttpInstrumentation() ]
});

sdk.start().then(() => {
    console.log('>>>> OpenTelemetry SDK started');
}).catch(err => {
    console.log('ERROR starting OpenTelemetry SDK. Shutting down', err);
    process.exit(1);
});

process.on("SIGTERM", () => {
  sdk
    .shutdown()
    .then(
      () => console.log('>>>> SDK shut down successfully'),
      (err) => console.log('>>>> Error shutting down SDK', err)
    )
    .finally(() => process.exit(0));
});

with this package.json dependencies:

  "dependencies": {
    "@opentelemetry/api": "1.4.0",
    "@opentelemetry/instrumentation-http": "0.35.1",
    "@opentelemetry/exporter-prometheus": "0.35.1",
    "@opentelemetry/sdk-node": "0.35.0",
    "express": "4.18.2"
  },

Standing up a simple Express application that just
require('./monitoring.js') and calling it on the metrics endpoint http://localhost:9464/metrics correctly shows the http metrics:

...
# HELP ghost_http_server_duration measures the duration of the inbound HTTP requests
# UNIT ghost_http_server_duration ms
# TYPE ghost_http_server_duration histogram
# HELP ghost_http_client_duration measures the duration of the outbound HTTP requests
# UNIT ghost_http_client_duration ms
# TYPE ghost_http_client_duration histogram
...

and calling the Express app correctly produces time series.

Updating the version of @opentelemetry/sdk-node to 0.35.1 breaks the http instrumentation: standing up the Express app and calling on the metrics endpoints http://localhost:9464/metrics does not report http metrics definition anymore and calling the Express app does not produces time series.

Expected Result

New version does not break http instrumentation.

Actual Result

New version 0.35.1 breaks http instrumentation.

Additional Details

OpenTelemetry Setup Code

/**
 * Autoinstrument node.js express app and export to prometheus
 */
const api = require('@opentelemetry/api');
const opentelemetry = require('@opentelemetry/sdk-node');
const { PrometheusExporter } = require('@opentelemetry/exporter-prometheus');
const { HttpInstrumentation } = require('@opentelemetry/instrumentation-http');

const pPort = PrometheusExporter.DEFAULT_OPTIONS.port;
const pEndpoint = PrometheusExporter.DEFAULT_OPTIONS.endpoint;

const prometheusExporter = new PrometheusExporter(
    { preventServerStart: false, prefix: 'ghost' },
    () => { console.log(`>>>> Prometheus scrape endpoint: http://localhost:${pPort}${pEndpoint}`); }
);

const sdk = new opentelemetry.NodeSDK({
    metricReader: prometheusExporter,

    instrumentations: [ new HttpInstrumentation() ]
});

sdk.start().then(() => {
    console.log('>>>> OpenTelemetry SDK started');
}).catch(err => {
    console.log('ERROR starting OpenTelemetry SDK. Shutting down', err);
    process.exit(1);
});

process.on("SIGTERM", () => {
  sdk
    .shutdown()
    .then(
      () => console.log('>>>> SDK shut down successfully'),
      (err) => console.log('>>>> Error shutting down SDK', err)
    )
    .finally(() => process.exit(0));
});

package.json

{
  "name": "echo-server",
  "version": "1.0.0",
  "main": "app.js",
  "dependencies": {
    "@opentelemetry/api": "1.4.0",
    "@opentelemetry/instrumentation-http": "0.35.1",
    "@opentelemetry/exporter-prometheus": "0.35.1",
    "@opentelemetry/sdk-node": "0.35.0",
    "express": "4.18.2"
  }
}

Relevant log output

No response

[pichlermarc]

I was able to reproduce this, it looks like this problem was introduced with 0.35.1 via #3502. Now that we're registering the instrumentations early, the MeterProvider used by the instrumentations is a NoopMeterProvider and all metrics get dropped. 🙁

We may either have to revert the changes made in #3502 or provide a workaround that sets the MeterProvider on all instrumentations after initialization in NodeSDK.start() finishes. I'll open a PR for that tomorrow. 🙂

I also created an issue aiming for a long-term fix here #3622