[
https://issues.apache.org/jira/browse/SUREFIRE-2096?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17551775#comment-17551775
]
Andrey Loskutov commented on SUREFIRE-2096:
-------------------------------------------
Just a guess: if you have lot of tests, you might run into memory issues, so it
could be related to memory leak in SUREFIRE-2072? Or to descriptors leak in
SUREFIRE-2094? Both issues were introduced in 3.0 M6.
> 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)
