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-6983] Unexpected drop in performance of (identity-)closure the second time it is used #49531

Open
jepers opened this issue Feb 12, 2018 · 5 comments
Open

[SR-6983] Unexpected drop in performance of (identity-)closure the second time it is used #49531

jepers opened this issue Feb 12, 2018 · 5 comments
Labels
compiler The Swift compiler in itself improvement performance

Comments

@jepers
Copy link

jepers commented Feb 12, 2018

Previous ID SR-6983
Radar rdar://problem/40661588
Original Reporter @jepers
Type Improvement
Additional Detail from JIRA
Votes 1
Component/s Compiler
Labels Improvement, Performance
Assignee None
Priority Medium

md5: 19f6d1e506b16df7b9ecc2264c9326db

relates to:

  • SR-7023 Missed optimization opportunity, but not missed if wrapping code in a nested func

Issue Description:

Reporting this issue as suggested by @dabrahams in this forum thread.

The following program measures the time it takes to process a hundred million random input values using an identity closure and an identity func. In the first measurement, both are equally fast (as expected). But in the second measurement (identical in code and context) the closure is slower for some reason.

import AppKit

func measureExecutionTime(label: String, subject: (Int) -> Int) {
    let operationsPerTrial = 100_000_000
    var randomIntValues = [Int](repeating: 0, count: operationsPerTrial)
    var minTime = Double.infinity
    print("\(label):")
    for _ in 0 ..< 5 {
        randomIntValues.withUnsafeMutableBytes { (ptr) -> Void in
            let r = SecRandomCopyBytes(nil, ptr.count, ptr.baseAddress!)
            precondition(r == errSecSuccess)
        }
        var checksum = Int(0)
        let t0 = CACurrentMediaTime()
        for randomInput in randomIntValues {
            let r = subject(randomInput)
            checksum ^= r
        }
        let t1 = CACurrentMediaTime()
        let time = t1 - t0
        print("  time:", time, "seconds (checksum: \(checksum))")
        minTime = min(minTime, time)
    }
    print("  minimum time:", minTime, "seconds\n")
}

let identityClosure: (Int) -> Int = { return $0 }
func identityFunc(input: Int) -> Int { return input }

// Note that both have the same execution time here:
measureExecutionTime(label: "1st use of closure", subject: identityClosure)
measureExecutionTime(label: "1st use of func", subject: identityFunc)

// Note that identityClosure is slower this time:
measureExecutionTime(label: "2nd use of closure", subject: identityClosure)
measureExecutionTime(label: "2nd use of func", subject: identityFunc)

// Why?

Compiling and running it on my MBP:

> swiftc --version
Apple Swift version 4.1 (swiftlang-902.0.38 clang-902.0.30)
Target: x86_64-apple-darwin17.4.0
> swiftc -O -static-stdlib test.swift
> ./test
1st use of closure:
  time: 0.0631774560024496 seconds (checksum: -5969152766063222341)
  time: 0.0609615579887759 seconds (checksum: 1436576802479868292)
  time: 0.0627239710011054 seconds (checksum: 7897566598316776330)
  time: 0.0592733160010539 seconds (checksum: -1676386092480912224)
  time: 0.0597947819915134 seconds (checksum: 7356946459760327795)
  minimum time: 0.0592733160010539 seconds

1st use of func:
  time: 0.0596228250069544 seconds (checksum: 6666500747078896187)
  time: 0.059224077995168 seconds (checksum: 4253268501060393296)
  time: 0.0597734379989561 seconds (checksum: 3079996028968815475)
  time: 0.059408948989585 seconds (checksum: -39057913403395343)
  time: 0.0593238050059881 seconds (checksum: -1275339559973029455)
  minimum time: 0.059224077995168 seconds

2nd use of closure:
  time: 0.180851501005236 seconds (checksum: -297275842764426349)
  time: 0.191041134006809 seconds (checksum: -2297966356982257278)
  time: 0.181297669012565 seconds (checksum: 4242728420682360232)
  time: 0.19395082097617 seconds (checksum: 4169899910790849794)
  time: 0.183614853012841 seconds (checksum: -7725848402084691842)
  minimum time: 0.180851501005236 seconds

2nd use of func:
  time: 0.0590045459975954 seconds (checksum: -1243511994543017911)
  time: 0.0606653710128739 seconds (checksum: 4379620549680557500)
  time: 0.0616895709827077 seconds (checksum: -3147320019667911741)
  time: 0.0594128520169761 seconds (checksum: 3804868237876071121)
  time: 0.0593436420022044 seconds (checksum: 138671714869980974)
  minimum time: 0.0590045459975954 seconds

(Note that “2nd use of closure” is 0.18 seconds while all the other measurements are 0.06 seconds.)
@belkadan
Copy link
Contributor

cc aschwaighofer@apple.com (JIRA User)

@jepers
Copy link
Author

jepers commented May 30, 2018

Issue remains – and has gotten worse – with the default toolchain of Xcode 9.4 (9F1027a).

The "2nd use of closure" is now 10 instead of 3 times slower than the others:

› swiftc --version
Apple Swift version 4.1.2 (swiftlang-902.0.54 clang-902.0.39.2)
Target: x86_64-apple-darwin17.5.0
› swiftc -O -static-stdlib test.swift
› ./test
1st use of closure:
  time: 0.0632649020117242 seconds (checksum: 581423683991283777)
  time: 0.0617133129999274 seconds (checksum: -7306424433621360502)
  time: 0.0625146849924931 seconds (checksum: 7081978004570742532)
  time: 0.0610871280077845 seconds (checksum: -4065774701487485870)
  time: 0.0624201809987426 seconds (checksum: -2784397570979284854)
  minimum time: 0.0610871280077845 seconds

1st use of func:
  time: 0.0610684939892963 seconds (checksum: 264423982952719367)
  time: 0.0615423239942174 seconds (checksum: 2237211590060124107)
  time: 0.061124823987484 seconds (checksum: -4267020249627113289)
  time: 0.0619161030044779 seconds (checksum: 1792111283221657060)
  time: 0.063269748003222 seconds (checksum: -1589300676560776483)
  minimum time: 0.0610684939892963 seconds

2nd use of closure:
  time: 0.699463352997554 seconds (checksum: -3918483693787300236)
  time: 0.667777561000548 seconds (checksum: 1137324794268155767)
  time: 0.664340454997728 seconds (checksum: -7811258734802726978)
  time: 0.661137435992714 seconds (checksum: 1048546319275511909)
  time: 0.666032235996681 seconds (checksum: 1052028149280526971)
  minimum time: 0.661137435992714 seconds

2nd use of func:
  time: 0.0614374390133889 seconds (checksum: 6639092839694586210)
  time: 0.0611787349916995 seconds (checksum: -8533491229019487789)
  time: 0.060995906998869 seconds (checksum: -4113116250669794077)
  time: 0.0605206390027888 seconds (checksum: -4439758878194388265)
  time: 0.0613778190017911 seconds (checksum: 1964471734991009996)
  minimum time: 0.0605206390027888 seconds

So “2nd use of closure” is now 0.66 seconds. It was 0.18 seconds when I reported the issue (see compiler version in the example run in the report). The other ones are still 0.06 seconds.

BUT: When using a recent dev snapshot (2018-05-29) the "2nd use of closure" is back to 0.18 seconds again.

@belkadan
Copy link
Contributor

@swift-ci create

@jepers
Copy link
Author

jepers commented May 31, 2018

Ah! The same workaround as is discussed in SR-7023 can of course be used here too, so replacing the for-in loop with a while loop as follows will make all test cases equally fast:

        let t0 = CACurrentMediaTime()
        var i = 0
        let count = randomIntValues.count
        while i < count {
            let r = subject(randomIntValues[i])
            checksum ^= r
            i = i &+ 1
        }
        let t1 = CACurrentMediaTime()

@jepers
Copy link
Author

jepers commented Jan 20, 2020

Issue remains in Xcode 11.3 (11C29), and the work-around (while instead of for-in) in the comment above no longer works.

@swift-ci swift-ci transferred this issue from apple/swift-issues Apr 25, 2022
@ejensen ejensen mentioned this issue Oct 22, 2022
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
compiler The Swift compiler in itself improvement performance
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@belkadan @jepers