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.

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

http_server_requests metrics missing with spring boot 2.7.0 in the cloud #3207

Closed
headfox23 opened this issue Jun 3, 2022 · 14 comments
Closed
Labels
for: external-project For an external project and not something we can fix

Comments

@headfox23
Copy link

Describe the bug
If I deploy an application with spring boot 2.7.0 and micrometer prometheus exporter to cloud foundry, the http_server_requests* metrics are missing.

Environment

  • Micrometer version 1.9.0
  • Micrometer registry prometheus
  • OS: Linux
  • Java version: 11

To Reproduce
How to reproduce the bug:
https://github.com/headfox23/spring-boot-micrometer-test reproduces this issue.

Expected behavior
I expect to see this:

# HELP http_server_requests_seconds  
# TYPE http_server_requests_seconds histogram
http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",le="0.5",} 7.0
http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",le="1.0",} 7.0
http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",le="2.0",} 7.0
http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",le="5.0",} 7.0
http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",le="10.0",} 7.0
http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",le="15.0",} 7.0
http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",le="30.0",} 7.0
http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",le="+Inf",} 7.0
http_server_requests_seconds_count{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",} 7.0
http_server_requests_seconds_sum{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/actuator/prometheus",} 0.097961682

Additional context
If i run the example locally it works fine...

@headfox23
Copy link
Author

Current export:

# HELP tomcat_sessions_active_current_sessions  
# TYPE tomcat_sessions_active_current_sessions gauge
tomcat_sessions_active_current_sessions 0.0
# HELP zipkin_reporter_messages_dropped_total  
# TYPE zipkin_reporter_messages_dropped_total counter
zipkin_reporter_messages_dropped_total{cause="ResourceAccessException",} 4.0
# HELP jvm_gc_live_data_size_bytes Size of long-lived heap memory pool after reclamation
# TYPE jvm_gc_live_data_size_bytes gauge
jvm_gc_live_data_size_bytes 0.0
# HELP jvm_threads_peak_threads The peak live thread count since the Java virtual machine started or peak was reset
# TYPE jvm_threads_peak_threads gauge
jvm_threads_peak_threads 25.0
# HELP zipkin_reporter_spans_dropped_total Spans dropped (failed to report)
# TYPE zipkin_reporter_spans_dropped_total counter
zipkin_reporter_spans_dropped_total 5.0
# HELP tomcat_sessions_rejected_sessions_total  
# TYPE tomcat_sessions_rejected_sessions_total counter
tomcat_sessions_rejected_sessions_total 0.0
# HELP executor_pool_max_threads The maximum allowed number of threads in the pool
# TYPE executor_pool_max_threads gauge
executor_pool_max_threads{name="applicationTaskExecutor",} 2.147483647E9
# HELP executor_active_threads The approximate number of threads that are actively executing tasks
# TYPE executor_active_threads gauge
executor_active_threads{name="applicationTaskExecutor",} 0.0
# HELP executor_pool_core_threads The core number of threads for the pool
# TYPE executor_pool_core_threads gauge
executor_pool_core_threads{name="applicationTaskExecutor",} 8.0
# HELP jvm_buffer_total_capacity_bytes An estimate of the total capacity of the buffers in this pool
# TYPE jvm_buffer_total_capacity_bytes gauge
jvm_buffer_total_capacity_bytes{id="mapped",} 0.0
jvm_buffer_total_capacity_bytes{id="direct",} 81920.0
# HELP executor_queued_tasks The approximate number of tasks that are queued for execution
# TYPE executor_queued_tasks gauge
executor_queued_tasks{name="applicationTaskExecutor",} 0.0
# HELP jvm_memory_max_bytes The maximum amount of memory in bytes that can be used for memory management
# TYPE jvm_memory_max_bytes gauge
jvm_memory_max_bytes{area="nonheap",id="CodeHeap 'profiled nmethods'",} 1.22028032E8
jvm_memory_max_bytes{area="heap",id="G1 Survivor Space",} -1.0
jvm_memory_max_bytes{area="heap",id="G1 Old Gen",} 1.476395008E9
jvm_memory_max_bytes{area="nonheap",id="Metaspace",} 1.4757888E8
jvm_memory_max_bytes{area="nonheap",id="CodeHeap 'non-nmethods'",} 7598080.0
jvm_memory_max_bytes{area="heap",id="G1 Eden Space",} -1.0
jvm_memory_max_bytes{area="nonheap",id="Compressed Class Space",} 1.39190272E8
jvm_memory_max_bytes{area="nonheap",id="CodeHeap 'non-profiled nmethods'",} 1.22032128E8
# HELP jvm_buffer_count_buffers An estimate of the number of buffers in the pool
# TYPE jvm_buffer_count_buffers gauge
jvm_buffer_count_buffers{id="mapped",} 0.0
jvm_buffer_count_buffers{id="direct",} 10.0
# HELP process_cpu_usage The "recent cpu usage" for the Java Virtual Machine process
# TYPE process_cpu_usage gauge
process_cpu_usage 0.02027027027027027
# HELP process_files_max_files The maximum file descriptor count
# TYPE process_files_max_files gauge
process_files_max_files 16384.0
# HELP zipkin_reporter_messages_bytes_total Total bytes of messages reported
# TYPE zipkin_reporter_messages_bytes_total counter
zipkin_reporter_messages_bytes_total 1847.0
# HELP executor_completed_tasks_total The approximate total number of tasks that have completed execution
# TYPE executor_completed_tasks_total counter
executor_completed_tasks_total{name="applicationTaskExecutor",} 0.0
# HELP jvm_memory_used_bytes The amount of used memory
# TYPE jvm_memory_used_bytes gauge
jvm_memory_used_bytes{area="nonheap",id="CodeHeap 'profiled nmethods'",} 1.943552E7
jvm_memory_used_bytes{area="heap",id="G1 Survivor Space",} 8388608.0
jvm_memory_used_bytes{area="heap",id="G1 Old Gen",} 3.1295048E7
jvm_memory_used_bytes{area="nonheap",id="Metaspace",} 5.6124216E7
jvm_memory_used_bytes{area="nonheap",id="CodeHeap 'non-nmethods'",} 1293696.0
jvm_memory_used_bytes{area="heap",id="G1 Eden Space",} 5.4525952E7
jvm_memory_used_bytes{area="nonheap",id="Compressed Class Space",} 6864296.0
jvm_memory_used_bytes{area="nonheap",id="CodeHeap 'non-profiled nmethods'",} 7258112.0
# HELP jvm_classes_loaded_classes The number of classes that are currently loaded in the Java virtual machine
# TYPE jvm_classes_loaded_classes gauge
jvm_classes_loaded_classes 10152.0
# HELP system_cpu_usage The "recent cpu usage" of the system the application is running in
# TYPE system_cpu_usage gauge
system_cpu_usage 0.01761482331081081
# HELP application_ready_time_seconds Time taken (ms) for the application to be ready to service requests
# TYPE application_ready_time_seconds gauge
application_ready_time_seconds{main_application_class="com.example.MicrometerTest",} 8.411
# HELP logback_events_total Number of error level events that made it to the logs
# TYPE logback_events_total counter
logback_events_total{level="warn",} 3.0
logback_events_total{level="debug",} 2337.0
logback_events_total{level="error",} 0.0
logback_events_total{level="trace",} 0.0
logback_events_total{level="info",} 6.0
# HELP process_files_open_files The open file descriptor count
# TYPE process_files_open_files gauge
process_files_open_files 105.0
# HELP jvm_gc_memory_promoted_bytes_total Count of positive increases in the size of the old generation memory pool before GC to after GC
# TYPE jvm_gc_memory_promoted_bytes_total counter
jvm_gc_memory_promoted_bytes_total 1.1063408E7
# HELP jvm_threads_live_threads The current number of live threads including both daemon and non-daemon threads
# TYPE jvm_threads_live_threads gauge
jvm_threads_live_threads 25.0
# HELP tomcat_sessions_active_max_sessions  
# TYPE tomcat_sessions_active_max_sessions gauge
tomcat_sessions_active_max_sessions 0.0
# HELP jvm_gc_max_data_size_bytes Max size of long-lived heap memory pool
# TYPE jvm_gc_max_data_size_bytes gauge
jvm_gc_max_data_size_bytes 1.476395008E9
# HELP jvm_threads_daemon_threads The current number of live daemon threads
# TYPE jvm_threads_daemon_threads gauge
jvm_threads_daemon_threads 20.0
# HELP application_started_time_seconds Time taken (ms) to start the application
# TYPE application_started_time_seconds gauge
application_started_time_seconds{main_application_class="com.example.MicrometerTest",} 8.371
# HELP process_uptime_seconds The uptime of the Java virtual machine
# TYPE process_uptime_seconds gauge
process_uptime_seconds 1559.516
# HELP zipkin_reporter_spans_total Spans reported
# TYPE zipkin_reporter_spans_total counter
zipkin_reporter_spans_total 5.0
# HELP zipkin_reporter_queue_bytes Total size of all encoded spans queued for reporting
# TYPE zipkin_reporter_queue_bytes gauge
zipkin_reporter_queue_bytes 0.0
# HELP tomcat_sessions_created_sessions_total  
# TYPE tomcat_sessions_created_sessions_total counter
tomcat_sessions_created_sessions_total 0.0
# HELP process_start_time_seconds Start time of the process since unix epoch.
# TYPE process_start_time_seconds gauge
process_start_time_seconds 1.654255578793E9
# HELP jvm_memory_committed_bytes The amount of memory in bytes that is committed for the Java virtual machine to use
# TYPE jvm_memory_committed_bytes gauge
jvm_memory_committed_bytes{area="nonheap",id="CodeHeap 'profiled nmethods'",} 1.9464192E7
jvm_memory_committed_bytes{area="heap",id="G1 Survivor Space",} 8388608.0
jvm_memory_committed_bytes{area="heap",id="G1 Old Gen",} 5.767168E7
jvm_memory_committed_bytes{area="nonheap",id="Metaspace",} 5.8589184E7
jvm_memory_committed_bytes{area="nonheap",id="CodeHeap 'non-nmethods'",} 3211264.0
jvm_memory_committed_bytes{area="heap",id="G1 Eden Space",} 8.2837504E7
jvm_memory_committed_bytes{area="nonheap",id="Compressed Class Space",} 7733248.0
jvm_memory_committed_bytes{area="nonheap",id="CodeHeap 'non-profiled nmethods'",} 7274496.0
# HELP zipkin_reporter_messages_total Messages reported (or attempted to be reported)
# TYPE zipkin_reporter_messages_total counter
zipkin_reporter_messages_total 4.0
# HELP jvm_gc_overhead_percent An approximation of the percent of CPU time used by GC activities over the last lookback period or since monitoring began, whichever is shorter, in the range [0..1]
# TYPE jvm_gc_overhead_percent gauge
jvm_gc_overhead_percent 0.0
# HELP jvm_memory_usage_after_gc_percent The percentage of long-lived heap pool used after the last GC event, in the range [0..1]
# TYPE jvm_memory_usage_after_gc_percent gauge
jvm_memory_usage_after_gc_percent{area="heap",pool="long-lived",} 0.021196934309872715
# HELP jvm_buffer_memory_used_bytes An estimate of the memory that the Java virtual machine is using for this buffer pool
# TYPE jvm_buffer_memory_used_bytes gauge
jvm_buffer_memory_used_bytes{id="mapped",} 0.0
jvm_buffer_memory_used_bytes{id="direct",} 81920.0
# HELP executor_pool_size_threads The current number of threads in the pool
# TYPE executor_pool_size_threads gauge
executor_pool_size_threads{name="applicationTaskExecutor",} 0.0
# HELP disk_free_bytes Usable space for path
# TYPE disk_free_bytes gauge
disk_free_bytes{path="/home/vcap/app/.",} 8.85243904E8
# HELP jvm_gc_memory_allocated_bytes_total Incremented for an increase in the size of the (young) heap memory pool after one GC to before the next
# TYPE jvm_gc_memory_allocated_bytes_total counter
jvm_gc_memory_allocated_bytes_total 3.17718528E8
# HELP disk_total_bytes Total space for path
# TYPE disk_total_bytes gauge
disk_total_bytes{path="/home/vcap/app/.",} 1.073741824E9
# HELP jvm_gc_pause_seconds Time spent in GC pause
# TYPE jvm_gc_pause_seconds summary
jvm_gc_pause_seconds_count{action="end of minor GC",cause="G1 Evacuation Pause",} 5.0
jvm_gc_pause_seconds_sum{action="end of minor GC",cause="G1 Evacuation Pause",} 0.078
# HELP jvm_gc_pause_seconds_max Time spent in GC pause
# TYPE jvm_gc_pause_seconds_max gauge
jvm_gc_pause_seconds_max{action="end of minor GC",cause="G1 Evacuation Pause",} 0.0
# HELP jvm_classes_unloaded_classes_total The total number of classes unloaded since the Java virtual machine has started execution
# TYPE jvm_classes_unloaded_classes_total counter
jvm_classes_unloaded_classes_total 0.0
# HELP tomcat_sessions_expired_sessions_total  
# TYPE tomcat_sessions_expired_sessions_total counter
tomcat_sessions_expired_sessions_total 0.0
# HELP system_load_average_1m The sum of the number of runnable entities queued to available processors and the number of runnable entities running on the available processors averaged over a period of time
# TYPE system_load_average_1m gauge
system_load_average_1m 2.62
# HELP zipkin_reporter_spans_bytes_total Total bytes of encoded spans reported
# TYPE zipkin_reporter_spans_bytes_total counter
zipkin_reporter_spans_bytes_total 1838.0
# HELP zipkin_reporter_queue_spans Spans queued for reporting
# TYPE zipkin_reporter_queue_spans gauge
zipkin_reporter_queue_spans 0.0
# HELP executor_queue_remaining_tasks The number of additional elements that this queue can ideally accept without blocking
# TYPE executor_queue_remaining_tasks gauge
executor_queue_remaining_tasks{name="applicationTaskExecutor",} 2.147483647E9
# HELP jvm_threads_states_threads The current number of threads having NEW state
# TYPE jvm_threads_states_threads gauge
jvm_threads_states_threads{state="runnable",} 8.0
jvm_threads_states_threads{state="blocked",} 0.0
jvm_threads_states_threads{state="waiting",} 13.0
jvm_threads_states_threads{state="timed-waiting",} 4.0
jvm_threads_states_threads{state="new",} 0.0
jvm_threads_states_threads{state="terminated",} 0.0
# HELP system_cpu_count The number of processors available to the Java virtual machine
# TYPE system_cpu_count gauge
system_cpu_count 16.0
# HELP tomcat_sessions_alive_max_seconds  
# TYPE tomcat_sessions_alive_max_seconds gauge
tomcat_sessions_alive_max_seconds 0.0

@shakuzen
Copy link
Member

shakuzen commented Jun 3, 2022

Are you sending requests to the application before checking the metrics when deploying? The http server metrics won't show up until a request has been processed. The first time you request the prometheus endpoint, it won't have http server metrics for itself, because it is returning the metrics before the timing of the request to the prometheus endpoint completes.

@shakuzen shakuzen added the waiting for feedback We need additional information before we can continue label Jun 7, 2022
@ianff
Copy link

ianff commented Jun 8, 2022

Same here, even after sending a request to the endpoints, the prometheus endpoint does not display any http server metrics. Not sure if it's related to the spring-cloud-starter-kubernetes-client-config

@headfox23
Copy link
Author

Are you sending requests to the application before checking the metrics when deploying? The http server metrics won't show up until a request has been processed. The first time you request the prometheus endpoint, it won't have http server metrics for itself, because it is returning the metrics before the timing of the request to the prometheus endpoint completes.

Yes of course tested with requests on the API and on actuator itself...

@checketts
Copy link
Contributor

checketts commented Jun 8, 2022

OK. So I see it works locally (and I was able to run the sample locally and see the metrics), but the metric is missing when packaged and deployed to CloudFoundry. Can you add in details of your CF setup? What buildpack/Java version is being used? Are you deploying as a WAR or JAR?

Do you have the CF manifest or push command you are using?

@headfox23
Copy link
Author

We use cf push with manifest. Java buildpack.
I'll provide you the command and manifest in a moment.

@headfox23
Copy link
Author

Example manifest:

---
applications:
  - name: some_name...
    memory: 4G
    instances: 2
    buildpacks:
      - java_buildpack
    routes:
      - route: some_route...
    env:
      APP_VERSION: ((app_version))
      SPRING_PROFILES_ACTIVE: dev,ui,cloud
      JAVA_OPTS: '-XX:MaxDirectMemorySize=512M -server'
      JBP_CONFIG_SPRING_AUTO_RECONFIGURATION: '{enabled: false}'
      JBP_CONFIG_JMX: '{enabled: true}'
      JBP_CONFIG_OPEN_JDK_JRE: '{jre: { version: 11.+ }}'
      TZ: Europe/Amsterdam
    services:
      - some_services...

@headfox23
Copy link
Author

Example push command:

cf push -f some_name/manifest/manifest-${profile}.yml -p some_name/target/*${BUILD_NUMBER}.jar --var app_version="some_version"

@jonatan-ivanov
Copy link
Member

jonatan-ivanov commented Jun 8, 2022

Can it happen that there is a config source that you have in CF but you don't have locally (env var, property/yml file, vault, config server, git, etc.)?

Can you try to enable actuator and hit the /actuator/env endpoint?
Do you see any properties that could turn this off?

Also, you can try to diff the env and the beans endpoints between local and CF.

@stefanharke
Copy link

I had a similar issue with not receiving http_server_request metrics using Spring Boot 2.7.0.

As it turned out there is an issue in WebMvcMetricsFilter or, to be more precise, in its WebMvcMetricsAutoConfiguration introduced in 2.7.0 actuator. See the attached link for more information. Adding the recommended configuration solved the issue for me.

Maybe this is related to your problem, too.

spring-projects/spring-boot#31150

@shakuzen
Copy link
Member

@stefanharke thank you for sharing that.

Could folks seeing the issue reported here try with Spring Boot 2.7.1-SNAPSHOT to see if that fixes it?

@liul85
Copy link

liul85 commented Jun 10, 2022

I had this issue also, and it turned out to be an issue of Spring-boog 2.7.0 as @stefanharke mentioned here.

@liul85
Copy link

liul85 commented Jun 10, 2022

I tried 2.7.1-SNAPSHOT it worked, so you can use the workaround which is mentioned in the issue for now, then upgrade to 2.7.1 once it's released (23rd June).

@shakuzen shakuzen added for: external-project For an external project and not something we can fix and removed waiting for feedback We need additional information before we can continue labels Jun 10, 2022
@shakuzen
Copy link
Member

Thank you for checking the Spring Boot snapshots. I will close this issue as a duplicate of the issue in Spring Boot: spring-projects/spring-boot#31150

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
for: external-project For an external project and not something we can fix
Projects
None yet
Development

No branches or pull requests

7 participants