Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[SR-1277] Very slow compilation of lazy var initialisation with closures #43885

Closed
iby opened this issue Apr 20, 2016 · 13 comments
Closed

[SR-1277] Very slow compilation of lazy var initialisation with closures #43885

iby opened this issue Apr 20, 2016 · 13 comments
Labels
bug A deviation from expected or documented behavior. Also: expected but undesirable behavior. compiler The Swift compiler in itself performance type checker Area → compiler: Semantic analysis

Comments

@iby
Copy link

iby commented Apr 20, 2016

Previous ID SR-1277
Radar rdar://problem/26894118
Original Reporter @iby
Type Bug
Status Resolved
Resolution Done
Additional Detail from JIRA
Votes 3
Component/s Compiler
Labels Bug, Performance, TypeChecker
Assignee None
Priority Medium

md5: 0d38906c73f61a3fd3f3214015d6ca1c

Issue Description:

Trying to optimise build time and seeing strange behaviour – in many instances I have stuff like below, on per case basis it takes compiler up to 100x more time to process foo1 compared to foo2.

lazy var foo1: Foo = { … }()
lazy var foo2: Foo = self.getFoo()

private func getFoo() -> Foo {
    …
}

So it seems clear that I must simply provide explicit return type in a closure, but below makes little difference if any at all compared to foo2 above.

lazy var foo1: Foo = { () -> Foo in … }()

I see there're a few issues saying that Swift not playing well with closure types, is that what happening here? Any advice?
@belkadan
Copy link
Contributor

Can you attach a (self-contained) file where the issue reproduces? I think I've heard people complaining about this before, but there was no obvious reproducer.

@iby
Copy link
Author

iby commented Apr 21, 2016

Jordan, just tried getting that code into a separate project and the issue is not reproducible there, this happens on a medium-sized project, can't share the whole thing, but I think there's something else going on.

Looking closer at the logs I see that private func getFoo() -> Foo takes about the same time to compile, but that happens only once. As I understand, swift recompiles public class members as many times as many dependencies there are. So if the block takes X ms to compile and there are Y dependencies, in first case it recompiles lazy var foo1: Foo = { … }() every time taking overall X * Y time, in second case it compiles getFoo only one, and when it compiles lazy var foo2: Foo = self.getFoo() the time is negligible resulting in X time spent overall.

In my situation this happens mostly with lazy-initialised properties – the ones that use blocks or other properties that use structure that requires compiler to think. What do you think?

@iby
Copy link
Author

iby commented Apr 21, 2016

Just to demonstrate the above point, first log is for the same case as lazy var foo1: Foo = { … }(), second is for exactly the same scenario, but block is taken out into a private method: lazy var foo2: Foo = self.getFoo(). Another thing worth mentioning, all properties are private, not public as initially stated.

9.7ms   File.swift:23:61    (closure)
9.6ms   File.swift:23:61    (closure)
9.5ms   File.swift:23:26    get {}
9.1ms   File.swift:23:26    get {}
8.9ms   File.swift:23:26    get {}
8.8ms   File.swift:23:61    (closure)
8.7ms   File.swift:23:61    (closure)
8.7ms   File.swift:23:26    get {}
8.7ms   File.swift:23:26    get {}
8.7ms   File.swift:23:26    get {}
8.5ms   File.swift:23:61    (closure)
8.4ms   File.swift:23:61    (closure)
8.4ms   File.swift:23:61    (closure)
8.4ms   File.swift:23:26    get {}
8.4ms   File.swift:23:26    get {}
8.3ms   File.swift:86:13    final didSet {}
8.3ms   File.swift:23:61    (closure)
8.3ms   File.swift:232:22   private func handleOperationCompleteCallback()
8.2ms   File.swift:23:26    get {}
8.1ms   File.swift:23:61    (closure)
8.0ms   File.swift:23:61    (closure)
7.9ms   File.swift:23:61    (closure)
7.6ms   File.swift:23:26    get {}
7.5ms   File.swift:23:26    get {}
7.4ms   File.swift:23:26    get {}
7.3ms   File.swift:23:26    get {}
7.2ms   File.swift:23:61    (closure)
7.1ms   File.swift:23:61    (closure)
7.0ms   File.swift:23:61    (closure)
7.0ms   File.swift:23:26    get {}
7.0ms   File.swift:23:26    get {}
6.9ms   File.swift:23:61    (closure)
6.9ms   File.swift:23:26    get {}
6.9ms   File.swift:23:26    get {}
6.8ms   File.swift:23:26    get {}
6.8ms   File.swift:23:26    get {}
6.8ms   File.swift:23:26    get {}
6.8ms   File.swift:23:26    get {}
6.8ms   File.swift:23:26    get {}
6.7ms   File.swift:23:26    get {}
6.7ms   File.swift:23:26    get {}
6.7ms   File.swift:23:26    get {}
6.6ms   File.swift:23:61    (closure)
6.6ms   File.swift:23:61    (closure)
6.5ms   File.swift:23:61    (closure)
6.5ms   File.swift:23:61    (closure)
6.5ms   File.swift:23:61    (closure)
6.5ms   File.swift:23:61    (closure)
6.5ms   File.swift:23:61    (closure)
6.4ms   File.swift:23:61    (closure)
6.4ms   File.swift:23:61    (closure)
6.4ms   File.swift:23:61    (closure)
6.4ms   File.swift:23:61    (closure)
6.4ms   File.swift:23:26    get {}
6.4ms   File.swift:23:26    get {}
6.3ms   File.swift:23:61    (closure)
6.1ms   File.swift:23:61    (closure)
6.0ms   File.swift:23:61    (closure)
4.6ms   File.swift:258:22   private func handleOperationProgressCallback(progress: Double)
4.5ms   File.swift:179:22   private func schedule() -> SELF
4.3ms   File.swift:259:55   (closure)
4.0ms   File.swift:310:30   @objc override public func main()
3.7ms   File.swift:209:21   public func write(frame: Frame, immediately: Bool = default) -> SELF
2.9ms   File.swift:117:35   get {}
2.8ms   File.swift:242:54   (closure)
2.4ms   File.swift:121:34   get {}
2.2ms   File.swift:159:21   public func cancel() -> SELF
1.4ms   File.swift:76:13    final didSet {}
11.6ms  File.swift:191:21   public func write(frames: [Frame], immediately: Bool = default) -> SELF
8.9ms   File.swift:25:22    private func getFoo() -> CGImageDestination?
8.7ms   File.swift:64:13    final didSet {}
8.7ms   File.swift:210:22   private func handleOperationCompleteCallback()
5.1ms   File.swift:236:22   private func handleOperationProgressCallback(progress: Double)
4.8ms   File.swift:157:22   private func schedule() -> SELF
4.6ms   File.swift:237:55   (closure)
4.3ms   File.swift:288:30   @objc override public func main()
3.7ms   File.swift:187:21   public func write(frame: Frame, immediately: Bool = default) -> SELF
2.9ms   File.swift:220:54   (closure)
2.8ms   File.swift:95:35    get {}
2.7ms   File.swift:99:34    get {}
2.3ms   File.swift:137:21   public func cancel() -> SELF
1.6ms   File.swift:54:13    final didSet {}

@belkadan
Copy link
Contributor

Ah, we have to do that checking for any member with an inferred type, but if there's a type explicitly declared then other files should be able to just use it. I'm not sure why we're not set up to do that today, but it's definitely a reasonable improvement. It's good to know there's a workaround as well (move the initialization out-of-line).

Thanks for doing that investigation, by the way. That points out that it's not the (expression) type checker that needs to be made faster.

@iby
Copy link
Author

iby commented Apr 21, 2016

Type checker is a problem only at times, I'm yet to fully comprehend how to make the best out of it. The biggest issue are the cases like above – an expression takes 100 ms to compile, not much, but then it's repeated 30 times and now it's 3000 ms for a single class member. Even if it's only 10 ms, it adds up quickly.

@josephlord
Copy link

We are seeing the same issue. We have a lazy instance var that seemed to be being compiled over 400 times and taking a total of nearly 9s. Changing it to a computed var reduced it off the top slow functions list. This is all for a debug build (and the var is a private member) and only accessed in one place so I don't understand why it appears in the compile log so many times. The worst example was easily converted to a computed var but there are other functions taking nearly 3s.

@swift-ci
Copy link
Collaborator

Comment by Prasanth Guruprasad (JIRA)

slightly off-topic, @iby , where do you get the compile times from ? I use the compilation flags -Xfrontend -debug-time-function-bodies , and I use a plugin called 'Xcode Build time analyzer' that outputs the results in a NSWindow. But I haven't been able to copy it out.

@swift-ci
Copy link
Collaborator

Comment by Oscar Swanros (JIRA)

pguruprasad (JIRA User) You can use the following to have the compile times output to a txt file:

$ xcodebuild -project HBUIKit.xcodeproj -scheme HBUIKit clean build OTHER_SWIFT_FLAGS="-Xfrontend -debug-time-function-bodies" | grep .[0-9]ms | grep -v ^0.[0-9]ms | sort -nr > culprits.txt

@swift-ci
Copy link
Collaborator

Comment by Jeff Holliday (JIRA)

We are seeing this as well. We would love it if this were fixed. It would save us large amounts of time, cumulatively.

@belkadan
Copy link
Contributor

Ah, @rudkx fixed this recently, and it should be in the preview 3 branch and Xcode 8b3.

@iby
Copy link
Author

iby commented Jul 22, 2016

😛👍

@josephlord
Copy link

Thanks. Assume you mean this PR: #3354

@belkadan
Copy link
Contributor

Yep, that's the one. Sorry for not linking it previously!

@swift-ci swift-ci transferred this issue from apple/swift-issues Apr 25, 2022
This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug A deviation from expected or documented behavior. Also: expected but undesirable behavior. compiler The Swift compiler in itself performance type checker Area → compiler: Semantic analysis
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@belkadan @josephlord @iby @swift-ci