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

Rewrite of throttling logging appender testing #2458

Merged
merged 3 commits into from
Aug 17, 2018
Merged

Rewrite of throttling logging appender testing #2458

merged 3 commits into from
Aug 17, 2018

Conversation

isaki
Copy link
Contributor

@isaki isaki commented Aug 17, 2018

  • Renamed test class to match the class it is testing
    (ThrottlingAppenderWrapper).
  • Rewrote class to play nicer with slower processing and to improve long
    term supportability.
  • Relied on system property for line seperation instead of hardcoded
    regex.
  • Removed unused imports (and in the class being tested as well).
Problem:

The current unit test relies on wall clock timings which can cause issues during CI builds on slow machines.

Solution:

I've done my best to eliminate wall clock where possible and added calculations where that wasn't possible to dynamically calculate the expected result for slow machines.

Result:

The tests should be far more reliable.

- Renamed test class to match the class it is testing
(ThrottlingAppenderWrapper).
- Rewrote class to play nicer with slower processing and to improve long
term supportability.
- Relied on system property for line seperation instead of hardcoded
regex.
- Removed unused imports (and in the class being tested as well).
@isaki
Copy link
Contributor Author

isaki commented Aug 17, 2018

The reason for this PR was discussed in another PR I submitted that had CI fail due to the issues addressed by this PR (see #2451).

@jplock jplock added this to the 2.0.0 milestone Aug 17, 2018
@isaki
Copy link
Contributor Author

isaki commented Aug 17, 2018

Interesting, CI failed on unrelated code (you can see the test affected by this PR was successful):

3628[INFO] ------------------------------------------------------------------------
3629[INFO] Reactor Summary:
3630[INFO] 
3631[INFO] Dropwizard Project ................................. SUCCESS [ 22.195 s]
3632[INFO] Dropwizard Documentation ........................... SUCCESS [  5.187 s]
3633[INFO] Dropwizard BOM ..................................... SUCCESS [  0.344 s]
3634[INFO] Dropwizard Utility Classes ......................... SUCCESS [ 14.676 s]
3635[INFO] Dropwizard Jackson Support ......................... SUCCESS [  6.828 s]
3636[INFO] Dropwizard Validation Support ...................... SUCCESS [  8.641 s]
3637[INFO] Dropwizard Configuration Support ................... SUCCESS [ 20.134 s]
3638[INFO] Dropwizard Logging Support ......................... SUCCESS [ 13.902 s]
3639[INFO] Dropwizard Lifecycle Support ....................... SUCCESS [  5.961 s]
3640[INFO] Dropwizard Metrics Support ......................... SUCCESS [  5.814 s]
3641[INFO] Dropwizard Jersey Support .......................... FAILURE [ 30.649 s]
3642[INFO] Dropwizard Servlet Support ......................... SKIPPED
3643[INFO] Dropwizard Jetty Support ........................... SKIPPED
3644[INFO] Dropwizard Request Logging Support ................. SKIPPED

Here is the specific failure:

[INFO] Running io.dropwizard.jersey.DropwizardResourceConfigTest
3502[ERROR] Tests run: 17, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.875 s <<< FAILURE! - in io.dropwizard.jersey.DropwizardResourceConfigTest
3503[ERROR] logsEndpointsContextPath(io.dropwizard.jersey.DropwizardResourceConfigTest)  Time elapsed: 0 s  <<< ERROR!
3504java.lang.RuntimeException: Could not start jersey
3505	at io.dropwizard.jersey.DropwizardResourceConfigTest.runJersey(DropwizardResourceConfigTest.java:47)
3506	at io.dropwizard.jersey.DropwizardResourceConfigTest.logsEndpointsContextPath(DropwizardResourceConfigTest.java:249)
3507Caused by: org.glassfish.jersey.test.spi.TestContainerException: java.net.BindException: Address already in use: bind
3508	at io.dropwizard.jersey.DropwizardResourceConfigTest.runJersey(DropwizardResourceConfigTest.java:45)
3509	at io.dropwizard.jersey.DropwizardResourceConfigTest.logsEndpointsContextPath(DropwizardResourceConfigTest.java:249)
3510Caused by: java.net.BindException: Address already in use: bind
3511	at io.dropwizard.jersey.DropwizardResourceConfigTest.runJersey(DropwizardResourceConfigTest.java:45)
3512	at io.dropwizard.jersey.DropwizardResourceConfigTest.logsEndpointsContextPath(DropwizardResourceConfigTest.java:249)

I suspect there is a resource/socket somewhere from another test that failed to be cleaned up or something else holding the desired listening port. It seems to be specific to the AppVeyor CI as my previous commit failed at the exact same spot for the same CI solution.

@nickbabcock
Copy link
Contributor

nickbabcock commented Aug 17, 2018

I suspect there is a resource/socket somewhere from another test that failed to be cleaned up.

Huh, what's weird is that the code sets the CONTAINER_PORT for those tests to 0, so it should use the first available. So even if a previous test had a bad teardown (though I'm optimistic that this is not the case), it shouldn't affect the DropwizardResourceConfigTest tests

@isaki
Copy link
Contributor Author

isaki commented Aug 17, 2018

I haven't dug too deeply into the issue; I have the same failure in two builds on the same CI system (my first commit and then my second to remove an additional unused import I missed on my first pass). It is possible there is something messed up specific to the AppVeyor instance.

// add one regardless as at full speed, we end up with 1 + executed
// intervals as an event fires at time zero.
int high = (int) intervals;
if ((intervals - high > 0d)) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can this be written more straightforward with something like Math.ceil? a la

int high = (int)Math.ceil(intervals) + 1

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done. Commit inbound.

@nickbabcock
Copy link
Contributor

Yeah maybe we'll just keep an eye on the appveyor flakiness. Hopefully it'll be just that one time. I tested this PR on my windows machine and everything passed, so don't worry.

@isaki
Copy link
Contributor Author

isaki commented Aug 17, 2018

It looks like AppVeyor worked this time!

@nickbabcock
Copy link
Contributor

Excellent, thank you! I certainly liked the way structured the test so it becomes resilient to variable CI environments.

@nickbabcock nickbabcock merged commit 1ee6401 into dropwizard:master Aug 17, 2018
@isaki
Copy link
Contributor Author

isaki commented Aug 17, 2018

Thank you sir!

@isaki isaki deleted the throttle_test_refactor branch August 18, 2018 00:46
joschi added a commit to dropwizard/logback-throttling-appender that referenced this pull request Dec 30, 2018
Extract `ThrottlingAppenderWrapper` from Dropwizard and keep it as a separate (tiny) project.

Refs dropwizard/dropwizard#2376
Refs dropwizard/dropwizard#2384
Refs dropwizard/dropwizard#2458
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants