eclipse / microprofile-metrics

microprofile-metrics
Apache License 2.0
100 stars 66 forks source link

Timer base unit is seconds #725

Closed Channyboy closed 1 year ago

Channyboy commented 1 year ago

fixes #724

jgallimore commented 1 year ago

I'm ok with this change and generally happy to approve it. Just to make sure my understanding is correct - this only affects the values we'd get from the snapshots (the stop() method on Context above would still return in nanoseconds?), and wouldn't affect the prometheus output, or the granularity that implementations would capture the timings at?

donbourne commented 1 year ago

looking at behavior from MP Metrics 4.0, even with the units specified as "seconds" in the Timer annotation the values returned in the Timer's snapshot are always in nanoseconds:

    @Path("timed2")
    @Timed(name = "timed-request222",unit = "seconds")
    @GET
    public String timedRequest2() throws InterruptedException {

        int wait = new Random().nextInt(1000);
        Thread.sleep(wait);

        SortedMap<MetricID, Timer> timers = metricRegistry.getTimers();
        for (MetricID mid : timers.keySet()) {
            System.out.println(mid);
        }

        Timer t = metricRegistry.getTimer(new MetricID("com.example.demo.metric.MetricController.timed-request222"));
        long[] values = t.getSnapshot().getValues();
        String vstr = "Values:\n";
        for (long v : values) {
            vstr += v + "\n";
        }
        System.out.println(vstr);

        System.out.println("75th percentile:" + t.getSnapshot().get75thPercentile());
        System.out.println("max:" + t.getSnapshot().getMax());
        System.out.println("mean:" + t.getSnapshot().getMean());

        return "Request2 is used in statistics, check with the Metrics call.\n";
    }

results in:

MetricID{name='com.example.demo.metric.MetricController.timed-request', tags=[]}
[INFO] MetricID{name='com.example.demo.metric.MetricController.timed-request222', tags=[]}
[INFO] Values:
[INFO] 155007364
[INFO] 165321846
[INFO] 314078968
[INFO] 454136472
[INFO] 529411374
[INFO] 581802637
[INFO] 690137171
[INFO] 838741836
[INFO] 953674612
[INFO] 999309895
[INFO] 75th percentile:8.38741836E8
[INFO] max:999309895
[INFO] mean:5.692408266253115E8

so basically the units specified in the metadata of a Timer are ignored.