[SR-11632] Higher maximum jobs (-j) lead to longer build time

swift-ci commented 4 years ago


Previous ID	SR-11632
Radar	rdar://problem/56397673
Original Reporter	polac24 (JIRA User)
Type	Bug

Attachment: Download

Environment

- 8-core 2,4 GHz Intel Core i9 MacBook Pro - 16 GB RAM - Xcode 11.0 - MacOS Mojave 10.14.6 (18G103)

Additional Detail from JIRA

| | | |------------------|-----------------| |Votes | 2 | |Component/s | Compiler | |Labels | Bug | |Assignee | None | |Priority | Medium | md5: da0af5b4cf3f0467c8dd995db3243a55

Issue Description:

For a small target, where there are about 10-30 swift files, limiting the number of jobs to 4 passed to swiftc command (-j4) speeds up the overall building time.
The dummy, sample project improves 15s -> 7s on a local machine, 8-code i9 MacBookPro.

Steps to reproduce:

8 cores machine is recommended (but 6 should expose an issue too)
Expand MaxJobs3.zip and call ./reproduce.sh
This is what it does:
- Clean relative/local DerivedData from any previous runs (no global DerivedData is used)
- Performs the same command as Xcode incremental build three times with times summary:
  - first with -jNUMBER_OF_CORES
  - then with -j4
  - first with -jNUMBER_OF_CORES (just to demonstrate that there is no caching)
Time for the second run is signifficantly smaller (e.g. 13.524s -> 6.518s) ❌

Sample output (local machine):

Building with 16 jobs...
real    0m13.524s
user    0m48.149s
sys 1m6.364s

Building with 4 jobs...
real    0m6.518s
user    0m12.253s
sys 0m4.736s

Building with 16 jobs...
real    0m13.238s
user    0m52.122s
sys 1m5.685s

This is observed only for small projects 10-30 files.

Build times improvment `-j16` vs `-j4` for various project size:

project with 10 files (4s -> 1.5s)
project with 100 files: (8.7s -> 8.2s)
project with 340 files: (21.5s -> 32s)

swift-ci commented 4 years ago

Comment by Bartosz Polaczyk (JIRA)

I disabled antivirus for testing

-Xfrontend -Rmodule-interface-rebuild didn't print anything extra
for a real project (about 20 swift targets, 10 swift files on average) we experimented with a thin wrapper that limits -j to 3 and final improvement was around 330s -> 240s.

swift-ci commented 4 years ago

Comment by Bartosz Polaczyk (JIRA)

For reference, my generated command that I used:

time /Applications/Xcode_1100.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/swiftc -incremental -module-name MaxJobs -Onone -enable-batch-mode -enforce-exclusivity=checked @/Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/Objects-normal/x86_64/MaxJobs.SwiftFileList -DDEBUG -sdk /Applications/Xcode_1100.app/Contents/Developer/Platforms/iPhoneSimulator.platform/Developer/SDKs/iPhoneSimulator13.0.sdk -target x86_64-apple-ios13.0-simulator -g -module-cache-path /Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/ModuleCache.noindex -Xfrontend -serialize-debugging-options -enable-testing -index-store-path /Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Index/DataStore -swift-version 5 -I /Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Products/Debug-iphonesimulator -F /Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Products/Debug-iphonesimulator -c -j16 -output-file-map /Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/Objects-normal/x86_64/MaxJobs-OutputFileMap.json -parseable-output -serialize-diagnostics -emit-dependencies -emit-module -emit-module-path /Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/Objects-normal/x86_64/MaxJobs.swiftmodule -Xcc -I/Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/swift-overrides.hmap -Xcc -iquote -Xcc /Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/MaxJobs-generated-files.hmap -Xcc -I/Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/MaxJobs-own-target-headers.hmap -Xcc -I/Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/MaxJobs-all-target-headers.hmap -Xcc -iquote -Xcc /Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/MaxJobs-project-headers.hmap -Xcc -I/Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Products/Debug-iphonesimulator/include -Xcc -I/Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/DerivedSources-normal/x86_64 -Xcc -I/Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/DerivedSources/x86_64 -Xcc -I/Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/DerivedSources -Xcc -DDEBUG=1 -emit-objc-header -emit-objc-header-path /Users/username/Desktop/MaxJobs/MaxJobs/DerivedData/MaxJobs/Build/Intermediates.noindex/MaxJobs.build/Debug-iphonesimulator/MaxJobs.build/Objects-normal/x86_64/MaxJobs-Swift.h -working-directory /Users/username/Desktop/MaxJobs/MaxJobs

beccadax commented 4 years ago

@swift-ci create

beccadax commented 4 years ago

polac24 (JIRA User) I'm a little confused about your reproduction instructions:

1. Are you cleaning the build folder between the two manual commands? If not, the second command may be skipping some of the work done by the first.

2. The command you pasted includes -module-cache-path /Users/bartoszp/Desktop/MaxJobs/MaxJobs/DerivedData/ModuleCache.noindex, which is a directory that's not in the normal build intermediates folder. When you clean the DerivedData folder, are you deleting this directory? If not, the second command may be reusing modules built by the first.

Thanks!

swift-ci commented 4 years ago

Comment by Bartosz Polaczyk (JIRA)

brentdax (JIRA User), sorry for not-so-easy steps to reproduce. I modified steps to reproduce an uploaded a shell script that automates it.

To answer:

Yes, I was removing entire DerivedData (almost)
my deletion included ModuleCache.noindex too

swift-ci commented 4 years ago

Comment by Patrick Balestra (JIRA)

brentdax (JIRA User) Do you have any official update regarding this? Is it a side-effect of optimizing the compiler performance for larger Swift modules?

swift-ci commented 4 years ago

Comment by Bartosz Polaczyk (JIRA)

Here are the results from the same machine (Xcode 11.0.0) built in a ssafe mode (that limit the impact from third-party demons):

Building with 16 jobs...

real    1m23.119s
user    17m48.556s
sys 0m23.801s
Building with 4 jobs...

real    0m44.344s
user    2m38.451s
sys 0m4.565s
Building with 16 jobs...

real    1m27.299s
user    18m16.711s
sys 0m27.703s

swift-ci commented 4 years ago

Comment by Bartosz Polaczyk (JIRA)

We get another output: iMac Pro, 18-cores Intel(R) Xeon(R) W-2191B CPU @ 2.30GHz, no anti-virus installed, Xcode 11.3

Building with 36 jobs...
real    0m7.600s
user    0m32.209s
sys 0m23.893s
Building with 4 jobs...
real    0m5.969s
user    0m11.907s
sys 0m3.135s
Building with 36 jobs...
real    0m6.463s
user    0m31.764s
sys 0m20.792s

36 parallel jobs (all CPUs) took \~7 seconds in total
4 jobs took \~6 seconds in total

swift-ci commented 4 years ago

Comment by Khaos Tian (JIRA)

This might be somewhat related to SR-11927? There were a few workarounds landed in swift master recently, and using the latest snapshot build, the result is much better:

swiftc from macOS 10.15.2

Building with 32 jobs...

real    0m6.913s
user    0m29.720s
sys 0m15.265s
Building with 4 jobs...

real    0m5.871s
user    0m11.869s
sys 0m2.921s
Building again with 32 jobs...

real    0m6.397s
user    0m28.703s
sys 0m15.269s

swiftc from 2019-12-26 snapshot

Building with 32 jobs...

real    0m5.962s
user    0m34.839s
sys 0m5.661s
Building with 4 jobs...

real    0m6.459s
user    0m15.275s
sys 0m2.209s
Building again with 32 jobs...

real    0m5.912s
user    0m34.641s
sys 0m5.679s

swift-ci commented 3 years ago

Comment by Bartosz Polaczyk (JIRA)

Let me just update with results for Swift 5.3 and SNAPSHOT-2020-10-07.
Unfortunately, I am not able to benchmark the development trunk with the larger project (crash SR-13751).

7th of October trunk Snapshot:

Building with 16 jobs...

real    0m12.705s
user    0m59.808s
sys 0m4.527s
Building with 4 jobs...

real    0m11.850s
user    0m21.021s
sys 0m2.742s
Building again with 16 jobs...

real    0m12.290s
user    1m1.354s
sys 0m4.933s

Swift 5.3 (Xcode 12.0.0):

Building with 16 jobs...

real    0m8.286s
user    0m48.922s
sys 0m5.722s
Building with 4 jobs...

real    0m7.065s
user    0m15.185s
sys 0m2.581s
Building again with 16 jobs...

real    0m7.961s
user    0m52.779s
sys 0m5.307s

swiftlang / swift