A profiler that measures performance across threads for Swift

profiler.swift

/*

Copyright 2017 Ali Akhtarzada

Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at

    http://www.apache.org/licenses/LICENSE-2.0

Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.

*/

import Foundation

struct ProfilerConfiguration {

    // How many threads you want to measure in
    var threadCount: Int

    // The number of samples to run per thread
    var sampleCount: Int

    var autoPrint: Bool

    // This is the default configuration for a single measurement with a single Profiler
    static let single = ProfilerConfiguration(
        threadCount: 1,
        sampleCount: 1000,
        autoPrint: true
    )

    // This is the default configuration for performing multiple measurements with the same Profiler
    static let multiple = ProfilerConfiguration(
        threadCount: 4,
        sampleCount: 1000,
        autoPrint: false
    )
}

class Profiler {
    private static let kNanosPerUSec: Double = 1000
    private static let kNanosPerMSec: Double = kNanosPerUSec * 1000

    private static let kAbsMultiplier: Double = {
        let info = mach_timebase_info_t.allocate(capacity: 1)
        info.initialize(to: mach_timebase_info(numer: 0, denom: 0))
        defer {
            info.deinitialize()
            info.deallocate(capacity: 1)
        }
        mach_timebase_info(info)
        return Double(info.pointee.numer) / Double(info.pointee.denom)
    }()

    private static func absoluteTimeToMS(_ abs: Double) -> Double {
        return Double(abs) * self.kAbsMultiplier / self.kNanosPerMSec
    }

    private typealias Duration = (start: UInt64, end: UInt64)

    private static func averageDurations(_ durations: [Duration]) -> Double {
        let sum: UInt64 = durations.reduce(0) { (memo, data) -> UInt64 in
            return memo + (data.end - data.start)
        }
        let averageTime = Double(sum) / Double(durations.count)
        return self.absoluteTimeToMS(averageTime)
    }

    private let queue = DispatchQueue(label: "profiler.queue")
    private let configuration: ProfilerConfiguration
    private let tag: String?
    private var results: [String: Double] = [:]

    init(tag: String? = nil, configuration: ProfilerConfiguration = .multiple) {
        self.tag = tag
        self.configuration = configuration
    }

    @discardableResult
    static func profile(tag: String, configuration: ProfilerConfiguration = .single, block: @escaping () -> Void) -> Double {
        let profiler = Profiler(configuration: configuration)
        return profiler.profile(tag: tag, block: block)
    }

    private func process(block: @escaping () -> Void) -> [Duration] {
        var durations: [Duration] = []
        DispatchQueue.concurrentPerform(iterations: self.configuration.threadCount) { _ in
            var durationsPerThread = [Duration](
                repeating: (0, 0),
                count: self.configuration.sampleCount
            )
            for i in 0..<self.configuration.sampleCount {
                durationsPerThread[i].start = mach_absolute_time()
                block()
                durationsPerThread[i].end = mach_absolute_time()
            }
            self.queue.sync {
                durations.append(contentsOf: durationsPerThread)
            }
        }
        return durations
    }

    @discardableResult
    func profile(tag: String, block: @escaping () -> Void) -> Double {
        let durations = self.process(block: block)
        let averageDuration = Profiler.averageDurations(durations)
        self.queue.sync {
            self.results[tag] = averageDuration
            if self.configuration.autoPrint {
                print("\(tag) (threads: \(self.configuration.threadCount), samples: \(self.configuration.sampleCount)):\n  time: \(averageDuration)")
            }
        }
        return averageDuration
    }

    struct Stats: CustomStringConvertible {
        let profilerTag: String?
        let configuration: ProfilerConfiguration
        let orderedResults: [(tag: String, duration: Double)]

        var description: String {
            guard orderedResults.count > 0 else {
                return "You haven't profiled anything numbnuts"
            }

            let profilerTagString = self.profilerTag != nil ? "\"\(self.profilerTag!)\"" : ""
            let header = "\(profilerTagString) profiler - config: threads: \(self.configuration.threadCount), samples: \(self.configuration.sampleCount)"
            var lines: [String] = []
            var previousDuration: Double?
            for result in self.orderedResults {
                var percentString: String?
                if let p = previousDuration {
                    let percent = p == result.duration ? 0 : Int((p - result.duration) / p * 100)
                    percentString = " (\(percent) % faster)"
                }
                lines.append("  " + result.tag + ": \(result.duration) ms" + (percentString ?? ""))
                previousDuration = result.duration
            }
            return header + "\n" + lines.reversed().joined(separator: "\n")
        }
    }

    func stats() -> Stats {
        var array: [(String, Double)] = []
        self.queue.sync {
            array = Array(self.results)
        }
        let descendingResults = array.sorted() {
            return $0.1 > $1.1
        }.map { (tag: $0.0, duration: $0.1) }
        return Stats(
            profilerTag: self.tag,
            configuration: self.configuration,
            orderedResults: descendingResults
        )
    }
}

// ===============================================================
// =================== Example usage follows =====================
// ===============================================================

class AsyncGCD {
    let q = DispatchQueue(label: "async", attributes: .concurrent)
    var d: Int = 0

    func set(_ i: Int) {
        q.async(flags: .barrier) {
            self.d = i
        }
    }

    func get() -> Int {
        var x: Int = 0
        q.sync {
            x = self.d
        }
        return x
    }
}

class SyncGCD {
    let q = DispatchQueue(label: "sync")
    var d: Int = 0

    func set(_ i: Int) {
        q.sync {
            self.d = i
        }
    }

    func get() -> Int {
        var x: Int = 0
        q.sync {
            x = self.d
        }
        return x
    }
}

class ObjCSynchronized {
    var d: Int = 0

    func set(_ i: Int) {
        objc_sync_enter(self)
        defer { objc_sync_exit(self) }
        self.d = i
    }

    func get() -> Int {
        objc_sync_enter(self)
        defer { objc_sync_exit(self) }
        return self.d
    }
}

func test(configuration: ProfilerConfiguration) {
    let setProfiler = Profiler(tag: "set", configuration: configuration)
    let getProfiler = Profiler(tag: "get", configuration: configuration)
    let setAndGetProfiler = Profiler(tag: "set-get", configuration: configuration)
    let getAndSetProfiler = Profiler(tag: "get-set", configuration: configuration)

    let asyncGCD = AsyncGCD()
    let syncGCD = SyncGCD()
    let objcSynchronized = ObjCSynchronized()

    setProfiler.profile(tag: "async") {
        asyncGCD.set(3)
    }

    setProfiler.profile(tag: "sync") {
        syncGCD.set(4)
    }

    setProfiler.profile(tag: "objc") {
        objcSynchronized.set(5)
    }

    getProfiler.profile(tag: "async") {
        let _ = asyncGCD.get()
    }

    getProfiler.profile(tag: "sync") {
        let _ = syncGCD.get()
    }

    getProfiler.profile(tag: "objc") {
        let _ = objcSynchronized.get()
    }

    setAndGetProfiler.profile(tag: "async") {
        asyncGCD.set(3)
        let _ = asyncGCD.get()
    }

    setAndGetProfiler.profile(tag: "sync") {
        syncGCD.set(4)
        let _ = asyncGCD.get()
    }

    setAndGetProfiler.profile(tag: "objc") {
        objcSynchronized.set(5)
        let _ = objcSynchronized.get()
    }

    getAndSetProfiler.profile(tag: "async") {
        let _ = asyncGCD.get()
        asyncGCD.set(3)
    }

    getAndSetProfiler.profile(tag: "sync") {
        let _ = asyncGCD.get()
        syncGCD.set(4)
    }

    getAndSetProfiler.profile(tag: "objc") {
        let _ = objcSynchronized.get()
        objcSynchronized.set(5)
    }

    precondition(asyncGCD.get() == 3)
    precondition(syncGCD.get() == 4)
    precondition(objcSynchronized.get() == 5)

    print(setProfiler.stats())
    print(getProfiler.stats())
    print(setAndGetProfiler.stats())
    print(getAndSetProfiler.stats())
}

var c1 = ProfilerConfiguration.multiple
c1.threadCount = 2
var c2 = ProfilerConfiguration.multiple
c2.threadCount = 4

test(configuration: c1)
test(configuration: c2)

class SemaphoreGCD {
    let s = DispatchSemaphore(value: 1)
    var d: Int = 0

    func set(_ i: Int) {
        s.wait()
        self.d = i
        s.signal()
    }

    func get() -> Int {
        var x: Int = 0
        s.wait()
        x = self.d
        s.signal()
        return x
    }
}