Unexpected behavior for DELTA metric interval

[trask]

The following code:

    OpenTelemetry openTelemetry =
        OpenTelemetrySdk.builder()
            .setMeterProvider(
                SdkMeterProvider.builder()
                    .registerMetricReader(
                        PeriodicMetricReader.builder(
                                LoggingMetricExporter.create(AggregationTemporality.DELTA))
                            .setInterval(Duration.ofSeconds(10))
                            .build())
                    .build())
            .build();

    openTelemetry.getMeter("test").histogramBuilder("histo1").build().record(1);
    SECONDS.sleep(15);
    openTelemetry.getMeter("test").histogramBuilder("histo2").build().record(2);
    SECONDS.sleep(15);

reports the following metrics:

INFO: metric: ImmutableMetricData{name=histo1, description=, unit=1, type=HISTOGRAM,
  data=ImmutableHistogramData{aggregationTemporality=DELTA,
    points=[ImmutableHistogramPointData{getStartEpochNanos=1650484261414000000, getEpochNanos=1650484271431000000}]
  }
}
INFO: metric: ImmutableMetricData{name=histo2, description=, unit=1, type=HISTOGRAM,
  data=ImmutableHistogramData{aggregationTemporality=DELTA,
    points=[ImmutableHistogramPointData{getStartEpochNanos=1650484261414000000, getEpochNanos=1650484281425000000}]
  }
}

what is unexpected (to me at least) is that the metric "interval" (getEpochNanos - getStartEpochNanos) is ~20 seconds for histo2, instead of approximately 10 seconds as configured.

I can see how the current behavior is technically correct, but I'm worried about user questions asking why the metric interval that we report isn't always approximately the value that they configured (e.g. via OTEL_METRIC_EXPORT_INTERVAL).

[jack-berg]

Yeah that is a bit strange isn't it? Here's the code that produces it.

If we have previous recordings we use the start time from it. However if its the first collection, we need to set the start time to some value. We don't currently track the time of the last collection for each reader, so we take the overall start time of the sdk instead (which we do track because its needed for cumulative metrics).

[anuraaga]

Not sure if it's related to DELTA or not - start is a constant similar to app start time from what I understand. So we expect that subtraction to get larger over time. If we explain what start means well enough, hopefully it's not too confusing? Unless I'm already confused 😅

[trask]

@anuraaga here's another example that might help (or further confuse?)

    DoubleHistogram histo3 = openTelemetry.getMeter("test").histogramBuilder("histo3").build();
    for (int i = 0; i < 50; i++) {
      histo3.record(1);
      SECONDS.sleep(1);
    }

INFO: metric: ImmutableMetricData{name=histo3, description=, unit=1, type=HISTOGRAM, data=ImmutableHistogramData{aggregationTemporality=DELTA, points=[ImmutableHistogramPointData{getStartEpochNanos=1650497965597000000, getEpochNanos=1650497975617000000, ...}]}}
INFO: metric: ImmutableMetricData{name=histo3, description=, unit=1, type=HISTOGRAM, data=ImmutableHistogramData{aggregationTemporality=DELTA, points=[ImmutableHistogramPointData{getStartEpochNanos=1650497975617000000, getEpochNanos=1650497985613000000, ...}]}}
INFO: metric: ImmutableMetricData{name=histo3, description=, unit=1, type=HISTOGRAM, data=ImmutableHistogramData{aggregationTemporality=DELTA, points=[ImmutableHistogramPointData{getStartEpochNanos=1650497985613000000, getEpochNanos=1650497995620000000, ...}]}}
INFO: metric: ImmutableMetricData{name=histo3, description=, unit=1, type=HISTOGRAM, data=ImmutableHistogramData{aggregationTemporality=DELTA, points=[ImmutableHistogramPointData{getStartEpochNanos=1650497995620000000, getEpochNanos=1650498005619000000, ...}]}}
INFO: metric: ImmutableMetricData{name=histo3, description=, unit=1, type=HISTOGRAM, data=ImmutableHistogramData{aggregationTemporality=DELTA, points=[ImmutableHistogramPointData{getStartEpochNanos=1650498005619000000, getEpochNanos=1650498015614000000, ...}]}}

[anuraaga]

Oh - yeah I thought start is supposed to be constant, is this correct behavior?

[jack-berg]

start is a constant similar to app start time from what I understand. So we expect that subtraction to get larger over time

Start is only constant when temporality is cumulative. When temporality is delta it represents the beginning of the collection window, which is the app start time if it's the first collection, or the time of the last collection. Check out this image from the data model.