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

[SR-11312] Type-checker takes a long time on first SIMD init calls #53713

Open
AliSoftware opened this issue Aug 15, 2019 · 5 comments
Open

[SR-11312] Type-checker takes a long time on first SIMD init calls #53713

AliSoftware opened this issue Aug 15, 2019 · 5 comments
Labels
bug A deviation from expected or documented behavior. Also: expected but undesirable behavior. compiler The Swift compiler in itself

Comments

@AliSoftware
Copy link
Contributor

Previous ID SR-11312
Radar None
Original Reporter @AliSoftware
Type Bug
Environment

Swift 5.0.1 (Xcode 10.2.1) and Swift 5.1 (Xcode 11b4)

Additional Detail from JIRA
Votes 0
Component/s Compiler
Labels Bug
Assignee None
Priority Medium

md5: bef33b731cca360caa4ab12a6f7f2937

Issue Description:

Given the following code (whole code from file named GLK+SIMD.swift), the first let line1 takes ~ 70-100ms to type-check – while the remaining line2-4 take ~ 0.12ms.

This even seems to have worsen between Swift 5.0.1 and 5.1

Demo code

import simd
import GLKit

extension simd_float4x4 {
    init(_ matrix: GLKMatrix4) {
        let line1 = float4(matrix.m00, matrix.m01, matrix.m02, matrix.m03)
        let line2 = float4(matrix.m10, matrix.m11, matrix.m12, matrix.m13)
        let line3 = float4(matrix.m20, matrix.m21, matrix.m22, matrix.m23)
        let line4 = float4(matrix.m30, matrix.m31, matrix.m32, matrix.m33)

        self.init(
            line1,
            line2,
            line3,
            line4
        )
    }
}

Results

Swift 5.0.1

$ DEVELOPER_DIR=/Applications/Xcode-10.2.1.app swift --version 
Apple Swift version 5.0.1 (swiftlang-1001.0.82.4 clang-1001.0.46.5)
Target: x86_64-apple-darwin18.7.0

$ DEVELOPER_DIR=/Applications/Xcode-10.2.1.app swiftc -Xfrontend -debug-time-expression-type-checking GLK+SIMD.swift 
78.81ms GLK+SIMD.swift:6:32
0.14ms  GLK+SIMD.swift:7:32
0.11ms  GLK+SIMD.swift:8:32
0.12ms  GLK+SIMD.swift:9:32
0.07ms  GLK+SIMD.swift:11:14
...

Swift 5.1

$ DEVELOPER_DIR=/Applications/Xcode-11b4.app swift --version
Apple Swift version 5.1 (swiftlang-1100.0.257.2 clang-1100.0.31.3)
Target: x86_64-apple-darwin18.7.0

$ DEVELOPER_DIR=/Applications/Xcode-11b4.app swiftc -Xfrontend -debug-time-expression-type-checking GLK+SIMD.swift
100.25ms    GLK+SIMD.swift:6:32
0.15ms  GLK+SIMD.swift:7:32
0.12ms  GLK+SIMD.swift:8:32
0.14ms  GLK+SIMD.swift:9:32
0.10ms  GLK+SIMD.swift:11:14
...

Switching to use the init( x:y:z:w: ) instead of init( _:_:_:_: ) doesn't seem to help.

What's strange is that the long type-checker time affects the first line but not the following ones that have the exact same structure (or is it some caching in action?)

Workaround by rearranging the code

The only workaround I found to reduce the type-checking time to way more reasonable values is to build a reference to the init function first, and then use it:

import simd
import GLKit

extension simd_float4x4 {
    init(_ matrix: GLKMatrix4) {
        let makef4 = SIMD4<Float>.init(x:y:z:w:) as (Float, Float, Float, Float) -> SIMD4<Float>
        let line1 = makef4(matrix.m00, matrix.m01, matrix.m02, matrix.m03)
        let line2 = makef4(matrix.m10, matrix.m11, matrix.m12, matrix.m13)
        let line3 = makef4(matrix.m20, matrix.m21, matrix.m22, matrix.m23)
        let line4 = makef4(matrix.m30, matrix.m31, matrix.m32, matrix.m33)

        self.init(line1, line2, line3, line4)
    }
}

Swift 5.0.1

$ DEVELOPER_DIR=/Applications/Xcode-10.2.1.app swiftc -Xfrontend -debug-time-expression-type-checking GLK+SIMD.swift
1.65ms  GLK+SIMD.swift:6:50
0.21ms  GLK+SIMD.swift:7:21
0.08ms  GLK+SIMD.swift:8:21
0.07ms  GLK+SIMD.swift:9:21
0.08ms  GLK+SIMD.swift:10:21
0.13ms  GLK+SIMD.swift:12:14
...

Swift 5.1

$ DEVELOPER_DIR=/Applications/Xcode-11b4.app swiftc -Xfrontend -debug-time-expression-type-checking GLK+SIMD.swift
21.24ms GLK+SIMD.swift:6:50
0.20ms  GLK+SIMD.swift:7:21
0.08ms  GLK+SIMD.swift:8:21
0.07ms  GLK+SIMD.swift:9:21
0.07ms  GLK+SIMD.swift:10:21
0.10ms  GLK+SIMD.swift:12:14
...

It seems it led to a lot better timings on Swift 5.0.1 (resolution of init reduced to 1.65ms), but is still at 20ms on Swift 5.1 (despite all the hints we give to the type-checker in the code) so there might be some regression there too.

Footnote: It's worse (150ms) in the context of a bigger Xcode project

The initial code I posted at the top of this issue sometimes took >150ms when built in the context or our big project in Xcode 10.2.1 – triggering our -Xfrontend -warn-long-expression-type-checking=150 warning.
I haven't found any extension float4 or extension SIMD4 in our own codebase that would declare more init overloads and could explain the additional time it took in the context of our big project. We have external dependencies though so maybe they were the ones defining additional overloads, but Cmd-Clicking the float4.init didn't show any overload other than the official one (the same that I've now extracted in makef4)

But even once extracted to only compile that single from our big project directly using swiftc from the Terminal, the time taken by the type-checker seems curiously long.

@belkadan
Copy link
Contributor

I am a little curious why your rearrangement helped in any significant way, since most of the time spent in the first expression is probably not actually about the expression itself, but about loading information about SIMD4 from the standard library. cc @xedin

@xedin
Copy link
Member

xedin commented Aug 16, 2019

I don't believe that this is related to expression type-checker because all of the expressions would exhibit the same performance since there is no cross expression caching.

@AliSoftware
Copy link
Contributor Author

@xedin do you need me to provide additional debug output then, like try with some other frontend flag that would show deeper drill-down of timings and better highlight where the bottleneck would be?

@xedin
Copy link
Member

xedin commented Aug 21, 2019

@slavapestov Since you have been working in that area, any ideas how to narrow this down?

@slavapestov
Copy link
Member

I'll take a closer look soon, but trying out -trace-stats-events together with -stats-output-dir might be interesting.

@swift-ci swift-ci transferred this issue from apple/swift-issues Apr 25, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug A deviation from expected or documented behavior. Also: expected but undesirable behavior. compiler The Swift compiler in itself
Projects
None yet
Development

No branches or pull requests

4 participants