You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@maven.apache.org by "Allan Jones (Jira)" <ji...@apache.org> on 2022/06/08 13:56:00 UTC
[jira] [Updated] (SUREFIRE-2096) Major performance difference between 3.0.0-M5 and 3.0.0-M6/3.0.0-M7
[ https://issues.apache.org/jira/browse/SUREFIRE-2096?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Allan Jones updated SUREFIRE-2096:
----------------------------------
Description:
After upgrading surefire/failsafe to the latest milestone (3.0.0-M7), we faced a major performance problem in our integration tests. They increased nearly 23 minutes (+30%).
This is the 2nd upgrade attempt. When 3.0.0-M6 was released, we did the upgrade and after a couple of days we had to revert back to 3.0.0-M5 because all our integration test jobs were running nearly 30% slower.
----
These are the latest results we have:
Before with 3.0.0-M5:
{{[2022-06-07T06:59:56.398Z] [INFO] Main Server DB Tests [project-test-db] SUCCESS [ 01:16 h]}}
After with 3.0.0-M7:
{{[2022-06-07T18:09:21.297Z] [INFO] Main Server DB Tests [project-test-db] SUCCESS [ 01:39 h]}}
----
Our integration tests are organized in 3 reusable forks. They are JUnit 5 Suites. On 3.0.0-M5, the maven output log was only showing the Suites and their time (the whole output):
{{[2022-06-07T05:38:02.737Z] [INFO] Running AbcIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T05:38:02.995Z] [INFO] Running DatabaseBasedIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T05:38:02.996Z] [INFO] Running OptimizerSpecificTestCategoryDynamicSuite}}
{{[2022-06-07T06:07:10.541Z] [WARNING] Tests run: 1244, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 1,743.768 s - in DatabaseBasedIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:07:15.833Z] [INFO] Running DefServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:17:52.723Z] [WARNING] Tests run: 703, Failures: 0, Errors: 0, Skipped: 7, Time elapsed: 2,376.439 s - in AbcIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:17:52.723Z] [INFO] Running MnoRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:27:59.428Z] [WARNING] Tests run: 1009, Failures: 0, Errors: 0, Skipped: 2, Time elapsed: 1,243.484 s - in DefServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:28:07.556Z] [INFO] Running TransactionAwareDefServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:36:44.297Z] [WARNING] Tests run: 69, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 3,519.25 s - in OptimizerSpecificTestCategoryDynamicSuite}}
{{[2022-06-07T06:36:50.852Z] [INFO] Running GhiIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:42:27.435Z] [WARNING] Tests run: 185, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 335.077 s - in GhiIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:42:37.405Z] [INFO] Running JdoIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:45:28.867Z] [WARNING] Tests run: 1028, Failures: 0, Errors: 0, Skipped: 2, Time elapsed: 1,038.893 s - in TransactionAwareDefServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:45:34.135Z] [INFO] Running JklAuthorizationRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:46:41.815Z] [INFO] Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 57.734 s - in JklAuthorizationRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:46:41.815Z] [INFO] Running JklBroadcastIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:03.233Z] [INFO] Tests run: 3176, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 317.062 s - in JdoIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:03.233Z] [INFO] Tests run: 17, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 74.634 s - in JklBroadcastIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:03.233Z] [INFO] Running JklRestServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:05.132Z] [INFO] Running EnversIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:07.031Z] [WARNING] Tests run: 1092, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 1,819.178 s - in MnoRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:48:15.148Z] [INFO] Running LdapIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:49:11.394Z] [INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 48.07 s - in LdapIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:49:11.394Z] [INFO] Tests run: 62, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 58.879 s - in EnversIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:49:11.395Z] [INFO] Running ObjectSecurityIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:49:11.395Z] [INFO] Running SecondLevelCacheTestCategoryDynamicSuite}}
{{[2022-06-07T06:50:47.898Z] [INFO] Tests run: 160, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 85.201 s - in ObjectSecurityIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:50:47.898Z] [INFO] Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 93.342 s - in SecondLevelCacheTestCategoryDynamicSuite}}
{{[2022-06-07T06:50:47.898Z] [INFO] Running MnoAuthorizationRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:50:48.830Z] [WARNING] Tests run: 277, Failures: 0, Errors: 0, Skipped: 2, Time elapsed: 167.534 s - in JklRestServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:50:53.013Z] [INFO] Running MnoRestServiceWithGhiIntegrationTestDynamicSuite}}
{{[2022-06-07T06:50:58.272Z] [INFO] Running PqrTestCategoryDynamicSuite}}
{{[2022-06-07T06:52:19.688Z] [INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 90.355 s - in MnoAuthorizationRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:52:20.254Z] [INFO] Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 87.234 s - in MnoRestServiceWithGhiIntegrationTestDynamicSuite}}
{{[2022-06-07T06:53:16.466Z] [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 131.736 s - in PqrTestCategoryDynamicSuite}}
{{[2022-06-07T06:53:16.466Z] [INFO] }}
{{[2022-06-07T06:53:16.466Z] [INFO] Results:}}
{{[2022-06-07T06:53:16.466Z] [INFO] }}
{{[2022-06-07T06:53:16.466Z] [WARNING] Tests run: 9066, Failures: 0, Errors: 0, Skipped: 19}}
----
Now with 3.0.0-M7 (or even 3.0.0-M6), we see a line for every single test inside the suite in maven output (just beginning of the output):
{{[2022-06-07T16:32:36.387Z] [INFO] Running com.aaa.ccc.testcommon.suite.order.b.AbcIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.aaa.ccc.testcommon.suite.order.a.OptimizerSpecificTestCategoryDynamicSuite}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.bbb.workflow.statemachine.abc.statemachine.AbcStatePart2IntegrationTest}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.bbb.optimization.service.EngineIntegrationTest}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.aaa.ccc.testcommon.suite.order.c.DatabaseBasedIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.bbb.bi.TableHelperIntegrationTest}}
{{[2022-06-07T16:33:15.086Z] [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 38.042 s - in com.bbb.bi.TableHelperIntegrationTest}}
{{[2022-06-07T16:33:15.086Z] [INFO] Running com.bbb.agreement.importer.dao.jdbc.AdvDaoIntegrationTest}}
{{[2022-06-07T16:33:15.086Z] [INFO] Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.246 s - in com.bbb.agreement.importer.dao.jdbc.AdvDaoIntegrationTest}}
{{[2022-06-07T16:33:15.086Z] [INFO] Running com.bbb.housekeeping.task.DefabcIntegrationTest}}
----
I did some investigation and my initial guess is that it's related to:
https://issues.apache.org/jira/browse/SUREFIRE-1926 and [https://github.com/apache/maven-surefire/pull/419/files] (which makes all methods in PluginConsoleLogger synchronized)
I had no issues with the previous behaviour that was only logging the Suites, and not the individual tests. I also don't mind logging each individual test in maven output, but without the expense of such huge performance difference. I tried to see if there was a way to disable or configure this behaviour, but with no luck.
was:
After upgrading surefire/failsafe to the latest milestone (3.0.0-M7), we faced a major performance problem in our integration tests. They increased nearly 23 minutes (+30%).
This is the 2nd upgrade attempt. When 3.0.0-M6 was released, we did the upgrade and after a couple of days we had to revert back to 3.0.0-M5 because all our integration test jobs were running nearly 30% slower.
These are the latest results we have:
Before with 3.0.0-M5
{{[2022-06-07T06:59:56.398Z] [INFO] Main Server DB Tests [project-test-db] SUCCESS [ 01:16 h]}}
After with 3.0.0-M7
{{[2022-06-07T18:09:21.297Z] [INFO] Main Server DB Tests [project-test-db] SUCCESS [ 01:39 h]}}
jobs w
Our integration tests are organized in 3 reusable forks. They are JUnit 5 Suites. On 3.0.0-M5, the maven output log was only showing the Suites and their time (the whole output):
{{[2022-06-07T05:38:02.737Z] [INFO] Running AbcIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T05:38:02.995Z] [INFO] Running DatabaseBasedIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T05:38:02.996Z] [INFO] Running OptimizerSpecificTestCategoryDynamicSuite}}
{{[2022-06-07T06:07:10.541Z] [WARNING] Tests run: 1244, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 1,743.768 s - in DatabaseBasedIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:07:15.833Z] [INFO] Running DefServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:17:52.723Z] [WARNING] Tests run: 703, Failures: 0, Errors: 0, Skipped: 7, Time elapsed: 2,376.439 s - in AbcIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:17:52.723Z] [INFO] Running MnoRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:27:59.428Z] [WARNING] Tests run: 1009, Failures: 0, Errors: 0, Skipped: 2, Time elapsed: 1,243.484 s - in DefServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:28:07.556Z] [INFO] Running TransactionAwareDefServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:36:44.297Z] [WARNING] Tests run: 69, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 3,519.25 s - in OptimizerSpecificTestCategoryDynamicSuite}}
{{[2022-06-07T06:36:50.852Z] [INFO] Running GhiIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:42:27.435Z] [WARNING] Tests run: 185, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 335.077 s - in GhiIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:42:37.405Z] [INFO] Running JdoIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:45:28.867Z] [WARNING] Tests run: 1028, Failures: 0, Errors: 0, Skipped: 2, Time elapsed: 1,038.893 s - in TransactionAwareDefServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:45:34.135Z] [INFO] Running JklAuthorizationRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:46:41.815Z] [INFO] Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 57.734 s - in JklAuthorizationRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:46:41.815Z] [INFO] Running JklBroadcastIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:03.233Z] [INFO] Tests run: 3176, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 317.062 s - in JdoIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:03.233Z] [INFO] Tests run: 17, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 74.634 s - in JklBroadcastIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:03.233Z] [INFO] Running JklRestServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:05.132Z] [INFO] Running EnversIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:48:07.031Z] [WARNING] Tests run: 1092, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 1,819.178 s - in MnoRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:48:15.148Z] [INFO] Running LdapIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:49:11.394Z] [INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 48.07 s - in LdapIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:49:11.394Z] [INFO] Tests run: 62, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 58.879 s - in EnversIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:49:11.395Z] [INFO] Running ObjectSecurityIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:49:11.395Z] [INFO] Running SecondLevelCacheTestCategoryDynamicSuite}}
{{[2022-06-07T06:50:47.898Z] [INFO] Tests run: 160, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 85.201 s - in ObjectSecurityIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:50:47.898Z] [INFO] Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 93.342 s - in SecondLevelCacheTestCategoryDynamicSuite}}
{{[2022-06-07T06:50:47.898Z] [INFO] Running MnoAuthorizationRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:50:48.830Z] [WARNING] Tests run: 277, Failures: 0, Errors: 0, Skipped: 2, Time elapsed: 167.534 s - in JklRestServiceIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T06:50:53.013Z] [INFO] Running MnoRestServiceWithGhiIntegrationTestDynamicSuite}}
{{[2022-06-07T06:50:58.272Z] [INFO] Running PqrTestCategoryDynamicSuite}}
{{[2022-06-07T06:52:19.688Z] [INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 90.355 s - in MnoAuthorizationRestServiceIntegrationTestDynamicSuite}}
{{[2022-06-07T06:52:20.254Z] [INFO] Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 87.234 s - in MnoRestServiceWithGhiIntegrationTestDynamicSuite}}
{{[2022-06-07T06:53:16.466Z] [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 131.736 s - in PqrTestCategoryDynamicSuite}}
{{[2022-06-07T06:53:16.466Z] [INFO] }}
{{[2022-06-07T06:53:16.466Z] [INFO] Results:}}
{{[2022-06-07T06:53:16.466Z] [INFO] }}
{{[2022-06-07T06:53:16.466Z] [WARNING] Tests run: 9066, Failures: 0, Errors: 0, Skipped: 19}}
Now with 3.0.0-M7 (or even 3.0.0-M6), we see a line for every single test inside the suite in maven output (just beginning of the output):
{{[2022-06-07T16:32:36.387Z] [INFO] Running com.aaa.ccc.testcommon.suite.order.b.AbcIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.aaa.ccc.testcommon.suite.order.a.OptimizerSpecificTestCategoryDynamicSuite}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.bbb.workflow.statemachine.abc.statemachine.AbcStatePart2IntegrationTest}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.bbb.optimization.service.EngineIntegrationTest}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.aaa.ccc.testcommon.suite.order.c.DatabaseBasedIntegrationTestCategoryDynamicSuite}}
{{[2022-06-07T16:32:36.388Z] [INFO] Running com.bbb.bi.TableHelperIntegrationTest}}
{{[2022-06-07T16:33:15.086Z] [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 38.042 s - in com.bbb.bi.TableHelperIntegrationTest}}
{{[2022-06-07T16:33:15.086Z] [INFO] Running com.bbb.agreement.importer.dao.jdbc.AdvDaoIntegrationTest}}
{{[2022-06-07T16:33:15.086Z] [INFO] Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.246 s - in com.bbb.agreement.importer.dao.jdbc.AdvDaoIntegrationTest}}
{{[2022-06-07T16:33:15.086Z] [INFO] Running com.bbb.housekeeping.task.DefabcIntegrationTest}}
I did some investigation and my initial guess is that it's related to:
https://issues.apache.org/jira/browse/SUREFIRE-1926 and [https://github.com/apache/maven-surefire/pull/419/files] (which makes all methods in PluginConsoleLogger synchronized)
I had no issues with the previous behaviour that was only logging the Suites, and not the individual tests. I also don't mind logging each individual test in maven output, but without the expense of such huge performance difference. I tried to see if there was a way to disable or configure this behaviour, but with no luck.
> Major performance difference between 3.0.0-M5 and 3.0.0-M6/3.0.0-M7
> -------------------------------------------------------------------
>
> Key: SUREFIRE-2096
> URL: https://issues.apache.org/jira/browse/SUREFIRE-2096
> Project: Maven Surefire
> Issue Type: Bug
> Components: Maven Failsafe Plugin, Maven Surefire Plugin
> Affects Versions: 3.0.0-M6, 3.0.0-M7
> Reporter: Allan Jones
> Priority: Major
>
> After upgrading surefire/failsafe to the latest milestone (3.0.0-M7), we faced a major performance problem in our integration tests. They increased nearly 23 minutes (+30%).
> This is the 2nd upgrade attempt. When 3.0.0-M6 was released, we did the upgrade and after a couple of days we had to revert back to 3.0.0-M5 because all our integration test jobs were running nearly 30% slower.
> ----
>
> These are the latest results we have:
> Before with 3.0.0-M5:
> {{[2022-06-07T06:59:56.398Z] [INFO] Main Server DB Tests [project-test-db] SUCCESS [ 01:16 h]}}
>
> After with 3.0.0-M7:
> {{[2022-06-07T18:09:21.297Z] [INFO] Main Server DB Tests [project-test-db] SUCCESS [ 01:39 h]}}
> ----
>
> Our integration tests are organized in 3 reusable forks. They are JUnit 5 Suites. On 3.0.0-M5, the maven output log was only showing the Suites and their time (the whole output):
> {{[2022-06-07T05:38:02.737Z] [INFO] Running AbcIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T05:38:02.995Z] [INFO] Running DatabaseBasedIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T05:38:02.996Z] [INFO] Running OptimizerSpecificTestCategoryDynamicSuite}}
> {{[2022-06-07T06:07:10.541Z] [WARNING] Tests run: 1244, Failures: 0, Errors: 0, Skipped: 3, Time elapsed: 1,743.768 s - in DatabaseBasedIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:07:15.833Z] [INFO] Running DefServiceIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:17:52.723Z] [WARNING] Tests run: 703, Failures: 0, Errors: 0, Skipped: 7, Time elapsed: 2,376.439 s - in AbcIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:17:52.723Z] [INFO] Running MnoRestServiceIntegrationTestDynamicSuite}}
> {{[2022-06-07T06:27:59.428Z] [WARNING] Tests run: 1009, Failures: 0, Errors: 0, Skipped: 2, Time elapsed: 1,243.484 s - in DefServiceIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:28:07.556Z] [INFO] Running TransactionAwareDefServiceIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:36:44.297Z] [WARNING] Tests run: 69, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 3,519.25 s - in OptimizerSpecificTestCategoryDynamicSuite}}
> {{[2022-06-07T06:36:50.852Z] [INFO] Running GhiIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:42:27.435Z] [WARNING] Tests run: 185, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 335.077 s - in GhiIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:42:37.405Z] [INFO] Running JdoIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:45:28.867Z] [WARNING] Tests run: 1028, Failures: 0, Errors: 0, Skipped: 2, Time elapsed: 1,038.893 s - in TransactionAwareDefServiceIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:45:34.135Z] [INFO] Running JklAuthorizationRestServiceIntegrationTestDynamicSuite}}
> {{[2022-06-07T06:46:41.815Z] [INFO] Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 57.734 s - in JklAuthorizationRestServiceIntegrationTestDynamicSuite}}
> {{[2022-06-07T06:46:41.815Z] [INFO] Running JklBroadcastIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:48:03.233Z] [INFO] Tests run: 3176, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 317.062 s - in JdoIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:48:03.233Z] [INFO] Tests run: 17, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 74.634 s - in JklBroadcastIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:48:03.233Z] [INFO] Running JklRestServiceIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:48:05.132Z] [INFO] Running EnversIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:48:07.031Z] [WARNING] Tests run: 1092, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 1,819.178 s - in MnoRestServiceIntegrationTestDynamicSuite}}
> {{[2022-06-07T06:48:15.148Z] [INFO] Running LdapIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:49:11.394Z] [INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 48.07 s - in LdapIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:49:11.394Z] [INFO] Tests run: 62, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 58.879 s - in EnversIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:49:11.395Z] [INFO] Running ObjectSecurityIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:49:11.395Z] [INFO] Running SecondLevelCacheTestCategoryDynamicSuite}}
> {{[2022-06-07T06:50:47.898Z] [INFO] Tests run: 160, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 85.201 s - in ObjectSecurityIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:50:47.898Z] [INFO] Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 93.342 s - in SecondLevelCacheTestCategoryDynamicSuite}}
> {{[2022-06-07T06:50:47.898Z] [INFO] Running MnoAuthorizationRestServiceIntegrationTestDynamicSuite}}
> {{[2022-06-07T06:50:48.830Z] [WARNING] Tests run: 277, Failures: 0, Errors: 0, Skipped: 2, Time elapsed: 167.534 s - in JklRestServiceIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T06:50:53.013Z] [INFO] Running MnoRestServiceWithGhiIntegrationTestDynamicSuite}}
> {{[2022-06-07T06:50:58.272Z] [INFO] Running PqrTestCategoryDynamicSuite}}
> {{[2022-06-07T06:52:19.688Z] [INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 90.355 s - in MnoAuthorizationRestServiceIntegrationTestDynamicSuite}}
> {{[2022-06-07T06:52:20.254Z] [INFO] Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 87.234 s - in MnoRestServiceWithGhiIntegrationTestDynamicSuite}}
> {{[2022-06-07T06:53:16.466Z] [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 131.736 s - in PqrTestCategoryDynamicSuite}}
> {{[2022-06-07T06:53:16.466Z] [INFO] }}
> {{[2022-06-07T06:53:16.466Z] [INFO] Results:}}
> {{[2022-06-07T06:53:16.466Z] [INFO] }}
> {{[2022-06-07T06:53:16.466Z] [WARNING] Tests run: 9066, Failures: 0, Errors: 0, Skipped: 19}}
>
> ----
> Now with 3.0.0-M7 (or even 3.0.0-M6), we see a line for every single test inside the suite in maven output (just beginning of the output):
> {{[2022-06-07T16:32:36.387Z] [INFO] Running com.aaa.ccc.testcommon.suite.order.b.AbcIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T16:32:36.388Z] [INFO] Running com.aaa.ccc.testcommon.suite.order.a.OptimizerSpecificTestCategoryDynamicSuite}}
> {{[2022-06-07T16:32:36.388Z] [INFO] Running com.bbb.workflow.statemachine.abc.statemachine.AbcStatePart2IntegrationTest}}
> {{[2022-06-07T16:32:36.388Z] [INFO] Running com.bbb.optimization.service.EngineIntegrationTest}}
> {{[2022-06-07T16:32:36.388Z] [INFO] Running com.aaa.ccc.testcommon.suite.order.c.DatabaseBasedIntegrationTestCategoryDynamicSuite}}
> {{[2022-06-07T16:32:36.388Z] [INFO] Running com.bbb.bi.TableHelperIntegrationTest}}
> {{[2022-06-07T16:33:15.086Z] [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 38.042 s - in com.bbb.bi.TableHelperIntegrationTest}}
> {{[2022-06-07T16:33:15.086Z] [INFO] Running com.bbb.agreement.importer.dao.jdbc.AdvDaoIntegrationTest}}
> {{[2022-06-07T16:33:15.086Z] [INFO] Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.246 s - in com.bbb.agreement.importer.dao.jdbc.AdvDaoIntegrationTest}}
> {{[2022-06-07T16:33:15.086Z] [INFO] Running com.bbb.housekeeping.task.DefabcIntegrationTest}}
> ----
>
>
> I did some investigation and my initial guess is that it's related to:
> https://issues.apache.org/jira/browse/SUREFIRE-1926 and [https://github.com/apache/maven-surefire/pull/419/files] (which makes all methods in PluginConsoleLogger synchronized)
>
> I had no issues with the previous behaviour that was only logging the Suites, and not the individual tests. I also don't mind logging each individual test in maven output, but without the expense of such huge performance difference. I tried to see if there was a way to disable or configure this behaviour, but with no luck.
>
--
This message was sent by Atlassian Jira
(v8.20.7#820007)