Speed up your Maven Surefire tests by removing unnecessary logs
Sometimes your tests could be slow due to reasons you do not expect at first
Hey everyone! I want to share with you one story from my experience when I faced a pretty usual problem, but the solution turned out to be not so obvious.
Problem
Let me explain you prerequisites first. We have an E2E tests project written in Java, we use Maven as a build tool and execute our tests with the Maven Surefire plugin. This project has a small test suite containing 20+ tests.
Once, I noticed a very strange behavior with this suite. When I run tests in IntelliJ IDEA by clicking the Run button, the whole suite execution time is around 30 sec. But when this suite is being run as a part of the CI pipeline it usually takes near 1 min 45 sec. This is 3.5 times slower!
Actions
My first thought was that it happens because several tests suites are running at the same time and hit Selenoid limit. Timeline report supported this idea, it looks like there are no available browsers in Selenoid, and tests just waiting for them to be executed.
But after analyzing all Allure reports and running several experiments I realized that this problem has nothing to do with reaching Selenoid limits, so I continued to dig.
My next thought was about a wrong testng.xmlsuite file structure, but its structure was straightforward, so this was a dead-end too.
My third idea was that tests have some hidden dependencies between each other, but, again, that’s not the case, missed shot.
I spend 2 or 3 days investigating this issue and when I, without any hope, was checking CI logs for the 100th time, I noticed that amount of logs looks much bigger when tests are being run during CI process than when I run them in IDE. I tried to google something related to this topic and found this thread on StackOverflow. Wait a minute, this is exactly my problem!
So, the reason for the tests’ slowness was in a big amount of logs. A lot of tests in this suite generate CSV files from Java classes using OpenCSV library. And during this conversion, it produces a huge amount of logging (basically, for each value in a CSV file). Apparently, Surefire plugin multiplies this output by 3 times, to save all your output and this causes Surefire to take more time (actually, x3 more time) to execute the same suite than in IntelliJ IDEA.
Solution
The solution turned out to be super simple. All logs related to Java-class-to-CSV conversion were on the DEBUG level, so I just set level="INFO" as the default logging level for the application. If you still need some DEBUG logs, you can use a more advanced configuration and specify the level only for the particular logger that produces a big amount of unnecessary logs.
With that one-liner fix (actually, it was 3 lines in a configuration file), the test suite on CI started to be executed for the same 30 seconds as it was in IDE before.
That’s it. Thanks for your attention! I hope this information could be helpful for someone with the same issue, and this person will not spend 3 days trying to find the root cause of the problem.
If you still have any questions, you can find me on LinkedIn https://www.linkedin.com/in/andrii-baidachenko/
