dropwizard / dropwizard

A damn simple library for building production-ready RESTful web services.
https://www.dropwizard.io
Apache License 2.0
8.51k stars 3.44k forks source link

Metrics registry duplicate metric issue (regression). #832

Closed jshort closed 9 years ago

jshort commented 9 years ago

dropwizard-client-0.8.0-rc2-20150104.140645-65.jar regression

A unit test in my project has started failing with the dropwizard-client jar from a few hours ago. I put the previous snapshot version into my pom and it works as it always has so I believe something in commit: https://github.com/dropwizard/dropwizard/commit/637f48c7e28451aec52dddb6fb77f5bbc69a17dc or https://github.com/dropwizard/dropwizard/commit/f12d6cb43212f9dd091287a05d18bde290c1c02b has regressed this behavior.

whenCreateEventItShouldPersist(org.coner.it.CreateEventIntegrationTest)  Time elapsed: 0.01 sec  <<< ERROR!
java.lang.IllegalArgumentException: A metric named     org.apache.http.conn.HttpClientConnectionManager.test-client.available-connections already exists
at com.codahale.metrics.MetricRegistry.register(MetricRegistry.java:91)
at com.codahale.metrics.httpclient.InstrumentedHttpClientConnectionManager.<init>(InstrumentedHttpClientConnectionManager.java:57)
at io.dropwizard.client.ApacheClientBuilderBase.createConnectionManager(ApacheClientBuilderBase.java:184)
at io.dropwizard.client.JerseyClientBuilder.buildConfig(JerseyClientBuilder.java:185)
at io.dropwizard.client.JerseyClientBuilder.build(JerseyClientBuilder.java:166)
at io.dropwizard.client.JerseyClientBuilder.build(JerseyClientBuilder.java:152)
at org.coner.it.IntegrationTestUtils.buildClient(IntegrationTestUtils.java:31)
at org.coner.it.CreateEventIntegrationTest.whenCreateEventItShouldPersist(CreateEventIntegrationTest.java:38)
jshort commented 9 years ago

Code in question:

public static Client buildClient(DropwizardAppRule<ConerDropwizardConfiguration> appRule) {
    return new JerseyClientBuilder(appRule.getEnvironment())
            .using(appRule.getConfiguration().getJerseyClientConfiguration())
            .build("test-client");
}
jshort commented 9 years ago

Debug info:

So I noticed that we are using the same DropwizardAppRule object to build a Client for each unit test in the unit test class. The first test passes but the second test fails since the appRule object's enivironment.metricRegistry.metrics hash already has the 4 metrics that the InstrumentedHttpClientConnectionManager constructor adds to the metricRegistry.

I suppose prior to recent merges that these metrics were not cached.

jshort commented 9 years ago

Here is a workaround to this as this bug is fixed:

https://github.com/jshort/coner/commit/4f6a622543548211dc2569f62b00dbc7c04e2f64

joschi commented 9 years ago

I tried to reproduce the issue with the latest Dropwizard 0.8.0-rc.2 SNAPSHOT according to your description and came up with the following test class: https://gist.github.com/joschi/eb12da2baae6c032a1a4

Unfortunately (or rather luckily) the test cases succeed.

Could you please check if the issue still exists and provide a reproducible test case, if it does?

jshort commented 9 years ago

Still exists with: 16096 Jan 18 10:05 dropwizard-client-0.8.0-rc2-20150117.172343-98.jar

Your tests in the gist above seem like they should fail based on the behavior I'm seeing. I'll try to determine the delta between my test code and yours.

So I have recently refactored our tests to build a single client per class as opposed to a client per test in each class. Even doing so, I get the IAE on whatever is the 2nd class that junit runs.

jshort commented 9 years ago

@joschi in your test, change the following and make the app rule static and your test will fail.

@Rule => @ClassRule
joschi commented 9 years ago

But that's the whole point actually. If you only want to initialize the application (and with it the MetricRegistry) once per test class, use a @ClassRule. To initialize it per test case, use @Rule.

jshort commented 9 years ago

I see, but after a refactor where I only build the client once per test class, then the 2nd integration test class that runs will fail with the same error so there is some sort of state caching across test classes as well.

EDIT: Actually even running a single integration test class in intellij, it fails the same way without stripping the Metrics that have the client name in them before instantiating the client. This means that since I initially reported the bug, that something has changed such that just creating the DropwizardAppRule is passing the MetricsRegistry through the InstrumentedHttpClientConnectionManager constructor. Though even as I have typed the last sentence, that doesn't make sense since the 'test-client' name isn't even brought into the picture until the first time I build a Client.

java.lang.IllegalArgumentException: A metric named org.apache.http.conn.HttpClientConnectionManager.test-client.available-connections already exists
    at com.codahale.metrics.MetricRegistry.register(MetricRegistry.java:91)
    at com.codahale.metrics.httpclient.InstrumentedHttpClientConnectionManager.<init>(InstrumentedHttpClientConnectionManager.java:57)
    at io.dropwizard.client.ApacheClientBuilderBase.createConnectionManager(ApacheClientBuilderBase.java:192)
    at io.dropwizard.client.JerseyClientBuilder.buildConfig(JerseyClientBuilder.java:185)
    at io.dropwizard.client.JerseyClientBuilder.build(JerseyClientBuilder.java:166)
    at io.dropwizard.client.JerseyClientBuilder.build(JerseyClientBuilder.java:152)
    at org.coner.it.IntegrationTestUtils.buildClient(IntegrationTestUtils.java:38)
    at org.coner.it.CreateEventIntegrationTest.<init>(CreateEventIntegrationTest.java:33)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:408)
    at org.junit.runners.BlockJUnit4ClassRunner.createTest(BlockJUnit4ClassRunner.java:217)
    at org.junit.runners.BlockJUnit4ClassRunner$1.runReflectiveCall(BlockJUnit4ClassRunner.java:266)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.BlockJUnit4ClassRunner.methodBlock(BlockJUnit4ClassRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48)
    at org.junit.rules.RunRules.evaluate(RunRules.java:20)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:74)
    at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:211)
    at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:67)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:134)
jshort commented 9 years ago

So here is the the top of my test class

public class CreateRegistrationIntegrationTest {

    @ClassRule
    public static final DropwizardAppRule<ConerDropwizardConfiguration> RULE = IntegrationTestUtils.buildAppRule();

    private final Client client = IntegrationTestUtils.buildClient(RULE);
...

and the exception occurs on that last line above. I still don't understand how it is complaining about the duplicate metric since until that buildClient(RULE) method is called, the notion of 'test-client' doesn't exist.

I changed it to:

    @ClassRule
    public static final DropwizardAppRule<ConerDropwizardConfiguration> RULE = IntegrationTestUtils.buildAppRule();

    private static Client client;

    @BeforeClass
    public static void setupClass() {
        client = IntegrationTestUtils.buildClient(RULE);
    }

and it works without my metric stripping code. I vaguely remember that junit instantiates a new instance of the class for each test so I wonder if it had already run the buildClient(RULE) method for another test (though it had not 'run' yet).

joschi commented 9 years ago

I still don't understand how it is complaining about the duplicate metric since until that buildClient(RULE) method is called, the notion of 'test-client' doesn't exist. […] I vaguely remember that junit instantiates a new instance of the class for each test so I wonder if it had already run the buildClient(RULE) method for another test

I think this behavior depends on whether JUnit is forking new JVM processes per test class or is reusing processes, and whether it's running tests in parallel. See https://maven.apache.org/surefire/maven-surefire-plugin/examples/fork-options-and-parallel-execution.html for details.

As a workaround you could provide the name of the test class to your IntegrationTestUtils.buildClient()method and add it to the client name in order to have unique metric names.

I'm closing this issue for now since the DropwizardAppRule<T> is working as intended.

ghost commented 9 years ago

This issue still exists. I am struggling with it right now. While it is true that one can provide unique names, however, if I want to use a fresh client each time I need a new one in the same class/test class/(in general in the same context), then this issue is limiting my approaches. What are the reasons that the behaviour was changed in 0.8.0 in a way that introduces this bug/limitation. Can the metrics registry be cleared when a client is closed? Is there a plan to fix this issue? What is the work around for now short of supplying unique names.

I am using dropwizard-client 0.8.2

java.lang.IllegalArgumentException: A metric named org.apache.http.conn.HttpClientConnectionManager.cs.available-connections already exists at com.codahale.metrics.MetricRegistry.register(MetricRegistry.java:91) at com.codahale.metrics.httpclient.InstrumentedHttpClientConnectionManager.(InstrumentedHttpClientConnectionManager.java:63) at io.dropwizard.client.HttpClientBuilder.createConnectionManager(HttpClientBuilder.java:287) at io.dropwizard.client.HttpClientBuilder.buildWithDefaultRequestConfiguration(HttpClientBuilder.java:182) at io.dropwizard.client.JerseyClientBuilder.buildConfig(JerseyClientBuilder.java:347) at io.dropwizard.client.JerseyClientBuilder.build(JerseyClientBuilder.java:315) at io.dropwizard.client.JerseyClientBuilder.build(JerseyClientBuilder.java:309)