micrometer: "Duplicate call to publish" error since 1.11.0-RC1
Describe the bug As part of some internal testing with our Dynatrace meter registry, I recently saw the following error message for the first time:
Publishing is already in progress. Skipping duplicate call to publish().
This log message was introduced in https://github.com/micrometer-metrics/micrometer/pull/3714 and first released with Micrometer 1.11.0-RC1.
I was trying to debug this a little bit, but it’s really hard to reproduce (which is a good thing, I guess 😄). One thing that I did find out was that some change in 1.11.0-RC1 seems to lead to multiple publishing threads being created. E.g., when running the registry with micrometer core version 1.9.10 (the default for Spring Boot 2.7.11), I get 1 thread named dynatrace-metrics-publisher
, which is responsible for pushing metrics every X seconds. The thread is created using the default thread factory, which is an instance of NamedThreadFactory. Everything is fine and seems to work in this version.
However, when I switch over to Micrometer 1.11.0-RC1, I suddenly have two publishing threads ( dynatrace-metrics-publisher
and dynatrace-metrics-publisher-2
). It, therefore, seems as if the NewThread method on the ThreadFactory is called twice. I am not quite sure how this happens, since I assume the threads are created here and the SingleThreadScheduledExecutor should not create two threads (maybe?).
I have also tried another registry (I randomly picked the elastic registry), and it seems to also be creating two export threads instead of one. Hence, I believe this might have something to do with the base class (maybe StepMeterRegistry?). Have you seen this before? Any ideas where it could come from? As I said, I am having a hard time getting a reproducer ready (getting two threads is easy, but they seem to not interfere most of the time). I assume the error comes from a race condition when both threads try to export at the same time. This would also explain why it only shows up once in a blue moon.
Environment
- Micrometer version: 1.11.0-RC1
- Micrometer registry: I assume StepMeterRegistry, confirmed in DynatraceMeterRegistry and ElasticMeterRegistry, possibly others.
- OS: WSL2 on Windows 11
- Java version:
openjdk version "17.0.4" 2022-07-19
To Reproduce How to reproduce the bug: -
Expected behavior I expected to not see that error and to only have one live publishing thread.
About this issue
- Original URL
- State: closed
- Created a year ago
- Comments: 21 (21 by maintainers)
@lenin-jaganathan @jonatan-ivanov @shakuzen Thank you very much for looking into this issue with me. I opened #3872 in order to track the potential addition of a timeout to wait for the final export to finish.
I don’t think you are missing anything, but I am missing my last value and I don’t yet know why 😄