CODEWITHSUNDEEP
iosswiftcompilation
coping
coping

Reputation: 835

How to debug slow Swift compile times

I have a Swift SpriteKit project with about 25 smallish files. The time to compile this project is 30-45 seconds! It's pure Swift with no ObjC.

I've watched the compile in the Report Navigator to try to find a single file that's taking the time. But, it's not really a single file. It's always the last file in the list that seems to take all the time. But that file can be different between compiles and still takes all the time.

The step right after the last file is Merge xxx.swiftmodule, which happens quickly, but I'm not sure if because it comes right after the slowness it might be related.

I've searched and tried various approaches to find the culprit. I read this post: Why is Swift compile time so slow? and tried those approaches. I've done a command line build using CTRL-\, but that does not show any useful information about the slowness.

I've gone through my project looking for places where type inference might be getting tripped up, but haven't found much (and really, if that was the case, I'd expect a single file to be the culprit).

Does anyone have any other suggestions for tracking this down? Coming from an Objective-C project that compiles nearly instantly, this is driving me crazy.

EDIT I worked on this a bit more and am including a screen shot of the build output, noting where the slowness happens. The thing is, if I comment out the code in the slow file, then the file before it in the list becomes the slow one (where it was fine before). If I comment that code out, then the one before that becomes the slow one, etc.

Build Output

Upvotes: 9

Views: 2937

Answers (4)

yoAlex5
yoAlex5

Reputation: 34225

Swift time compilation

Swift Compiler Performance

Measure and Tools You should clean and build your project to have a better results for comparing.

  1. Xcode Build time output.
//Terminal command
defaults write com.apple.dt.Xcode ShowBuildOperationDuration YES

Output: enter image description here

  1. Build With Timing Summary.
//Xcode
Product -> Perform Action -> Build With Timing Summary

Output:

Report Navigator -> <build> -> Recent

enter image description here

  1. Type check warnings

Trigger a warning in Xcode for any function/expressions which is more than a user-defined limit to type-check

Build Settings -> Other Swift Flags(OTHER_SWIFT_FLAGS)
-Xfrontend -warn-long-function-bodies=200
-Xfrontend -warn-long-expression-type-checking=200

Output:

Instance method 'foo()' took 200ms to type-check (limit: 200ms)

enter image description here

  1. Record a time which is taken to compile every function/expression
Build Settings -> Other Swift Flags(OTHER_SWIFT_FLAGS)
-Xfrontend -debug-time-function-bodies
-Xfrontend -debug-time-expression-type-checking

Output:

Report Navigator -> <build> -> Expand All Transcripts

-Xfrontend -debug-time-function-bodies

enter image description here

-Xfrontend -debug-time-expression-type-checking

enter image description here

BuildTimeAnalyzer-for-Xcode is based on this flag. Also it has interesting column which is called Occurrences - how many times compiler is type checking it(e.g. lazy properties, closures)

enter image description here

XCLogParser analize logs

xclogparser parse --project Experiments2 --reporter html --rootOutput "/Users/User/Desktop/temp"

enter image description here

You are able to open Xcodelog with .xcactivitylog extension by changing to .zip and unzip it. After it you can open it as a text file

/Users/User/Library/Developer/Xcode/DerivedData/Experiments2-fejelsaznlrfewdtvyfyhhbgxlwl/Logs/Build/00D3B76E-B61B-4FB8-AE0B-1FAD5AF3F452.xcactivitylog

XCMetrics(by Spotify) as a next step of collecting log data

Notes:

-debug-time-compilation was removed

Experiments were made on Xcode v13.3.1. Do not forget to clean project before measure

You are able to set flag for specyfic target(e.g. in modularized project)

Upvotes: 2

Chris Livdahl
Chris Livdahl

Reputation: 4740

Building on other answers, the following commands are helpful...

To see a sorted list of functions by build time: 

xcodebuild -workspace [Your Workspace Name].xcworkspace -scheme [Your Build Scheme Name] clean build OTHER_SWIFT_FLAGS="-Xfrontend -debug-time-function-bodies" | grep .[0-9]ms | grep -v ^0.[0-9]ms | sort -nr > culprits.txt

To see a sorted list of functions that take over 1s to build: 

xcodebuild -workspace [Your Workspace Name].xcworkspace -scheme [Your Build Scheme Name] clean build OTHER_SWIFT_FLAGS="-Xfrontend -debug-time-function-bodies" | grep [1-9].[0-9]ms | sort -nr > culprits.txt

You can get a list of scheme names like so (this command runs a clean first): 

xcodebuild -workspace [Your Workspace Name].xcworkspace -list

Helpful Articles about why your build times may be long:

Upvotes: 4

Valentin Shergin
Valentin Shergin

Reputation: 7334

There is a hidden option in Swift compiler that prints out the exact time intervals that compiler takes to compile every single function: -Xfrontend -debug-time-function-bodies.

Simple run the following in terminal and analyze results:

xcodebuild -workspace App.xcworkspace -scheme App clean build OTHER_SWIFT_FLAGS="-Xfrontend -debug-time-function-bodies" | grep [1-9].[0-9]ms | sort -nr > culprits.txt

Awesome Brian Irace wrote brilliant article about it Profiling your Swift compilation times.

Upvotes: 6

coping
coping

Reputation: 835

After more digging and debugging, I found the problem. It turns out it actually is type inference, as other posts have suggested. Part of the problem is that I did not notice that the build output in the Report Navigator shows an arrow for files still compiling and a checkmark for those that are done (my color blindness played a role). So I thought they were all finished compiling when one was not.

In any case, I read the article here: GM release of Xcode 6 compile and did a command line build of the entire project, which showed me the file that was the issue. Then, using the CTRL-\ approach noted above, I found the culprit.

It turns out that this line was the issue:

ourWindowCopy.position = CGPoint(x: ((26.5 + theXOffset) * self.multiplierWidth) + (4.0 * CGFloat(randomRow) * 2.0 * self.multiplierWidth), y: ((41.0 + theYOffset) * self.multiplierHeight) + (5.75 * CGFloat(randomColumn) * 2.0 * self.multiplierHeight))

I know it seems a mess - I was playing around with a bunch of different options early on and hadn't yet gone back to simplify. I replaced it with this (and will of course replace the literals as well as simply further):

let floatRandomRow = CGFloat(randomRow)
let floatRandomCol = CGFloat(randomColumn)
let pointX: CGFloat = ((26.5 + theXOffset) * self.multiplierWidth) + (4.0 * floatRandomRow * 2.0 * self.multiplierWidth)
let pointY: CGFloat = ((41.0 + theYOffset) * self.multiplierHeight) + (5.75 * floatRandomCol * 2.0 * self.multiplierHeight)

ourWindowCopy.position = CGPoint(x: pointX, y: pointY)

Now the compile speed is very fast!

I'm not sure there's really any new information here, but wanted to close this out with a solution in case someone runs across it.

Upvotes: 6

Related Questions