Custom metrics via APM Java agent Micrometer integration are missing

Kibana version: 7.9.1
Elasticsearch version: 7.9.1
APM Server version: 7.9.1
APM Agent: Java agent 1.18.0
Java version: 1.8.0_172
Micrometer version: 1.5.5
Browser version: N/A
Original install method: docker-compose recipe
Fresh install

I'm trying to take the Micrometer automatic integration via the Java APM agent for a spin as described here: https://www.elastic.co/guide/en/apm/agent/java/current/metrics.html#metrics-micrometer. Everything looks fine all the way through the v2 intake API, but I see no metrics, nor any errors apparent in the docker console output. In particular I was somewhat expecting a "Metrics" section to appear under my service name in APM, much the same way it does when enabling APM internal instrumentation:

Steps to reproduce:

  1. Install via docker-compose recipe provided in the APM->Deploy->Docker documentation. The docker-compose.yaml I'm using is at the end of this description.
  2. Configure the agent(just running app via Maven exec), args provided below:
<argument>-javaagent:/Users/__/Downloads/elastic-apm-agent-1.18.0.jar</argument>
<argument>-Delastic.apm.service_name=foo</argument>
<argument>-Delastic.apm.log_level=TRACE</argument>
<argument>-Delastic.apm.log_file=${APP_INSTALLDIR}/logs/apm.log</argument>
<argument>-Delastic.apm.server_urls=http://localhost:8200</argument>
<argument>-Delastic.apm.secret_token=</argument>
<argument>-Delastic.apm.secret_token=</argument>
<argument>-Delastic.apm.application_packages=com.foo</argument>

Relevant logs:
On the app with the agent instrumented things look like they are working:

2020-10-01 13:59:42,529 [elastic-apm-shared] DEBUG co.elastic.apm.agent.micrometer.MicrometerMetricsReporter - Reporting 2 meters
2020-10-01 13:59:42,532 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Receiving JSON_WRITER event (sequence 7)
2020-10-01 13:59:42,532 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Starting new request to http://localhost:8200/intake/v2/events
2020-10-01 13:59:42,535 [elastic-apm-server-reporter] DEBUG co.elastic.apm.agent.report.IntakeV2ReportingEventHandler - Scheduling request timeout in 10s

Logs on APM server from docker console look fine:

apm-server_1     | 2020-10-01T22:17:22.246Z	INFO	[request]	middleware/log_middleware.go:97	request accepted	{"request_id": "bc67138c-95ed-4c4b-bae6-d66e7668e5f4", "method": "POST", "URL": "/intake/v2/events", "content_length": -1, "remote_address": "pipe", "user-agent": "elasticapm-go/1.8.0 go/go1.13.10", "response_code": 202}

But I can find no trace of the metrics in the APM or metricsbeat indices. Here are the indices I see:

    yellow open metricbeat-7.9.2-2020.10.01-000001 WdPuUySjRvKek6MtyWGiJw 1 1 44097   0  14.9mb  14.9mb
    green  open .kibana-event-log-7.9.1-000001     Z78jQyAwQrePBj7duE-c5A 1 0     3   0  16.2kb  16.2kb
    green  open .apm-agent-configuration           sKfk7YeuTD6Qu2x0UNFl1A 1 0     0   0    208b    208b
    green  open apm-7.9.1-transaction-000001       jiztdQ4GTO-9fweHA_ZnqQ 1 0 13731   0   3.5mb   3.5mb
    green  open apm-7.9.1-profile-000001           Zfblu9xqS2KCudW0L5AqUw 1 0     0   0    208b    208b
    green  open apm-7.9.1-metric-000001            JZEWHg2zQy6ErHBBwlosWg 1 0 43777   0  10.4mb  10.4mb
    green  open .kibana_1                          s0uvxRk5SRuIZ3t0BI6QXw 1 0   218 184  10.9mb  10.9mb
    green  open .apm-custom-link                   SERxmsd0QQKE0B4q61etOw 1 0     0   0    208b    208b
    green  open apm-7.9.1-onboarding-2020.10.01    eYmOai86Tza_gJqpPPNjdA 1 0     1   0   6.8kb   6.8kb
    green  open .kibana_task_manager_1             59BToU3ASM6trf6q_MR3NQ 1 0     6 119 609.8kb 609.8kb
    green  open apm-7.9.1-onboarding-2020.09.28    yGvoFY4dRdm-8iD5q-2OEA 1 0     1   0   6.8kb   6.8kb
    green  open apm-7.9.1-onboarding-2020.09.29    z2KNeJe9R1qvTj2f16E0eQ 1 0     1   0   6.8kb   6.8kb
    green  open apm-7.9.1-span-000001              zJhu2o4mQYWqfFzkvfYw3A 1 0  2139   0   507kb   507kb
    green  open .async-search                      utsuqrkaTKyYwXXk3VnUZw 1 0    15   2   2.5mb   2.5mb
    green  open apm-7.9.1-error-000001             NFDPNByCRPS9czDLNWJcgw 1 0    91   0 140.7kb 140.7kb

docker-compose.yaml:

    version: '2.2'
    services:
      apm-server:
        image: docker.elastic.co/apm/apm-server:7.9.1
        depends_on:
          elasticsearch:
            condition: service_healthy
          kibana:
            condition: service_healthy
        cap_add: ["CHOWN", "DAC_OVERRIDE", "SETGID", "SETUID"]
        cap_drop: ["ALL"]
        ports:
        - 8200:8200
        networks:
        - elastic
        command: >
           apm-server -e
             -E apm-server.rum.enabled=true
             -E apm-server.instrumentation.enabled=true
             -E apm-server.register.ingest.pipeline.enabled=true
             -E setup.kibana.host=kibana:5601
             -E setup.template.settings.index.number_of_replicas=0
             -E apm-server.kibana.enabled=true
             -E apm-server.kibana.host=kibana:5601
             -E output.elasticsearch.hosts=["elasticsearch:9200"]
        healthcheck:
          interval: 10s
          retries: 12
          test: curl --write-out 'HTTP %{http_code}' --fail --silent --output /dev/null http://localhost:8200/

      elasticsearch:
        image: docker.elastic.co/elasticsearch/elasticsearch:7.9.1
        environment:
        - bootstrap.memory_lock=true
        - cluster.name=docker-cluster
        - cluster.routing.allocation.disk.threshold_enabled=false
        - discovery.type=single-node
        - ES_JAVA_OPTS=-XX:UseAVX=2 -Xms1g -Xmx1g
        ulimits:
          memlock:
            hard: -1
            soft: -1
        volumes:
        - esdata:/usr/share/elasticsearch/data
        ports:
        - 9200:9200
        networks:
        - elastic
        healthcheck:
          interval: 20s
          retries: 10
          test: curl -s http://localhost:9200/_cluster/health | grep -vq '"status":"red"'

      kibana:
        image: docker.elastic.co/kibana/kibana:7.9.1
        depends_on:
          elasticsearch:
            condition: service_healthy
        environment:
          ELASTICSEARCH_URL: http://elasticsearch:9200
          ELASTICSEARCH_HOSTS: http://elasticsearch:9200
        ports:
        - 5601:5601
        networks:
        - elastic
        healthcheck:
          interval: 10s
          retries: 20
          test: curl --write-out 'HTTP %{http_code}' --fail --silent --output /dev/null http://localhost:5601/api/status

    volumes:
      esdata:
        driver: local

    networks:
      elastic:
        driver: bridge

Should there be a metrics- index? Anything else I'm missing on config to get custom metrics to appear? Other troubleshooting tips?

Your micrometer metrics should be in this index:

When setting the log_level to trace, you should also be able to see the sent metrics in the agent logs.

Also, please not that if you use an application that has hikaricp connection pool, we have a known issue with micrometer integration https://github.com/elastic/apm/issues/347. If that's the case, using the workaround described in the issue should make it work.

If that's the case, you should have warnings in apm-server logs, thus please check that first to make sure it's the issue.

I am seeing the metrics in APM agent logs. Example:

2020-10-02 10:34:19,869 [elastic-apm-server-reporter] TRACE co.elastic.apm.agent.report.serialize.DslJsonSerializer - {"metricset":{"timestamp":1601660049857000,"samples":{"my.metric.timer.count":{"value":0},"my.metric.timer.sum.us":{"value":0.0},"other.custom.metric.timer.count":{"value":0},"other.custom.metric.timer.sum.us":{"value":0.0}}}}

Other metrics(JVM metrics for example) are ending up stored in Elastic just fine in the apm-7.9.1-metric-000001 index, and hikaricp is not in use, so doesn't appear to be related to that issue.

Querying for those metrics in that index is turning up nothing:

GET apm-7.9.1-metric/_search
{
  "query": {
    "exists": {
      "field": "metricset.samples.my.metric.timer.sum.us"
    }
  }
}

Nor do I see that query matching anything in other indices. In case of replacing . with _ I also checked for field metricset.samples.my_metric_timer.sum.us with no matches. And just tried renaming the metrics with underscores, and still don't see any custom metrics stored.

Thoughts on next trouble shooting steps?

Could you try to search indices using wildcards?

@felixbarny turns out the query side issue was the top level fields that get indexed are doing some transforms before persisting. Meaning I expected I needed to include metricset.samples.etc based on the raw JSON from the agent side logs. If I just search for:

GET apm-7.9.1-metric/_search
{
  "query": {
    "exists": {
      "field": "my_timer.count"
    }
  }
}

I get hits, so the data is there. However, I still don't see how to leverage these in the Metrics or APM app. The metrics don't show up in the Metrics Explorer, nor do I see where I'd leverage these from the APM app perspective. Are there some additional steps or doc I'm missing on how to associate my custom metrics with a service?

I'll take a closer look at what the APM app internal metrics are doing to see if there are any clues there. Meaning I see an obvious launching point for that service into its metrics, whereas for my app, I see nothing:

We don't have a good tutorial for that at the moment but I'd recommend to create a Kibana visualization using Lens or TSVB (Time Series Visual Builder).

OK. It's not very cohesive that we can't just create dashboards underneath the APM app and have those dashboards consist of both metrics provided by the APM agent itself, and other custom metrics reported through the agent(like those reported through the Micrometer instrumentation). :disappointed:

But I'll look into those other options for now. Thanks!

I completely agree with you on that. We're thinking about tighter integrations going forward. But in the meantime, this is hopefully better than having no custom metrics integration at all.