Skip to content

PeriodicExportingMetricReader discards its shutdown timeout #5574

Description

@dwin-gharibi

Describe your environment

Labels: bug, sdk, metrics
Affected packages: opentelemetry-sdk
Found on: main @ 0a5d76b6
Environment: CPython 3.12

What happened?

PeriodicExportingMetricReader.shutdown works out how much of the caller's budget is left after joining the ticker thread, then passes it to the exporter as timeout=. Every MetricExporter.shutdown is declared as shutdown(self, timeout_millis=30_000, **kwargs), so the value is absorbed by **kwargs and discarded, and the exporter falls back to its own 30 second default.

The force_flush call three lines below correctly uses timeout_millis=, which is what marks this as a slip rather than a deliberate choice.

Steps to Reproduce

import time
from opentelemetry.sdk.metrics import Counter, MeterProvider
from opentelemetry.sdk.metrics.export import (
    AggregationTemporality, MetricExporter, MetricExportResult,
    PeriodicExportingMetricReader,
)

class SlowExporter(MetricExporter):
    def __init__(self):
        super().__init__(preferred_temporality={Counter: AggregationTemporality.CUMULATIVE})
        self.got = None
    def export(self, metrics_data, timeout_millis=10_000, **kwargs):
        return MetricExportResult.SUCCESS
    def force_flush(self, timeout_millis=10_000):
        return True
    def shutdown(self, timeout_millis=30_000, **kwargs):
        self.got = timeout_millis
        time.sleep(min(timeout_millis, 3000) / 1000)   # a well-behaved exporter drains

exporter = SlowExporter()
provider = MeterProvider(
    metric_readers=[PeriodicExportingMetricReader(exporter, export_interval_millis=600_000)]
)
provider.get_meter("m").create_counter("c").add(1)

start = time.time()
provider.shutdown(timeout_millis=200)
print(f"asked for 200ms, exporter got {exporter.got}, took {(time.time()-start)*1000:.0f}ms")

Expected Result

The exporter receives the remaining budget as timeout_millis, and MeterProvider.shutdown(timeout_millis=200) returns within roughly that budget.

Actual Result

reader calls : self._exporter.shutdown(timeout=(deadline_ns - time_ns()) / 10**6)
reader calls : self._exporter.force_flush(timeout_millis=timeout_millis)
exporter sig : def shutdown(self, timeout_millis: float = 30000, **kwargs)

caller's budget      : 200 ms
exporter received    : timeout_millis=30000  (its own default)
swallowed into kwargs: {'timeout': 499.84}
actual wall clock    : 3000 ms  ->  15x over budget

Additional context

shutdown can block far longer than the caller allowed. This matters wherever shutdown is on a clock: a container receiving SIGTERM with a grace period, a serverless invocation finishing, a test suite tearing down a provider between cases. An exporter that honours its timeout will happily spend 30 seconds when the caller asked for a fraction of a second, and the caller has no way to influence it.

Because the wrong keyword is silently absorbed by **kwargs, nothing warns and no exception is raised.

Would you like to implement a fix?

Yes

Tip

React with 👍 to help prioritize this issue. Please use comments to provide useful context, avoiding +1 or me too, to help us triage it. Learn more here.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions