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

Slowdown with specific exclude pattern for agent #1344

Open
joel-costigliola opened this issue Jul 15, 2022 · 6 comments
Open

Slowdown with specific exclude pattern for agent #1344

joel-costigliola opened this issue Jul 15, 2022 · 6 comments
Labels
type: bug 🐛 Something isn't working

Comments

@joel-costigliola
Copy link

joel-costigliola commented Jul 15, 2022

I'm not sure if this is a bug or a regression but the feedback might be useful.

AssertJ Core is using jacoco but it was not activated by default, a build on my machine usually takes ~2min (executing ~18000 tests).
After we enabled jacoco by default (in this commit) the build took ~13min, I noticed that the tests that were slow were related to Path (but not File AFAIK).

Steps to reproduce

  • JaCoCo version: 0.8.8.202204050719
  • Operating system: see below
  • Tool integration: Maven
Apache Maven 3.8.2 (ea98e05a04480131370aa0c110b8c54cf726c06f)
Maven home: /home/joel/.sdkman/candidates/maven/current
Java version: 17.0.2, vendor: Oracle Corporation, runtime: /home/joel/.sdkman/candidates/java/17.0.2-open
Default locale: en_NZ, platform encoding: UTF-8
OS name: "linux", version: "5.4.0-122-generic", arch: "amd64", family: "unix"
  • Complete executable reproducer:

Clone https://github.com/assertj/assertj-core, build with mvn clean verify

  • Steps:

To build without jacoco enabled, checkout this commit: assertj/assertj@ad51a03

To build with jacoco enabled, checkout this commit: assertj/assertj@41179e5

Note that each test related to Path take a seconds to execute and it feels like the execution gets slower and slower (but that's a visual observation watching my console logs hangs for each Path tests

Sample logs extract showing that most of the tests are super fast but the Path one takes ~24s:

[INFO] Running FloatAssert isEqualTo with offset
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 s - in FloatAssert isEqualTo with offset
[INFO] Running ByteArrayAss
[path-tests.txt](https://github.com/jacoco/jacoco/files/9120279/path-tests.txt)
[run-full-log.txt](https://github.com/jacoco/jacoco/files/9120280/run-full-log.txt)
ert containsExactlyInAnyOrder with integers
[INFO] Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.001 s - in ByteArrayAssert containsExactlyInAnyOrder with integers
[INFO] Running Paths assertIsExecutable
[INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 23.918 s - in Paths assertIsExecutable
[INFO] Running DoubleArrayAssert doesNotHaveDuplicates
[INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.001 s - in DoubleArrayAssert doesNotHaveDuplicates

Expected behaviour

Reasonable build time, obviously would take more time than a build without jacoco but not a 6x increase.

Actual behaviour

~13min build time which basically prevents me running it locally which is why we have disabled it by default now
a subsequent run was 8min.

here's a run build time:

[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  13:05 min (Wall Clock)
[INFO] Finished at: 2022-07-15T22:44:40+12:00
[INFO] ------------------------------------------------------------------------

I have added the logs for a full run in run-full-log.txt and greped the Paths tests in path-tests.txt which shows the test execution time, hope that helps.

@joel-costigliola joel-costigliola added the type: bug 🐛 Something isn't working label Jul 15, 2022
@marchof
Copy link
Member

marchof commented Jul 15, 2022

Thanks for this detailed report! I'll try to debug what makes the test that slow.

@marchof
Copy link
Member

marchof commented Jul 15, 2022

Did a quick check in GitPod 🙀:

assertj/assertj@ad51a03 -> 02:10 min
assertj/assertj@41179e5 -> 14:14 min

@marchof
Copy link
Member

marchof commented Jul 15, 2022

A quick profiling showed that most of the time is spent in applying the filter regex for the filter: If I replace

<exclude>**/*hamcrest*/**</exclude>

with

<exclude>*hamcrest*</exclude>

the build time is down to 02:40 min. Also looks like due to the mocking of Paths tons of classes are generated by Mockito every time. Maybe this can be avoided or the mocked instance can be shared across test cases.

@scordio
Copy link

scordio commented Jul 15, 2022

Thanks for the feedback, @marchof! These are definitely improvements we can apply.

@joel-costigliola
Copy link
Author

After applying your suggestions, the build time is back to ~2min, @marchof feel free to close that issue and thanks again for the investigation.

@marchof
Copy link
Member

marchof commented Jul 18, 2022

@joel-costigliola Thanks for the feedback! I'll keep this open because I want to investigate the root cause.

@marchof marchof changed the title Jacoco is super slow when running tests related to Path Slowdown with specific exclude pattern for agent Jul 18, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: bug 🐛 Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants