*two* MetricReaders on a MeterProvider interfere with each other's async metric data point values

[trentm]

What happened?

Steps to Reproduce

The following script registers a MeterProvider with two metric readers -- both of them reading every 5s and exporting to the console.

/* eslint-disable */
'use strict'

const otel = require('@opentelemetry/api')
const { MeterProvider, ConsoleMetricExporter, PeriodicExportingMetricReader } = require('@opentelemetry/sdk-metrics')

const meterProvider = new MeterProvider()
meterProvider.addMetricReader(
  new PeriodicExportingMetricReader({
    exporter: new ConsoleMetricExporter(),
    exportIntervalMillis: 5000,
    exportTimeoutMillis: 2500
  })
)
meterProvider.addMetricReader(
  new PeriodicExportingMetricReader({
    exporter: new ConsoleMetricExporter(),
    exportIntervalMillis: 5000,
    exportTimeoutMillis: 2500
  })
)
otel.metrics.setGlobalMeterProvider(meterProvider)

const meter = otel.metrics.getMeter('my-meter')

let c = 0
const asyncUpDownCounter = meter.createObservableUpDownCounter('my_async_updowncounter')
asyncUpDownCounter.addCallback(observableResult => {
  console.log('observe:', c)
  observableResult.observe(c)
})

setInterval(() => {
  c++
}, 1000)

Run that script:

node two-metric-readers.js

Expected Result

Every 5 seconds, I expect that the asyncUpDownCounter callback is called and the my_async_updowncounter metric written to the console, twice. I expect that the data point value grows by 5 each time (because the setInterval is incrementing once per second).

Actual Result

The asyncUpDownCounter callback is called and the metric written to console twice, as expected.
However, the data point value of the second MetricReader is zero. (See the log below.)

Additional Details

From playing with the intervals on the two MetricReaders, the value isn't always zero for the second reader. It is more like the data collection from the first reader "takes or steals" all the accumulated delta for each interval up to that point in time. (I had been looking at the accumulations and calibrateStartTime usage in TemporalMetricProcessor.buildMetrics(), but I haven't yet gotten very far to know if that could be related.)

This example is contrived. The more practical example is if I have an app that is configured to have Prometheus (pull) metrics and also am pushing metrics to a separate thing; then the Prometheus scrapes can interfere with the data values for the other reader (or vice versa).

Is adding multiple MetricReaders to a MeterProvider meant to be supported?

OpenTelemetry Setup Code

// shown in the script above

package.json

{
  "name": "otel-metrics-bug",
  "version": "1.0.0",
  "private": true,
  "dependencies": {
    "@opentelemetry/api": "^1.4.0",
    "@opentelemetry/sdk-metrics": "^1.9.1"
  }
}

Relevant log output

Here is the full run of the script above:

% node two-metric-readers.js
observe: 4
{
  descriptor: {
    name: 'my_async_updowncounter',
    type: 'OBSERVABLE_UP_DOWN_COUNTER',
    description: '',
    unit: '',
    valueType: 1
  },
  dataPointType: 3,
  dataPoints: [
    { attributes: {}, startTime: [Array], endTime: [Array], value: 4 }
  ]
}
observe: 4
{
  descriptor: {
    name: 'my_async_updowncounter',
    type: 'OBSERVABLE_UP_DOWN_COUNTER',
    description: '',
    unit: '',
    valueType: 1
  },
  dataPointType: 3,
  dataPoints: [
    { attributes: {}, startTime: [Array], endTime: [Array], value: 0 }   // <--- this is zero!
  ]
}
observe: 9
{
  descriptor: {
    name: 'my_async_updowncounter',
    type: 'OBSERVABLE_UP_DOWN_COUNTER',
    description: '',
    unit: '',
    valueType: 1
  },
  dataPointType: 3,
  dataPoints: [
    { attributes: {}, startTime: [Array], endTime: [Array], value: 9 }
  ]
}
observe: 9
{
  descriptor: {
    name: 'my_async_updowncounter',
    type: 'OBSERVABLE_UP_DOWN_COUNTER',
    description: '',
    unit: '',
    valueType: 1
  },
  dataPointType: 3,
  dataPoints: [
    { attributes: {}, startTime: [Array], endTime: [Array], value: 0 }   // <--- this is zero!
  ]
}
observe: 14
{
  descriptor: {
    name: 'my_async_updowncounter',
    type: 'OBSERVABLE_UP_DOWN_COUNTER',
    description: '',
    unit: '',
    valueType: 1
  },
  dataPointType: 3,
  dataPoints: [
    { attributes: {}, startTime: [Array], endTime: [Array], value: 14 }
  ]
}
observe: 14
{
  descriptor: {
    name: 'my_async_updowncounter',
    type: 'OBSERVABLE_UP_DOWN_COUNTER',
    description: '',
    unit: '',
    valueType: 1
  },
  dataPointType: 3,
  dataPoints: [
    { attributes: {}, startTime: [Array], endTime: [Array], value: 0 }   // <--- this is zero!
  ]
}
^C

[trentm]

Is adding multiple MetricReaders to a MeterProvider meant to be supported?

I guess this paragraph from the spec:

The SDK MUST support multiple MetricReader instances to be registered on the
same MeterProvider, and the MetricReader.Collect invocation on one
MetricReader instance SHOULD NOT introduce side-effects to other MetricReader
instances. For example, if a MetricReader instance is receiving metric data
points that have delta temporality, it is expected
that SDK will update the time range - e.g. from (T_n, T_n+1]
to (T_n+1, T_n+2] - ONLY for this particular
MetricReader instance.

suggests this should be a bug.

[legendecas]

Thanks for the detailed reporting! I can confirm this problem and submitted a quick fix to this issue: #3667.