Wildfly 40.0.0.Final Micrometer Histogram + Percentiles

[Office Aizaz]

Hi,

Does Wildfly 40.0.0.Final with extension micrometer and prometheus registry configuration support historgram or percentile statistic generation?

I tried the following code:
        Timer timer = Timer.builder("jobs.processing.time")
                               .description("Job processing duration")
                               .publishPercentileHistogram()
                               .serviceLevelObjectives(
                                       Duration.ofMillis(10),
                                       Duration.ofMillis(50),
                                       Duration.ofMillis(100),
                                       Duration.ofMillis(200),
                                       Duration.ofMillis(500),
                                       Duration.ofSeconds(1)
                               )
                               .register(meterRegistry);

        timer.record(() -> service.hello(name));

I do not see any buckets i.e. _buckets{} metric when running the quick-start application configured with Micrometer (extension/addon) with promethes registry:

Plugin:

<plugin>
<groupId>org.wildfly.plugins</groupId>
<artifactId>wildfly-maven-plugin</artifactId>
<version>${version.wildfly.maven.plugin}</version>
<configuration>
<discover-provisioning-info>
<version>${version.wildfly.bom}</version>
<!-- A workaround for WFLY-18955 -->
<add-ons>
<add-on>micrometer</add-on>
</add-ons>
</discover-provisioning-info>
<!-- use cli script(s) to configure the server -->
<packaging-scripts>
<packaging-script>
<scripts>
<script>${basedir}/configure-micrometer.cli</script>
</scripts>
<resolve-expressions>false</resolve-expressions>
</packaging-script>
</packaging-scripts>
</configuration>
<executions>
<execution>
<goals>
<goal>package</goal>
</goals>

</execution>
</executions>
</plugin>

CLI Script:

# CLI script to enable micrometer for the quickstart application in the application server
if (outcome != success) of /extension=org.wildfly.extension.micrometer:read-resource
/extension=org.wildfly.extension.micrometer:add
/subsystem=micrometer:add()
end-if

# Configure the endpoint for metrics publication
/subsystem=micrometer/registry=prometheus:add(context="/metrics", security-enabled="false")

Regards,
Fahad

[Jason Lee]

I’m not sure off hand. The answer seems like it should be “it should” :) but I’ll have to check. Give me a bit to do some digging.

--
You received this message because you are subscribed to the Google Groups "WildFly" group.
To unsubscribe from this group and stop receiving emails from it, send an email to wildfly+u...@googlegroups.com.
To view this discussion visit https://groups.google.com/d/msgid/wildfly/de3a4cfd-a51b-495e-b71a-144dbbbff84bn%40googlegroups.com.

-- 
Jason Lee
Principal Software Engineer
IBM Java Middleware
Java Champion

[Jason Lee]

OK. I updated the Micrometer QS by adding this to RootResource.java:

    @GET

    @Path("/timer")

    public Response timer() {

        System.err.println("blargh: /timer");

        Timer timer = Timer.builder("jobs.processing.time")

                .description("Job processing duration")

                .publishPercentileHistogram()

                .serviceLevelObjectives(

                        Duration.ofMillis(10),

                        Duration.ofMillis(50),

                        Duration.ofMillis(100),

                        Duration.ofMillis(200),

                        Duration.ofMillis(500),

                        Duration.ofSeconds(1)

                )

                .register(registry);

        timer.record(this::mockService);

        return Response.ok().build();

    }

    protected void mockService() {

        try {

            Thread.sleep(500);

        } catch (InterruptedException e) {

            //

        }

    }

Then, following the instructions in README.adoc, I started an instance of WildFly (41.0.0.Beta1-SNAPSHOT, since that’s what I had handy) as well as the OpenTelemetry Collector. With those running, I did this:

$ curl http://localhost:8080/micrometer/timer

...

$ curl -s http://localhost:1234/metrics | grep "_bucket"

jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="micrometer.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="+Inf"} 1

prime_timer_milliseconds_bucket{WF_DEPLOYMENT="micrometer.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="+Inf"} 1

I do see two _bucket entries, so am I looking at the wrong thing? Or looking at things wrong..ly? :)

[Office Aizaz]

Hi Jason,

Thank you for looking into it. I must admit I overlooked the option of using otel collector and pushing metrics to it. So I re-created the example, this time with otel collector and appropriate standalone.xml. I used simply the getting started (micrometer) guide without any manual manipulation. Well it works as you already showed in your response.

The only difference I found was instead of two metrics, I only see the following:
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="+Inf"} 5

The following metric does not exist. It may be due to some difference in the setup but thats fine.
prime_timer_milliseconds_bucket

However the main issue that I have found so far is when WF40 is confugured with micrometer subsystem with prometheus registry. Looking at the admin guide:
https://docs.wildfly.org/40/Admin_Guide.html#Micrometer_Metrics

<qoute>

This subsystem exposes metrics from the WildFly Management Model and JVM MBeans, as well as end-user deployments via the Micrometer API now exposed by the server. Metrics are made available via Micrometer Registries, and WildFly supports two of these:

• OTLP - a push-based registry that publishes data periodically to the configured OpenTelemetry Collector

• Prometheus - a pull-based registry that allows for metrics to be pulled (or scraped) by an external process

Prometheus Registry

To install the Prometheus registry, execute this command:
[standalone@localhost:9990 /] /subsystem=micrometer/registry=prometheus:add(context="/metrics")

This will create a context on the management interface from which metrics can be scraped. For example, the above configuration would result in a URL that looks like http://localhost:9090/metrics. If you have not disabled the WildFly Metrics subsystem, you will not be able to use /metrics as your context, as that is already configured. To disable the WildFly Metrics Subsystem, see the remove commands above.

</qoute>

Additionally to this configuration, I simply added extra attibute to CLI script to disable security (security-enable="false"); in order to access it without creating a management user.  
There are multiple ways now to start the server and test. I only did the following:
- java 21
- mvn clean package
- ./target/server/bin/standalone.sh

curl http://localhost:8080/hello/Hello1234

I can see in the logs, the GET request got executed. I can see the job_processing_time_xxx metrics at http://localhost:9990/metrics; but buckets are missing.

Now I am not sure, if there is an issue with WF40 or is this something missing in my setup. I went through all possible documentation but all in vain.
I have attached both setups (minimal viable examples) with this email. If you don't mind checking whether it works for you with prometheus registry as well?

Regards,
Fahad
 

[Office Aizaz]

Sorry I forgot to answer the following question

<qoute>

$ curl -s http://localhost:1234/metrics | grep "_bucket"
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="micrometer.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="+Inf"} 1
prime_timer_milliseconds_bucket{WF_DEPLOYMENT="micrometer.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="+Inf"} 1

I do see two _bucket entries, so am I looking at the wrong thing? Or looking at things wrong..ly? :)

</qoute>

The bucket metric is there, but what it shows essentially is wrong. Each HTTP call should take 500ms. However the bucket is not build correctly: le="+Inf"
Expectation is something like:

jobs_processing_time_seconds_bucket{le="0.1"} ...
jobs_processing_time_seconds_bucket{le="0.5"} ...

Seems like an issue/problem to me.

Regards,
Fahad

[Markus Schulz]

Jason, did you remember this one here ;)

(i've made a mistake on the first rebase-op and opened a second pr)

The ApplicationRegistryWrapper missed to pass the config for all histogram based metrics.

regards, 

msc

[Office Aizaz]

Hi Markus,

I think that answers the question. The Jira issue https://redhat.atlassian.net/browse/WFLY-21339 also clarifies the problem I am seeing.
Hopefully, with WF41, the issue shall be resolved.

Regards,
Fahad

[Jason Lee]

Hi, Markus. Thanks, but I actually had not. I *probably* should have tested on a build without that one to verify before and after. Several plates spinning at the moment and was trying to get a quick answer. :P

Fahad, can you try with a 41 nightly? We _are_ prepping to release a beta for 41, but it will be a few days before that is released. If 41 (nightly or beta) doesn’t fix your problem, we might have time for more work on it before 41 final.

To view this discussion visit https://groups.google.com/d/msgid/wildfly/27a18b6b-f390-4158-acde-7df3e27f3f20n%40googlegroups.com.

[Office Aizaz]

Hi Jason,

I tested it with wildfly-41.0.0.Beta1-SNAPSHOT (nightly build). I can confirm that the behaviour of micrometer (percentiles/histograms) remains unchanged. The metric abcd_bucket is published but it does not reflect actual expected statistics.

Regards,
Fahad

To view this discussion visit https://groups.google.com/d/msgid/wildfly/9370B577-33A5-4688-949E-147B996BE9D3%40redhat.com.

[Jason Lee]

OK. Thanks. I will get to that as quickly as I can.

[Office Aizaz]

Hello Jason,

I tested it again today with the latest nightly build.
08:46:09,513 INFO  [org.jboss.modules] (main) JBoss Modules version 2.1.6.Final
08:46:09,734 INFO  [org.jboss.msc] (main) JBoss MSC version 1.5.6.Final
08:46:09,800 INFO  [org.jboss.as] (MSC service thread 1-3) WFLYSRV0049: WildFly 41.0.0.Beta1-SNAPSHOT (WildFly Core 33.0.0.Beta4) starting

And I can see the statistics now.

# HELP jobs_processing_time_milliseconds Time spent processing jobs
# TYPE jobs_processing_time_milliseconds histogram
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="1"} 0

...
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="357.913941"} 0
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="447.392426"} 0
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="536.870911"} 8
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="626.349396"} 8
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="715.827881"} 8
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="805.306366"} 8
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="894.784851"} 8
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="984.263336"} 8
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="1073.741824"} 8
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="1431.655765"} 8
...
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="28633.115306"} 8
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="30000"} 8
jobs_processing_time_milliseconds_bucket{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version="",le="+Inf"} 8
jobs_processing_time_milliseconds_sum{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version=""} 4000.771224
jobs_processing_time_milliseconds_count{WF_DEPLOYMENT="ROOT.war",job="wildfly",otel_scope_name="",otel_scope_schema_url="",otel_scope_version=""} 8

Seems to be working after the pull request from Markus got merged.

Thanks and Regards,
Fahad