diff --git a/Sources/CodeGen/LLVM/LLVMProgram.swift b/Sources/CodeGen/LLVM/LLVMProgram.swift index dd80562fc..cc4c43634 100644 --- a/Sources/CodeGen/LLVM/LLVMProgram.swift +++ b/Sources/CodeGen/LLVM/LLVMProgram.swift @@ -29,7 +29,9 @@ public struct LLVMProgram { self.target = try target ?? SwiftyLLVM.TargetMachine(for: .host()) for m in ir.modules.keys { var context = CodeGenerationContext(forCompiling: m, of: ir) - let _convertProbe = profiler?.createTimeMeasurementProbe(MeasurementType.IRConversion) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.IRConversion) + defer { probe?.stop() } + let transpilation = SwiftyLLVM.Module(transpiling: m, in: &context) do { try transpilation.verify() @@ -43,7 +45,8 @@ public struct LLVMProgram { /// Applies the mandatory IR simplification passes on each module in `self`. public mutating func applyMandatoryPasses() { - let _optimizeProbe = profiler?.createTimeMeasurementProbe(MeasurementType.MandatoryPass) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.MandatoryPass) + defer { probe?.stop() } for k in llvmModules.keys { llvmModules[k]!.runDefaultModulePasses(optimization: .none, for: target) } @@ -53,7 +56,8 @@ public struct LLVMProgram { /// /// Optimization applied are similar to clang's `-O3`. public mutating func optimize() { - let _mandatoryProbe = profiler?.createTimeMeasurementProbe(MeasurementType.Optimizations) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.Optimizations) + defer { probe?.stop() } for k in llvmModules.keys { llvmModules[k]!.runDefaultModulePasses(optimization: .aggressive, for: target) } @@ -70,7 +74,8 @@ public struct LLVMProgram { var result: [URL] = [] for m in llvmModules.values { let f = directory.appendingPathComponent(m.name).appendingPathExtension("o") - let _writeProbe = profiler?.createTimeMeasurementProbe(MeasurementType.EmitPhase) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.EmitPhase) + defer { probe?.stop() } try m.write(type, for: target, to: f.fileSystemPath) result.append(f) } diff --git a/Sources/Driver/Driver.swift b/Sources/Driver/Driver.swift index c18e252db..f835df428 100644 --- a/Sources/Driver/Driver.swift +++ b/Sources/Driver/Driver.swift @@ -397,7 +397,8 @@ public struct Driver: ParsableCommand { program: TypedProgram, reportingDiagnosticsTo log: inout DiagnosticSet, profileWith profiler: ProfilingMeasurements? ) throws -> IR.Program { - let _irProbe = profiler?.createTimeMeasurementProbe(MeasurementType.IRLowering) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.IRLowering) + defer { probe?.stop() } var loweredModules: [ModuleDecl.ID: IR.Module] = [:] for d in program.ast.modules { loweredModules[d] = try lower(d, in: program, reportingDiagnosticsTo: &log) @@ -433,7 +434,8 @@ public struct Driver: ParsableCommand { let xcrun = try findExecutable(invokedAs: "xcrun").fileSystemPath // linking profiling probe - let _probe = profiler?.createTimeMeasurementProbe(MeasurementType.LinkPhase) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.LinkPhase) + defer { probe?.stop() } let sdk = try runCommandLine(xcrun, ["--sdk", "macosx", "--show-sdk-path"], diagnostics: &diagnostics) @@ -467,7 +469,8 @@ public struct Driver: ParsableCommand { arguments.append(contentsOf: libraries.map({ "-l\($0)" })) // linking profiling probe - let _probe = profiler?.createTimeMeasurementProbe(MeasurementType.LinkPhase) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.LinkPhase) + defer { probe?.stop() } // Note: We use "clang" rather than "ld" so that to deal with the entry point of the program. // See https://stackoverflow.com/questions/51677440 @@ -484,7 +487,8 @@ public struct Driver: ParsableCommand { profileWith profiler: ProfilingMeasurements? ) throws { // linking profiling probe - let _probe = profiler?.createTimeMeasurementProbe(MeasurementType.LinkPhase) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.LinkPhase) + defer { probe?.stop() } try runCommandLine( findExecutable(invokedAs: "lld-link").fileSystemPath, diff --git a/Sources/FrontEnd/Parse/Lexer.swift b/Sources/FrontEnd/Parse/Lexer.swift index c8baaf97b..67789ab99 100644 --- a/Sources/FrontEnd/Parse/Lexer.swift +++ b/Sources/FrontEnd/Parse/Lexer.swift @@ -27,7 +27,8 @@ public struct Lexer: IteratorProtocol, Sequence { /// Advances to the next token and returns it, or returns `nil` if no next token exists. public mutating func next() -> Token? { // Start measuring Lexer time - let _probe = profiler?.createTimeMeasurementProbe(MeasurementType.Lexer) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.Lexer) + defer { probe?.stop() } // Skip whitespaces and comments. while true { diff --git a/Sources/FrontEnd/Parse/Parser.swift b/Sources/FrontEnd/Parse/Parser.swift index bcce32fe7..5b8d7236d 100644 --- a/Sources/FrontEnd/Parse/Parser.swift +++ b/Sources/FrontEnd/Parse/Parser.swift @@ -41,7 +41,8 @@ public enum Parser { var members: [AnyDeclID] = [] // start time measurement if needed - let _probe = profiler?.createTimeMeasurementProbe(MeasurementType.Parser) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.Parser) + defer { probe?.stop() } while let head = state.peek() { // Ignore semicolons. diff --git a/Sources/FrontEnd/TypedProgram.swift b/Sources/FrontEnd/TypedProgram.swift index 9c7c90543..2233dac6f 100644 --- a/Sources/FrontEnd/TypedProgram.swift +++ b/Sources/FrontEnd/TypedProgram.swift @@ -82,7 +82,8 @@ public struct TypedProgram { tasks.append(t) } - let _probe = profiler?.createTimeMeasurementProbe(MeasurementType.TypeChecker) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.TypeChecker) + defer { probe?.stop() } let queue = OperationQueue() queue.addOperations(tasks, waitUntilFinished: true) for t in tasks { @@ -95,7 +96,8 @@ public struct TypedProgram { constructing: $0, tracingInferenceIf: typeCheckingIsParallel ? nil : shouldTraceInference, loggingRequirementSystemIf: typeCheckingIsParallel ? nil : shouldLogRequirements) - let _probe = profiler?.createTimeMeasurementProbe(MeasurementType.TypeChecker) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.TypeChecker) + defer { probe?.stop() } checker.checkAllDeclarations() log.formUnion(checker.diagnostics) @@ -126,7 +128,8 @@ public struct TypedProgram { tracingInferenceIf: shouldTraceInference, loggingRequirementSystemIf: shouldLogRequirements) - let _probe = profiler?.createTimeMeasurementProbe(MeasurementType.TypeChecker) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.TypeChecker) + defer { probe?.stop() } checker.checkModule(m) log.formUnion(checker.diagnostics) diff --git a/Sources/IR/Analysis/Module+Depolymorphize.swift b/Sources/IR/Analysis/Module+Depolymorphize.swift index 301f3bbb5..4f2982b8f 100644 --- a/Sources/IR/Analysis/Module+Depolymorphize.swift +++ b/Sources/IR/Analysis/Module+Depolymorphize.swift @@ -6,7 +6,8 @@ extension IR.Program { /// Generates the non-parametric reslient APIs of the modules in `self`. public mutating func depolymorphize(profileWith profiler: ProfilingMeasurements? = nil) { - let _probe = profiler?.createTimeMeasurementProbe(MeasurementType.Depolymorphize) + let probe = profiler?.createAndStartProfilingProbe(MeasurementType.Depolymorphize) + defer { probe?.stop() } for m in modules.keys { depolymorphize(m) } diff --git a/Sources/Utils/Profiling.swift b/Sources/Utils/Profiling.swift index 12207d1af..9eca7fc9d 100644 --- a/Sources/Utils/Profiling.swift +++ b/Sources/Utils/Profiling.swift @@ -16,6 +16,8 @@ public enum MeasurementType: Int, CaseIterable { } } +/// Time measurement probe. Will report time between init() and stop() +/// to the associate ProfilingMeasurements object public struct TimeMeasurementProbe: ~Copyable { var beginning: ContinuousClock.Instant @@ -28,14 +30,14 @@ public struct TimeMeasurementProbe: ~Copyable { self.measure_type = measure_type } - deinit { + public func stop() { let time: Duration = ContinuousClock.Instant.now - beginning pool.addProfiledDuration(self.measure_type, time) } } -/// A container for profiling measurement +/// A container for profiling measurements public class ProfilingMeasurements { public init() {} @@ -43,14 +45,18 @@ public class ProfilingMeasurements { var cumulatedDurations: [Duration] = [Duration]( repeating: Duration.seconds(0), count: MeasurementType.count) - public func createTimeMeasurementProbe(_ measure_type: MeasurementType) -> TimeMeasurementProbe { + /// Create a new TimeMeasurementProbe for a given measure type + public func createAndStartProfilingProbe(_ measure_type: MeasurementType) -> TimeMeasurementProbe + { return TimeMeasurementProbe(measure_type, self) } - public func addProfiledDuration(_ measure_type: MeasurementType, _ duration: Duration) { + /// Internal. Reserved for TimeMeasurementProbe + internal func addProfiledDuration(_ measure_type: MeasurementType, _ duration: Duration) { self.cumulatedDurations[measure_type.rawValue] += duration } + /// Print the current profiling report public func printProfilingReport() { let profilingReport = """ **Compile time profiling summary** @@ -71,7 +77,7 @@ public class ProfilingMeasurements { print(profilingReport) } - public func measurement(_ measure_type: MeasurementType) -> Duration { + public func durationFor(_ measure_type: MeasurementType) -> Duration { switch measure_type { case .Parser: return cumulatedDurations[MeasurementType.Parser.rawValue] @@ -82,13 +88,13 @@ public class ProfilingMeasurements { } public func formattedMeasurement(_ measure_type: MeasurementType) -> String { - let measure = measurement(measure_type) - let measurementDouble = + let measure = durationFor(measure_type) + let measureDouble = Double(measure.components.seconds) + Double(measure.components.attoseconds) / 1e18 let unitArrays = ["s", "ms", "us", "ns", "ps"] var factor = 1 for i in 0...unitArrays.count { - let scaledMeasurement = measurementDouble * Double(factor) + let scaledMeasurement = measureDouble * Double(factor) if scaledMeasurement > 1.0 { return "\(String(format: "%.03f", scaledMeasurement)) \(unitArrays[i])" }