Pull request time increased

Swift macOS and Linux pull request testing time have increased significantly, it currently takes 5+hrs for macOS and 3+hrs for Linux.

To better understand the time being spent in pull request testing, I've added a feature to the build system that provides timing for each component. Below is a breakdown of the time being spent in the install, test and build phases.

Install Phase

macOS: (Total install phase ~10mins)

Build Percentage 	 Build Duration (sec) 	 Build Phase
================ 	 ==================== 	 ===========
1.7%              	 326.33                	 Installing swiftpm
1.2%              	 227.35                	 Installing swiftdocc

Linux: (Total install phase ~18mins)

Build Percentage 	 Build Duration (sec) 	 Build Phase
================ 	 ==================== 	 ===========
3.4%              	 324.27                	 Installing swiftpm
3.2%              	 300.37                	 Installing sourcekitlsp
2.6%              	 241.7                 	 Installing swiftdocc
1.9%              	 178.01                	 Installing swiftdriver

*only including install phase over 100sec in the table above.

Test Phase

macOS: (Total test phase ~121mins)

Build Percentage 	 Build Duration (sec) 	 Build Phase
================ 	 ==================== 	 ===========
21.5%             	 4120.18               	 macosx-x86_64-swift-test
						- 915.40s 				- check-swift-validation-watchsimulator-x86_64
						- 955.27s 				- check-swift-validation-watchsimulator-i386
						- 929.27s 				- check-swift-validation-iphonesimulator-x86_64
						- 1123.43s 				- check-swift-validation-macosx-x86_64
3.4%              	 647.08                	 macosx-x86_64-lldb-test
3.4%              	 646.1                 	 Running tests for swiftpm
2.8%              	 540.43                	 Running tests for swiftdriver
2.2%              	 426.13                	 Running tests for sourcekitlsp
1.6%              	 297.12                	 Running tests for swiftsyntax
1.4%              	 267.45                	 Running tests for skstresstester
1.4%              	 261.46                	 Running tests for swiftevolve

Linux: (Total test phase ~55mins)

Build Percentage 	 Build Duration (sec) 	 Build Phase
================ 	 ==================== 	 ===========
8.9%              	 836.63                	 linux-x86_64-swift-test
6.9%              	 652.31                	 Running tests for swiftdocc
5.6%              	 528.61                	 Running tests for swiftpm
4.4%              	 415.97                	 Running tests for swiftdriver
3.8%              	 356.48                	 Running tests for sourcekitlsp
2.5%              	 232.26                	 linux-x86_64-foundation-test
1.5%              	 141.42                	 linux-x86_64-lldb-test

*only including test phase over 100sec in the table above.

Build Phase

macOS: (Total build phase ~188mins)

Build Percentage 	 Build Duration (sec) 	 Build Phase
================ 	 ==================== 	 ===========
30.5%             	 5845.22               	 macosx-x86_64-swift-build
						- Top stdlib builds
							- 1510s					- stdlib/public/core/WATCHOS_SIMULATOR/i386/Swift.o
							- 1509s					- stdlib/public/core/IOS_SIMULATOR/i386/Swift.o
							- 1492s					- stdlib/public/core/IOS/armv7/Swift.o
							- 1492s					- stdlib/public/core/IOS/armv7s/Swift.o
							- 1488s					- stdlib/public/core/WATCHOS/armv7k/Swift.o
							- 1485s					- stdlib/public/core/WATCHOS/arm64_32/Swift.o
							- 1070s					- stdlib/public/core/OSX/x86_64/Swift.o
							- 1060s					- stdlib/public/core/OSX/arm64/Swift.o
							- 1024s					- stdlib/public/core/WATCHOS_SIMULATOR/x86_64/Swift.o
							- 1022s					- stdlib/public/core/IOS_SIMULATOR/x86_64/Swift.o
							- 1016s					- stdlib/public/core/IOS/arm64e/Swift.o
							- 1013s					- stdlib/public/core/IOS/arm64/Swift.o
							- 1012s					- stdlib/public/core/IOS_SIMULATOR/arm64/Swift.o
							- 1011s					- stdlib/public/core/WATCHOS_SIMULATOR/arm64/Swift.o
						- Top Benchmark builds 
							- 430s					- benchmark/Osize-arm64-apple-ios8.0/SortStrings.o
							- 383s					- benchmark/Osize-arm64_32-apple-watchos2.0/SortStrings.o
							- 184s					- benchmark/Osize-arm64e-apple-ios8.0/SortStrings.o
							- 170s					- benchmark/Osize-armv7-apple-ios8.0/PrimsNonStrongRef.o
							- 163s					- benchmark/Osize-armv7k-apple-watchos2.0/PrimsNonStrongRef.o
							- 156s					- benchmark/Osize-armv7-apple-ios8.0/PrimsSplit.o
							- 151s					- benchmark/Osize-armv7-apple-ios8.0/Prims.o
							- 150s					- benchmark/Osize-armv7k-apple-watchos2.0/PrimsSplit.o
							- 149s					- benchmark/Osize-armv7k-apple-watchos2.0/Prims.o
13.4%             	 2573.22               	 macosx-x86_64-llvm-build
3.0%              	 583.75                	 Building swiftpm
2.2%              	 422.21                	 macosx-x86_64-lldb-build
1.9%              	 361.74                	 Building sourcekitlsp
1.6%              	 296.96                	 Building swiftdocc
1.5%              	 279.35                	 Building skstresstester
1.4%              	 273.4                 	 Building swiftsyntax
1.4%              	 261.72                	 Building swiftevolve
0.8%              	 157.77                	 Building swiftdriver
0.5%              	 103.05                	 Building earlyswiftdriver

Linux: (Total build phase ~81mins)

Build Percentage 	 Build Duration (sec) 	 Build Phase
================ 	 ==================== 	 ===========
16.6%             	 1562.24               	 linux-x86_64-swift-build
16.3%             	 1533.94               	 linux-x86_64-llvm-build
4.8%              	 449.79                	 Building swiftpm
3.3%              	 310.35                	 Building sourcekitlsp
3.0%              	 277.96                	 linux-x86_64-lldb-build
2.9%              	 269.4                 	 Building swiftdocc
1.3%              	 125.23                	 Building swiftdriver
1.1%              	 105.08                	 Building benchmarks

*only including build phase over 100sec in the table above.

Swift trace (macosx-x86_64-swift-build, macosx-x86_64-swift-test)

How to view the trace locally:
  • Download the swift.json (1.3 MB)

  • Open Chrome - chrome://tracing/

  • Drag and drop swift.json file.

Questions to explore:

  • Why is the install phase for swiftpm, swiftdocc, sourcekitlsp and swiftdriver taking this long?
  • Can we reduce the test phase down?
  • Can we reduce the build time for benchmarks?
macOS full build duration log
Build Percentage 	 Build Duration (sec) 	 Build Phase
================ 	 ==================== 	 ===========
30.5%             	 5845.22               	 macosx-x86_64-swift-build
21.5%             	 4120.18               	 macosx-x86_64-swift-test
13.4%             	 2573.22               	 macosx-x86_64-llvm-build
3.4%              	 647.08                	 macosx-x86_64-lldb-test
3.4%              	 646.1                 	 Running tests for swiftpm
3.0%              	 583.75                	 Building swiftpm
2.8%              	 540.43                	 Running tests for swiftdriver
2.2%              	 426.13                	 Running tests for sourcekitlsp
2.2%              	 422.21                	 macosx-x86_64-lldb-build
1.9%              	 361.74                	 Building sourcekitlsp
1.7%              	 326.33                	 Installing swiftpm
1.6%              	 297.12                	 Running tests for swiftsyntax
1.6%              	 296.96                	 Building swiftdocc
1.5%              	 279.35                	 Building skstresstester
1.4%              	 273.4                 	 Building swiftsyntax
1.4%              	 267.45                	 Running tests for skstresstester
1.4%              	 261.72                	 Building swiftevolve
1.4%              	 261.46                	 Running tests for swiftevolve
1.2%              	 227.35                	 Installing swiftdocc
0.8%              	 157.77                	 Building swiftdriver
0.5%              	 103.05                	 Building earlyswiftdriver
0.3%              	 65.08                 	 Running tests for indexstoredb
0.3%              	 60.87                 	 macosx-x86_64-llbuild-build
0.3%              	 51.04                 	 Building indexstoredb
0.1%              	 13.95                 	 macosx-x86_64-llbuild-test
0.1%              	 13.18                 	 Building playgroundsupport
0.1%              	 10.44                 	 macosx-x86_64-swift-install
0.0%              	 6.85                  	 Building cmark
0.0%              	 5.04                  	 macosx-x86_64-llvm-install
0.0%              	 4.0                   	 macosx-x86_64-libcxx-build
0.0%              	 2.29                  	 Installing swiftdriver
0.0%              	 0.85                  	 macosx-x86_64-libcxx-install
0.0%              	 0.17                  	 macosx-x86_64-llbuild-install
0.0%              	 0.16                  	 Cleaning swiftpm
0.0%              	 0.15                  	 Cleaning swiftdriver
0.0%              	 0.11                  	 macosx-x86_64-libcxx-test
0.0%              	 0.1                   	 macosx-x86_64-llvm-test
0.0%              	 0.09                  	 macosx-x86_64-lldb-install
0.0%              	 0.06                  	 macosx-x86_64-extractsymbols
0.0%              	 0.06                  	 macosx-x86_64-package
0.0%              	 0.05                  	 merged-hosts-lipo-core
0.0%              	 0.05                  	 merged-hosts-lipo
0.0%              	 0.03                  	 Installing swiftdoccrender
Total Duration: 19152.64
Linux full build duration log
Build Percentage 	 Build Duration (sec) 	 Build Phase
================ 	 ==================== 	 ===========
16.6%             	 1562.24               	 linux-x86_64-swift-build
16.3%             	 1533.94               	 linux-x86_64-llvm-build
8.9%              	 836.63                	 linux-x86_64-swift-test
6.9%              	 652.31                	 Running tests for swiftdocc
5.6%              	 528.61                	 Running tests for swiftpm
4.8%              	 449.79                	 Building swiftpm
4.4%              	 415.97                	 Running tests for swiftdriver
3.8%              	 356.48                	 Running tests for sourcekitlsp
3.4%              	 324.27                	 Installing swiftpm
3.3%              	 310.35                	 Building sourcekitlsp
3.2%              	 300.37                	 Installing sourcekitlsp
3.0%              	 277.96                	 linux-x86_64-lldb-build
2.9%              	 269.4                 	 Building swiftdocc
2.6%              	 241.7                 	 Installing swiftdocc
2.5%              	 232.26                	 linux-x86_64-foundation-test
1.9%              	 178.01                	 Installing swiftdriver
1.7%              	 161.44                	 linux-x86_64-package
1.5%              	 141.42                	 linux-x86_64-lldb-test
1.3%              	 125.23                	 Building swiftdriver
1.1%              	 105.08                	 Building benchmarks
1.0%              	 94.34                 	 linux-x86_64-foundation-build
0.8%              	 75.43                 	 linux-x86_64-libicu-build
0.4%              	 34.72                 	 linux-x86_64-foundation-install
0.3%              	 31.14                 	 Running tests for indexstoredb
0.3%              	 29.76                 	 linux-x86_64-libdispatch-test
0.3%              	 28.93                 	 linux-x86_64-llbuild-build
0.3%              	 26.02                 	 linux-x86_64-llbuild-test
0.2%              	 21.54                 	 Building indexstoredb
0.2%              	 19.68                 	 linux-x86_64-libdispatch-build
0.2%              	 16.45                 	 linux-x86_64-libicu-test
0.2%              	 16.29                 	 linux-x86_64-xctest-test
0.1%              	 5.2                   	 linux-x86_64-xctest-build
0.0%              	 4.49                  	 linux-x86_64-llbuild-install
0.0%              	 3.24                  	 Building cmark
0.0%              	 2.94                  	 Running tests for cmark
0.0%              	 2.48                  	 linux-x86_64-llvm-install
0.0%              	 1.61                  	 linux-x86_64-swift-install
0.0%              	 1.22                  	 Running tests for benchmarks
0.0%              	 0.97                  	 linux-x86_64-lldb-install
0.0%              	 0.26                  	 linux-x86_64-xctest-install
0.0%              	 0.19                  	 linux-x86_64-libicu-install
0.0%              	 0.13                  	 linux-x86_64-libdispatch-install
0.0%              	 0.11                  	 Cleaning swiftdriver
0.0%              	 0.08                  	 linux-x86_64-llvm-test
0.0%              	 0.07                  	 merged-hosts-lipo
0.0%              	 0.06                  	 merged-hosts-lipo-core
0.0%              	 0.06                  	 linux-x86_64-extractsymbols
0.0%              	 0.05                  	 Cleaning swiftpm
0.0%              	 0.01                  	 Installing swiftdoccrender
Total Duration: 9420.93
11 Likes

I recommend that we stop building and testing for 64-bit watch simulator. It isn't going to provide any signal beyond what we get for the 32-bit watch simulator (which is good at detecting 32-bit-specific issues) or the 64-bit iOS simulator (which is good at detecting iOS-specific issues). That should save us at least 1024s (x86_64 watch simulator Swift.o build) + 1011s (arm64 watch simulator Swift.o build) + 929s (validation tests for x86_64 watch simulator), plus assorted other build stuff.

We build a lot of copies of the Swift standard library (at 1000-1500s each) that aren't getting tested. Even without direct testing, there is some value in building them, but perhaps not in building all of them: we might be able to drop armv7 iOS (it's covered by armv7s well enough), arm64 iOS, and i386 iOS simulator (it's covered by i386 watchOS simulator) without losing coverage. We'd have to try it to make sure that tests still run appropriately.

Doug

3 Likes

@mishal_shah Would you be able to share the build invocations that produce these results? I've been able to run your log-build-time branch locally but the default build commands don't seem to test all of the targets by default.

I was able to replicate some of the build process using the same timing information. Here are my results on a 2020 i9 iMac (10/20 core) on 12.2.1, Xcode 13.2.1, and sccache built from source.

utils/build-script --swift-darwin-supported-archs "$(uname -m)" \
--sccache --release-debuginfo --swift-disable-dead-stripping --test

Build Percentage 	 Build Duration (sec) 	 Build Phase
================ 	 ==================== 	 ===========
49.5%             	 1530.26               	 macosx-x86_64-llvm-build
33.5%             	 1037.05               	 macosx-x86_64-swift-build
14.5%             	 447.48                	 macosx-x86_64-swift-test
2.2%              	 67.35                 	 Building earlyswiftdriver
0.1%              	 4.5                   	 Building cmark
0.1%              	 3.9                   	 Running tests for cmark
0.0%              	 0.13                  	 macosx-x86_64-llvm-install
0.0%              	 0.11                  	 macosx-x86_64-swift-install
0.0%              	 0.1                   	 macosx-x86_64-llvm-test
0.0%              	 0.08                  	 macosx-x86_64-extractsymbols
0.0%              	 0.07                  	 macosx-x86_64-package
0.0%              	 0.06                  	 merged-hosts-lipo-core
0.0%              	 0.06                  	 merged-hosts-lipo
Total Duration: 3091.15

Now, the overall result isn't comparable, as the same things weren't tested, but we can compare some of the smaller items. Namely macosx-x86_64-swift-test. Assuming my build only ran the macOS tests (check-swift-validation-macosx-x86_64 above), we can see my setup is roughly 2.5x faster than whatever ran these tests. To me this indicates there's a lot to be gained by upgrading the runner hardware and may change the calculus for what platforms to drop.

I'm also interested in profiling why it takes so long to run these test suites in the first place. Are there any additional flags to gather test timing at all?

macOS

  • Preset
    buildbot_all_platforms,tools=RA,stdlib=RA
  • Build command:
./swift/utils/build-script \
--preset=buildbot_all_platforms,tools=RA,stdlib=RA 

Linux:

  • Preset:
    buildbot_linux
  • Build command:
 ./swift/utils/build-script --preset buildbot_linux install_destdir=/home/build-user/swift-nightly-install installable_package=/home/build-user/PR-ubuntu2004.tar.gz' 

I would avoid using sccache if you are doing build time benchmark, however it should be fine if you are only interested in test time. If you would like to break down of which tests are taking long time to execute, lit.py has a flag to display top 10 slow tests (--time-tests).

Here is example from another run I did:

Slowest Tests:
--------------------------------------------------------------------------
172.74s: Swift-validation(macosx-x86_64) :: Python/swift_build_support.swift
104.15s: Swift-validation(macosx-x86_64) :: BuildSystem/llvm-targets-options.test
94.86s: Swift(macosx-x86_64) :: Prototypes/CollectionTransformers.swift
79.85s: Swift(macosx-x86_64) :: APIJSON/spi.swift
79.16s: Swift(macosx-x86_64) :: APIJSON/apigen.swift
78.17s: Swift(macosx-x86_64) :: APIJSON/non-objc-class.swift
76.10s: Swift(macosx-x86_64) :: Interpreter/dynamic_replacement.swift
71.20s: Swift(macosx-x86_64) :: ClangImporter/requirement-conflict.swift
65.28s: Swift(macosx-x86_64) :: TypeDecoder/foreign_types.swift
63.88s: Swift(macosx-x86_64) :: TypeDecoder/objc_classes.swift
61.22s: Swift-validation(macosx-x86_64) :: Casting/BoxingCasts-4.test
60.90s: Swift-validation(macosx-x86_64) :: Casting/BoxingCasts-5.test
56.38s: Swift(macosx-x86_64) :: stdlib/SIMDConcreteIntegers.swift.gyb
54.23s: Swift(macosx-x86_64) :: refactoring/ConvertAsync/basic.swift
53.11s: Swift-validation(macosx-x86_64) :: BuildSystem/llvm-targets-options-for-cross-compile-hosts.test
46.46s: Swift(macosx-x86_64) :: stdlib/NumericParsing.swift.gyb
46.23s: Swift(macosx-x86_64) :: SourceKit/CursorInfo/cursor_info.swift
46.20s: Swift-validation(macosx-x86_64) :: BuildSystem/default_build_still_performs_epilogue_opts_after_split.test
42.90s: Swift-validation(macosx-x86_64) :: stdlib/Dictionary.swift
40.65s: Swift(macosx-x86_64) :: Interop/Cxx/value-witness-table/custom-destructors-virtual.swift

Tests Times:
--------------------------------------------------------------------------
[   Range   ] :: [               Percentage               ] :: [   Count   ]
--------------------------------------------------------------------------
[170s,180s) :: [                                        ] :: [    1/15327]
[160s,170s) :: [                                        ] :: [    0/15327]
[150s,160s) :: [                                        ] :: [    0/15327]
[140s,150s) :: [                                        ] :: [    0/15327]
[130s,140s) :: [                                        ] :: [    0/15327]
[120s,130s) :: [                                        ] :: [    0/15327]
[110s,120s) :: [                                        ] :: [    0/15327]
[100s,110s) :: [                                        ] :: [    1/15327]
[ 90s,100s) :: [                                        ] :: [    1/15327]
[ 80s, 90s) :: [                                        ] :: [    3/15327]
[ 70s, 80s) :: [                                        ] :: [    2/15327]
[ 60s, 70s) :: [                                        ] :: [    4/15327]
[ 50s, 60s) :: [                                        ] :: [    3/15327]
[ 40s, 50s) :: [                                        ] :: [    8/15327]
[ 30s, 40s) :: [                                        ] :: [   76/15327]
[ 20s, 30s) :: [                                        ] :: [   81/15327]
[ 10s, 20s) :: [                                        ] :: [  248/15327]
[  0s, 10s) :: [**************************************  ] :: [14899/15327]
--------------------------------------------------------------------------

Testing Time: 1208.83s
  Unsupported      :   355
  Passed           : 14941
  Expectedly Failed:    31

Agree, however this is currently not an option for Swift CI.

Hardware info for macOS

      Model Name: Mac mini
      Model Identifier: Macmini8,1
      Processor Name: 6-Core Intel Core i7
      Processor Speed: 3.2 GHz
      Number of Processors: 1
      Total Number of Cores: 6
      L2 Cache (per Core): 256 KB
      L3 Cache: 12 MB
      Hyper-Threading Technology: Enabled
      Memory: 64 GB