Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Timer max expiry inconsistent with percentiles expiry #3298

Open
gdabski opened this issue Jul 16, 2022 · 1 comment · May be fixed by #5237
Open

Timer max expiry inconsistent with percentiles expiry #3298

gdabski opened this issue Jul 16, 2022 · 1 comment · May be fixed by #5237
Labels
module: micrometer-core An issue that is related to our core module

Comments

@gdabski
Copy link

gdabski commented Jul 16, 2022

Describe the bug
A single recorded time (sample) affects a Timer's max() for a longer time than percentiles produced by the Timer. With default DistributionStatisticConfig the effective expiry is one minute for the percentiles and three minutes for max. The issue is related to how TimeWindowMax and AbstractTimeWindowHistogram interpret the value of DistributionStatisticConfig.expiry. Both use ring buffers of same size to implement the decay, but while the former only moves by one buffer position in intervals equal to expiry, the latter is implemented to do a full rotation of the buffer in the same time.

Environment

  • Micrometer version: 1.9.x
  • OS: Linux
  • Java version: 17.0.3

To Reproduce

    @Test
    void demonstratesDifferentExpiryForMaxAndPercentiles() throws InterruptedException {
        MeterRegistry meterRegistry = new SimpleMeterRegistry();
        Timer timer = Timer.builder("test").publishPercentiles(new double[]{0.5}).register(meterRegistry);
        Duration checkInterval = Duration.ofSeconds(30);

        timer.record(Duration.ofMillis(200));

        Duration testDuration = Duration.ZERO;
        var max = timer.max(MILLISECONDS);
        var snapshot = timer.takeSnapshot();

        while (max != 0) {
            System.out.printf("%ss: %s max %.0f%n", testDuration.toSeconds(), snapshot.percentileValues()[0], max);

            Thread.sleep(checkInterval.toMillis());

            testDuration = testDuration.plus(checkInterval);
            max = timer.max(MILLISECONDS);
            snapshot = timer.takeSnapshot();
        }

        System.out.printf("%ss: %s max %.0f%n", testDuration.toSeconds(), snapshot.percentileValues()[0], max);
    }

Prints:

0s: (1.92937984E8 at 50.0%) max 200
30s: (1.92937984E8 at 50.0%) max 200
60s: (0.0 at 50.0%) max 200
90s: (0.0 at 50.0%) max 200
120s: (0.0 at 50.0%) max 200
150s: (0.0 at 50.0%) max 200
180s: (0.0 at 50.0%) max 0

Expected behaviour
A single sample ceases to affect percentiles and timer max at the same point in time.

Related issues
In #2751 there is a complaint about max not expiring in expected time, but response was that the TimeWindowMax uses expiry (and bufferLength) from DistributionStatisticConfig right.
@gdabski gdabski changed the title Timer max expiry inconsistent with histogram expiry Timer max expiry inconsistent with percentiles expiry Jul 16, 2022
@shakuzen shakuzen added waiting-for-triage module: micrometer-core An issue that is related to our core module labels Jul 19, 2022
@trask trask mentioned this issue Jan 14, 2023
Open
@nowkarol nowkarol mentioned this issue Dec 9, 2023
Closed
@rafalh
Copy link

rafalh commented Jun 27, 2024

I just stepped onto this issue.
I think I found the root cause - it is the way how durationBetweenRotatesMillis is initialized. For some reasons expiry time from configuration is divided there by bufferLength (ageBuckets variable) unlike in TimeWindowMax where expiry time is taken directly. This means that effective expiry time (when metric is reset to 0 after single request) for max metric is expiry * bufferLength but for percentiles it is only expiry.
AFAIK documentation does not reflect this difference and for me it is confusing so I'm assuming it is a bug.
For the default configuration where expiry/step is set to 1 minute and bufferLength is set to 3, assuming metrics are scrapped every minute, in unfortunate case when scrapping occurs immediately after metrics are rotated, requests from 20 seconds window out of 1 minute (33% of data) are not taken into account in percentile metrics at all...
I'm planning to create a PR changing durationBetweenRotatesMillis initialization.

rafalh added a commit to rafalh/micrometer that referenced this issue Jul 1, 2024
@rafalh
Fix percentile metrics rotating too often
177becd 
Before this change percentile metrics rotation interval was set to `expiry / bufferLength`. This was different from other metrics like `_max` where the interval is set to `expiry`. At the same time documentation of the `expiry` parameter says clearly that it is used as rotation interval.
This inconsistent behavior was confusing for users because some metrics expired faster than the others. What's more it caused some requests to be ignored in percentile metrics if `expiry` (also called `step`) was set to the same duration as scrapping interval (e.g. 1 minute) and scrapping occurred not long after buffer rotation. In case of the default config where `bufferLength` is 3 it could result in up to 33% requests being ignored by percentile metrics.

Fix this inconsistency by changing buffer rotation interval for percentiles to `expiry`.

Fixes micrometer-metrics#3298
rafalh added a commit to rafalh/micrometer that referenced this issue Jul 1, 2024
@rafalh
Fix percentile metrics rotating too often
53fdbf3 
Before this change percentile metrics rotation interval was set to `expiry / bufferLength`. This was different from other metrics like `_max` where the interval is set to `expiry`. At the same time documentation of the `expiry` parameter says clearly that it is used as rotation interval.

This inconsistent behavior was confusing for users because some metrics expired faster than the others. What's more it caused some requests to be ignored in percentile metrics if `expiry` (also called `step`) was set to the same duration as scrapping interval (e.g. 1 minute) and scrapping occurred not long after buffer rotation. In case of the default config where `bufferLength` is 3 it could result in up to 33% requests being ignored by percentile metrics.

Fix this inconsistency by changing buffer rotation interval for percentiles to `expiry`.

Fixes micrometer-metrics#3298
@rafalh rafalh linked a pull request Jul 1, 2024 that will close this issue
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
module: micrometer-core An issue that is related to our core module
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix percentile metrics rotating too often rafalh/micrometer
3 participants
@rafalh @shakuzen @gdabski