micrometer icon indicating copy to clipboard operation
micrometer copied to clipboard

TomcatMetrics fails when using snake case convention for PrometheusMeterRegistry

Open tjuchniewicz opened this issue 4 years ago • 2 comments

In simple Spring Boot 2.3 app that exposes metrics over Prometheus endpoint:

<dependency>
	<groupId>org.springframework.boot</groupId>
	<artifactId>spring-boot-starter-actuator</artifactId>
</dependency>
<dependency>
	<groupId>org.springframework.boot</groupId>
	<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
	<groupId>io.micrometer</groupId>
	<artifactId>micrometer-registry-prometheus</artifactId>
</dependency>

we enable MBean Registry to get Tomcat metrics:

server.tomcat.mbeanregistry.enabled=true

then we customize naming convention:

@Bean
public MeterRegistryCustomizer<MeterRegistry> prometheusNamingConvention() {
    return registry -> registry
            .config()
            .namingConvention(NamingConvention.snakeCase);
}

When we enable NamingConvention.snakeCase TomcatMetrics fails when registering tomcat_global_request_max metric:

java.lang.IllegalArgumentException: Collector already registered that provides name: tomcat_global_request_max
        at io.prometheus.client.CollectorRegistry.register(CollectorRegistry.java:54) ~[simpleclient-0.8.1.jar:na]
        at io.prometheus.client.Collector.register(Collector.java:139) ~[simpleclient-0.8.1.jar:na]
        at io.micrometer.prometheus.PrometheusMeterRegistry.lambda$applyToCollector$16(PrometheusMeterRegistry.java:408) ~[micrometer-registry-prometheus-1.5.9.jar:1.5.9]
        at java.base/java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1916) ~[na:na]
        at io.micrometer.prometheus.PrometheusMeterRegistry.applyToCollector(PrometheusMeterRegistry.java:404) ~[micrometer-registry-prometheus-1.5.9.jar:1.5.9]
        at io.micrometer.prometheus.PrometheusMeterRegistry.newGauge(PrometheusMeterRegistry.java:206) ~[micrometer-registry-prometheus-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.MeterRegistry.newTimeGauge(MeterRegistry.java:201) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.MeterRegistry$More.lambda$timeGauge$3(MeterRegistry.java:977) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.MeterRegistry.lambda$registerMeterIfNecessary$5(MeterRegistry.java:559) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.MeterRegistry.getOrCreateMeter(MeterRegistry.java:612) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:566) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:559) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.MeterRegistry.access$600(MeterRegistry.java:76) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.MeterRegistry$More.timeGauge(MeterRegistry.java:977) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.TimeGauge$Builder.register(TimeGauge.java:117) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.binder.tomcat.TomcatMetrics.lambda$registerGlobalRequestMetrics$33(TomcatMetrics.java:224) ~[micrometer-core-1.5.9.jar:1.5.9]
        at io.micrometer.core.instrument.binder.tomcat.TomcatMetrics.lambda$registerMetricsEventually$34(TomcatMetrics.java:237) ~[micrometer-core-1.5.9.jar:1.5.9]

This is due to following code executed in TomcatMetrics:

FunctionTimer.builder("tomcat.global.request", mBeanServer,
                    s -> safeLong(() -> s.getAttribute(name, "requestCount")),
                    s -> safeDouble(() -> s.getAttribute(name, "processingTime")), TimeUnit.MILLISECONDS)
                    .tags(allTags)
                    .register(registry);

TimeGauge.builder("tomcat.global.request.max", mBeanServer, TimeUnit.MILLISECONDS,
                    s -> safeDouble(() -> s.getAttribute(name, "maxTime")))
                    .tags(allTags)
                    .register(registry);

First statement registers following metrics in Prometheus:

  • tomcat_global_request_count
  • tomcat_global_request_sum
  • tomcat_global_request_max

Second statement fails with message above. It affects also tomcat.servlet.request.max metric.

Proposed change is to rename metric in second statement to tomcat.servlet.request.maxtime

Source code to reproduce this issue: https://github.com/tjuchniewicz/spring-boot-tomcat-metrics-issue

tjuchniewicz avatar Dec 15 '20 07:12 tjuchniewicz

Thank you for the detailed description and the minimal sample project to reproduce the issue - those were very helpful. This does indeed seem to be an issue and one we can fix, but I would like to take a step back and understand why are you overriding the PrometheusNamingConvention with a plain NamingConvention.snakeCase? The PrometheusNamingConvention delegates to a snake-case naming convention with some additional functionality specific to Prometheus.

shakuzen avatar Jan 12 '21 09:01 shakuzen

I discovered this issue in my Spring Boot library we share between many services. Some of them use statds registry (uses dots), others moved to prometheus registry (uses underscores). We wanted to force snake-case for both, We execute code above without analyzing what registry type is currently used.

So this fails only if we want do something really unnecessary. Please consider this as very low-priority or even mark as won't fix.

tjuchniewicz avatar Jan 12 '21 15:01 tjuchniewicz