[go: up one dir, main page]

Page MenuHomePhabricator

Improve speed of codehealth checks
Open, In Progress, Needs TriagePublic

Description

The codehealth job for MW core is quite slow: overall, it's slower than the normal test checks, with an average of ~20 minutes apparently. By looking at the output for this random patch, there are two things that stand out immediately:

  • First, it looks like sonar is never using the cache, even if it's enabled:
19:30:12 INFO: Starting PHP symbol indexer
19:30:12 INFO: 4613 source files to be analyzed
19:30:22 INFO: 486/4613 files analyzed, current file: includes/libs/rdbms/lbfactory/LBFactorySingle.php
19:30:32 INFO: 846/4613 files analyzed, current file: tests/phpunit/structure/AutoLoaderStructureTest.php
19:30:42 INFO: 1298/4613 files analyzed, current file: includes/libs/filebackend/FileBackendMultiWrite.php
19:30:52 INFO: 1808/4613 files analyzed, current file: includes/MainConfigSchema.php
19:31:02 INFO: 2238/4613 files analyzed, current file: includes/language/converters/UzConverter.php
19:31:12 INFO: 2682/4613 files analyzed, current file: tests/phpunit/integration/includes/user/TempUser/RealTempUserConfigTest.php
19:31:22 INFO: 3097/4613 files analyzed, current file: includes/libs/objectcache/wancache/WANObjectCache.php
19:31:32 INFO: 3531/4613 files analyzed, current file: includes/MediaWiki.php
19:31:42 INFO: 4024/4613 files analyzed, current file: tests/phpunit/includes/session/SessionManagerTest.php
19:31:52 INFO: 4430/4613 files analyzed, current file: tests/phpunit/includes/filerepo/file/FileTest.php
19:31:58 INFO: 4613/4613 source files have been analyzed
19:31:58 INFO: Cached information of global symbols will be used for 0 out of 4613 files. Global symbols were recomputed for the remaining files.
19:31:59 INFO: Starting PHP rules
19:31:59 INFO: 4613 source files to be analyzed
19:32:09 INFO: 290/4613 files analyzed, current file: includes/import/WikiImporter.php
19:32:19 INFO: 517/4613 files analyzed, current file: includes/block/BlockRestrictionStore.php
19:32:29 INFO: 709/4613 files analyzed, current file: includes/collation/data/first-letters-root.php
19:32:39 INFO: 928/4613 files analyzed, current file: tests/phpunit/includes/Revision/RevisionStoreDbTest.php
19:32:49 INFO: 1209/4613 files analyzed, current file: includes/libs/lockmanager/MemcLockManager.php
19:32:59 INFO: 1491/4613 files analyzed, current file: includes/installer/PostgresUpdater.php
19:33:09 INFO: 1769/4613 files analyzed, current file: tests/phpunit/includes/parser/ParserCacheSerializationTestCases.php
19:33:19 INFO: 2020/4613 files analyzed, current file: includes/linker/Linker.php
19:33:29 INFO: 2288/4613 files analyzed, current file: includes/upload/UploadStash.php
19:33:39 INFO: 2579/4613 files analyzed, current file: languages/messages/MessagesTly.php
19:33:49 INFO: 2810/4613 files analyzed, current file: maintenance/rebuildtextindex.php
19:33:59 INFO: 3055/4613 files analyzed, current file: maintenance/compareLanguageConverterOutput.php
19:34:09 INFO: 3297/4613 files analyzed, current file: tests/phpunit/includes/filebackend/FileBackendIntegrationTest.php
19:34:19 INFO: 3537/4613 files analyzed, current file: tests/phpunit/includes/Status/StatusTest.php
19:34:29 INFO: 3838/4613 files analyzed, current file: includes/api/ApiQuery.php
19:34:39 INFO: 4106/4613 files analyzed, current file: includes/page/WikiPage.php
19:34:49 INFO: 4332/4613 files analyzed, current file: includes/Output/OutputPage.php
19:34:59 INFO: 4584/4613 files analyzed, current file: tests/phpunit/includes/session/UserInfoTest.php
19:35:03 INFO: 4613/4613 source files have been analyzed
19:35:03 INFO: The PHP analyzer was able to leverage cached data from previous analyses for 0 out of 4613 files. These files were not parsed.
  • Second, sonar spent 6 minutes and 40 seconds (!) running the TextAndSecretsSensor (which I assume looks for passwords etc?), checking i18n files in the process. Is this something we actually want/need and is worth almost 7 minutes of wait time?
19:35:04 INFO: Sensor TextAndSecretsSensor [text]
19:35:04 INFO: 6731 source files to be analyzed
19:35:14 INFO: 180/6731 files analyzed, current file: includes/installer/i18n/mk.json
19:35:24 INFO: 297/6731 files analyzed, current file: includes/installer/i18n/sl.json
19:35:34 INFO: 467/6731 files analyzed, current file: languages/i18n/vi.json
19:35:44 INFO: 635/6731 files analyzed, current file: languages/i18n/mn.json
19:35:54 INFO: 844/6731 files analyzed, current file: languages/i18n/mt.json
19:36:04 INFO: 937/6731 files analyzed, current file: includes/installer/i18n/lt.json
19:36:14 INFO: 1161/6731 files analyzed, current file: languages/i18n/cv.json
19:36:24 INFO: 1269/6731 files analyzed, current file: languages/i18n/szy.json
19:36:34 INFO: 1440/6731 files analyzed, current file: includes/api/ApiQueryAllLinks.php
19:36:44 INFO: 1639/6731 files analyzed, current file: languages/i18n/bdr.json
19:36:54 INFO: 1783/6731 files analyzed, current file: includes/editpage/Constraint/UserRateLimitConstraint.php
19:37:04 INFO: 2025/6731 files analyzed, current file: languages/i18n/vmw.json
19:37:14 INFO: 2210/6731 files analyzed, current file: languages/i18n/tt-latn.json
19:37:24 INFO: 2325/6731 files analyzed, current file: languages/i18n/sr-ec.json
19:37:34 INFO: 2456/6731 files analyzed, current file: languages/i18n/ti.json
19:37:44 INFO: 2686/6731 files analyzed, current file: languages/i18n/cy.json
19:37:54 INFO: 2819/6731 files analyzed, current file: languages/i18n/tk.json
19:38:04 INFO: 3037/6731 files analyzed, current file: languages/i18n/exif/bn.json
19:38:14 INFO: 3193/6731 files analyzed, current file: languages/i18n/qqq.json
19:38:24 INFO: 3387/6731 files analyzed, current file: languages/i18n/sah.json
19:38:34 INFO: 3586/6731 files analyzed, current file: languages/messages/MessagesCy.php
19:38:44 INFO: 3732/6731 files analyzed, current file: languages/i18n/sk.json
19:38:46 WARN: Invalid character encountered in file /workspace/src/tests/phpunit/unit/includes/tidy/html5lib-tests.json at line 3623 for encoding UTF-8. Please fix file content or configure the encoding to be used using property 'sonar.sourceEncoding'.
19:38:54 INFO: 3901/6731 files analyzed, current file: includes/ServiceWiring.php
19:39:04 INFO: 4060/6731 files analyzed, current file: languages/i18n/gor.json
19:39:14 INFO: 4228/6731 files analyzed, current file: languages/i18n/ruq-latn.json
19:39:24 INFO: 4403/6731 files analyzed, current file: languages/i18n/bs.json
19:39:34 INFO: 4521/6731 files analyzed, current file: languages/i18n/tay.json
19:39:44 INFO: 4658/6731 files analyzed, current file: languages/messages/MessagesKsw.php
19:39:54 INFO: 4848/6731 files analyzed, current file: includes/Storage/DerivedPageDataUpdater.php
19:40:04 INFO: 5029/6731 files analyzed, current file: languages/i18n/myv.json
19:40:14 INFO: 5213/6731 files analyzed, current file: languages/i18n/exif/or.json
19:40:24 INFO: 5353/6731 files analyzed, current file: includes/libs/rdbms/database/replication/MysqlReplicationReporter.php
19:40:34 INFO: 5482/6731 files analyzed, current file: languages/i18n/et.json
19:40:44 INFO: 5675/6731 files analyzed, current file: languages/i18n/kcg.json
19:40:54 INFO: 5830/6731 files analyzed, current file: languages/i18n/rue.json
19:41:04 INFO: 5998/6731 files analyzed, current file: includes/installer/i18n/cs.json
19:41:14 INFO: 6172/6731 files analyzed, current file: includes/content/ContentHandler.php
19:41:24 INFO: 6372/6731 files analyzed, current file: languages/i18n/tg-cyrl.json
19:41:34 INFO: 6521/6731 files analyzed, current file: languages/i18n/rmc.json
19:41:44 INFO: 6731/6731 source files have been analyzed
19:41:44 INFO: Sensor TextAndSecretsSensor [text] (done) | time=400114ms

Event Timeline

Change 975361 had a related patch set uploaded (by Kosta Harlan; author: Kosta Harlan):

[mediawiki/core@master] [WIP] sonar: Set up sonar-project.properties

https://gerrit.wikimedia.org/r/975361

It also looks like the taint analysis takes 8 minutes

22:08:12 INFO: Taint analysis for php: Starting
22:08:12 INFO: 0 / 24052 UCFGs simulated, memory usage: 895 MB
22:08:15 INFO: 703 / 24052 UCFGs simulated, memory usage: 2033 MB
22:08:19 INFO: 1360 / 24052 UCFGs simulated, memory usage: 1884 MB
22:08:26 INFO: 2044 / 24052 UCFGs simulated, memory usage: 1157 MB
22:08:32 INFO: 2633 / 24052 UCFGs simulated, memory usage: 2091 MB
22:08:37 INFO: 3212 / 24052 UCFGs simulated, memory usage: 1304 MB
22:08:41 INFO: 3626 / 24052 UCFGs simulated, memory usage: 1861 MB
22:08:47 INFO: 4347 / 24052 UCFGs simulated, memory usage: 1253 MB
22:08:55 INFO: 4746 / 24052 UCFGs simulated, memory usage: 1752 MB
22:09:03 INFO: 5222 / 24052 UCFGs simulated, memory usage: 2390 MB
22:09:17 INFO: 5698 / 24052 UCFGs simulated, memory usage: 2337 MB
22:09:27 INFO: 6127 / 24052 UCFGs simulated, memory usage: 2329 MB
22:09:41 INFO: 6588 / 24052 UCFGs simulated, memory usage: 2278 MB
22:09:51 INFO: 6910 / 24052 UCFGs simulated, memory usage: 2319 MB
22:10:00 INFO: 7219 / 24052 UCFGs simulated, memory usage: 2492 MB
22:10:08 INFO: Too high simulation costs for sink in /workspace/src/includes/libs/filebackend/fsfile/TempFSFileFactory.php:43. This sink will not be analyzed any further.
22:10:11 INFO: 7577 / 24052 UCFGs simulated, memory usage: 2552 MB
22:10:24 INFO: 7971 / 24052 UCFGs simulated, memory usage: 2535 MB
22:10:39 INFO: 8470 / 24052 UCFGs simulated, memory usage: 3162 MB
22:10:47 INFO: 8893 / 24052 UCFGs simulated, memory usage: 3362 MB
22:10:54 INFO: 9347 / 24052 UCFGs simulated, memory usage: 3319 MB
22:11:04 INFO: 9939 / 24052 UCFGs simulated, memory usage: 3721 MB
22:11:16 INFO: 10464 / 24052 UCFGs simulated, memory usage: 3503 MB
22:11:26 INFO: 11023 / 24052 UCFGs simulated, memory usage: 3265 MB
22:11:27 INFO: Too high simulation costs for sink in /workspace/src/includes/libs/filebackend/FSFileBackend.php:928. This sink will not be analyzed any further.
22:11:27 INFO: Too high simulation costs for sink in /workspace/src/includes/libs/filebackend/FSFileBackend.php:592. This sink will not be analyzed any further.
22:11:38 INFO: 11328 / 24052 UCFGs simulated, memory usage: 3349 MB
22:12:09 INFO: 11337 / 24052 UCFGs simulated, memory usage: 3718 MB
22:12:15 INFO: 11833 / 24052 UCFGs simulated, memory usage: 3711 MB
22:12:23 INFO: 12296 / 24052 UCFGs simulated, memory usage: 3662 MB
22:12:28 INFO: 12811 / 24052 UCFGs simulated, memory usage: 3815 MB
22:12:38 INFO: 13257 / 24052 UCFGs simulated, memory usage: 3961 MB
22:12:48 INFO: 13488 / 24052 UCFGs simulated, memory usage: 5184 MB
22:12:58 INFO: 14015 / 24052 UCFGs simulated, memory usage: 4033 MB
22:13:07 INFO: 14477 / 24052 UCFGs simulated, memory usage: 3996 MB
22:13:18 INFO: 14849 / 24052 UCFGs simulated, memory usage: 4810 MB
22:13:35 INFO: 15199 / 24052 UCFGs simulated, memory usage: 4015 MB
22:13:50 INFO: 15539 / 24052 UCFGs simulated, memory usage: 4239 MB
22:14:03 INFO: 15960 / 24052 UCFGs simulated, memory usage: 5083 MB
22:14:12 INFO: 16510 / 24052 UCFGs simulated, memory usage: 4824 MB
22:14:20 INFO: 16947 / 24052 UCFGs simulated, memory usage: 4537 MB
22:14:37 INFO: 17322 / 24052 UCFGs simulated, memory usage: 4654 MB
22:14:48 INFO: 17902 / 24052 UCFGs simulated, memory usage: 5295 MB
22:14:55 INFO: 18456 / 24052 UCFGs simulated, memory usage: 5262 MB
22:15:06 INFO: 18988 / 24052 UCFGs simulated, memory usage: 5142 MB
22:15:18 INFO: 19454 / 24052 UCFGs simulated, memory usage: 5353 MB
22:15:27 INFO: 19856 / 24052 UCFGs simulated, memory usage: 5291 MB
22:15:37 INFO: 20387 / 24052 UCFGs simulated, memory usage: 5213 MB
22:15:51 INFO: 20847 / 24052 UCFGs simulated, memory usage: 5348 MB
22:16:00 INFO: 21273 / 24052 UCFGs simulated, memory usage: 5461 MB
22:16:10 INFO: 21766 / 24052 UCFGs simulated, memory usage: 5450 MB
22:16:13 INFO: 21909 / 24052 UCFGs simulated, memory usage: 5457 MB
22:16:13 INFO: Taint analysis for php: Time spent was 00:08:01.047

I did some searching, I am not sure if it's possible to disable the taint analysis, but perhaps Quality-and-Test-Engineering-Team could follow-up with SonarCloud about that.

Change 975361 abandoned by Kosta Harlan:

[mediawiki/core@master] [WIP] sonar: Set up sonar-project.properties

Reason:

https://gerrit.wikimedia.org/r/975361

pwangai changed the task status from Open to In Progress.Jul 18 2024, 3:40 PM
pwangai claimed this task.

I did a few optimizations, and they seem to have positively impacted the time it takes to run codehealth checks on Core. I think this is an acceptable margin as it has reduced the average running time from ~20 minutes to ~10 minutes. I have monitored the trend for almost a week and it seems consistent.

mwcore-codehealth-patch_Build_time_trend.png (1×3 px, 586 KB)