Drastically Improve Speed and Memory Performance (#253)

cpisciotta · cpisciotta · commit e8873d1db8cc · 2024-02-25T14:19:53.000-05:00
Drastically improve xcbeautify's performance (time and memory). Testing with a large xcodebuild log, this change dropped xcbeautify's execution time by ~90% and memory footprint by ~99%. - Reduce unnecessary type instantiations, namely NSRegularExpression. - Skip parsing empty lines. - Introduce time-tracking logic and large xcodebuild log test to (1) find and fix the existing issue and (2) prevent future performance regressions. See testing results [here](#253).
diff --git a/Package.swift b/Package.swift
@@ -41,6 +41,7 @@ let package = Package(
             dependencies: ["XcbeautifyLib"],
             resources: [
                 .copy("ParsingTests/clean_build_xcode_15_1.txt"),
+                .copy("ParsingTests/large_xcodebuild_log.txt"),
             ]
         ),
     ]
diff --git a/Sources/XcbeautifyLib/Parser.swift b/Sources/XcbeautifyLib/Parser.swift
@@ -118,6 +118,11 @@ public class Parser {
     }
 
     public func parse(line: String) -> String? {
+        if line.isEmpty {
+            outputType = .undefined
+            return nil
+        }
+
         // Find first parser that can parse specified string
         guard let idx = captureGroupTypes.firstIndex(where: { $0.regex.match(string: line) }) else {
             // Some uncommon cases, which have additional logic and don't follow default flow
diff --git a/Sources/XcbeautifyLib/Regex.swift b/Sources/XcbeautifyLib/Regex.swift
@@ -1,9 +1,13 @@
 import Foundation
 
-class Regex {
+final class Regex {
     let pattern: String
 
-    private lazy var regex: NSRegularExpression? = try? NSRegularExpression(pattern: "^" + pattern, options: [.caseInsensitive])
+    private lazy var regex: NSRegularExpression? = {
+        let regex = try? NSRegularExpression(pattern: "^" + pattern, options: [.caseInsensitive])
+        assert(regex != nil)
+        return regex
+    }()
 
     init(pattern: String) {
         self.pattern = pattern
@@ -13,4 +17,17 @@ class Regex {
         let fullRange = NSRange(string.startIndex..., in: string)
         return regex?.rangeOfFirstMatch(in: string, range: fullRange).location != NSNotFound
     }
+
+    func captureGroups(for line: String) -> [String] {
+        let matches = regex?.matches(in: line, range: NSRange(location: 0, length: line.utf16.count))
+        guard let match = matches?.first else { return [] }
+
+        let lastRangeIndex = match.numberOfRanges - 1
+        guard lastRangeIndex >= 1 else { return [] }
+
+        return (1...lastRangeIndex).compactMap { index in
+            let capturedGroupIndex = match.range(at: index)
+            return line.substring(with: capturedGroupIndex)
+        }
+    }
 }
diff --git a/Sources/XcbeautifyLib/String+CapturedGroups.swift b/Sources/XcbeautifyLib/String+CapturedGroups.swift
@@ -1,119 +1,95 @@
 import Foundation
 
 extension String {
-    private func captureGroup(with pattern: String) -> [String] {
-        do {
-            let regex = try NSRegularExpression(pattern: pattern, options: [.caseInsensitive])
+    private static let captureGroups: [any CaptureGroup.Type] = [
+        AnalyzeCaptureGroup.self,
+        BuildTargetCaptureGroup.self,
+        AggregateTargetCaptureGroup.self,
+        AnalyzeTargetCaptureGroup.self,
+        CheckDependenciesCaptureGroup.self,
+        ShellCommandCaptureGroup.self,
+        CleanRemoveCaptureGroup.self,
+        CleanTargetCaptureGroup.self,
+        CodesignCaptureGroup.self,
+        CodesignFrameworkCaptureGroup.self,
+        CompileCaptureGroup.self,
+        CompileCommandCaptureGroup.self,
+        CompileXibCaptureGroup.self,
+        CompileStoryboardCaptureGroup.self,
+        CopyHeaderCaptureGroup.self,
+        CopyPlistCaptureGroup.self,
+        CopyStringsCaptureGroup.self,
+        CpresourceCaptureGroup.self,
+        ExecutedWithoutSkippedCaptureGroup.self,
+        ExecutedWithSkippedCaptureGroup.self,
+        FailingTestCaptureGroup.self,
+        UIFailingTestCaptureGroup.self,
+        RestartingTestCaptureGroup.self,
+        GenerateCoverageDataCaptureGroup.self,
+        GeneratedCoverageReportCaptureGroup.self,
+        GenerateDSYMCaptureGroup.self,
+        LibtoolCaptureGroup.self,
+        LinkingCaptureGroup.self,
+        TestCasePassedCaptureGroup.self,
+        TestCaseStartedCaptureGroup.self,
+        TestCasePendingCaptureGroup.self,
+        TestCaseMeasuredCaptureGroup.self,
+        ParallelTestCasePassedCaptureGroup.self,
+        ParallelTestCaseAppKitPassedCaptureGroup.self,
+        ParallelTestCaseFailedCaptureGroup.self,
+        ParallelTestingStartedCaptureGroup.self,
+        ParallelTestingPassedCaptureGroup.self,
+        ParallelTestingFailedCaptureGroup.self,
+        ParallelTestSuiteStartedCaptureGroup.self,
+        PhaseSuccessCaptureGroup.self,
+        PhaseScriptExecutionCaptureGroup.self,
+        ProcessPchCaptureGroup.self,
+        ProcessPchCommandCaptureGroup.self,
+        PreprocessCaptureGroup.self,
+        PbxcpCaptureGroup.self,
+        ProcessInfoPlistCaptureGroup.self,
+        TestsRunCompletionCaptureGroup.self,
+        TestSuiteStartedCaptureGroup.self,
+        TestSuiteStartCaptureGroup.self,
+        TestSuiteAllTestsPassedCaptureGroup.self,
+        TestSuiteAllTestsFailedCaptureGroup.self,
+        TIFFutilCaptureGroup.self,
+        TouchCaptureGroup.self,
+        WriteFileCaptureGroup.self,
+        WriteAuxiliaryFilesCaptureGroup.self,
+        CompileWarningCaptureGroup.self,
+        LDWarningCaptureGroup.self,
+        GenericWarningCaptureGroup.self,
+        WillNotBeCodeSignedCaptureGroup.self,
+        DuplicateLocalizedStringKeyCaptureGroup.self,
+        ClangErrorCaptureGroup.self,
+        CheckDependenciesErrorsCaptureGroup.self,
+        ProvisioningProfileRequiredCaptureGroup.self,
+        NoCertificateCaptureGroup.self,
+        CompileErrorCaptureGroup.self,
+        CursorCaptureGroup.self,
+        FatalErrorCaptureGroup.self,
+        FileMissingErrorCaptureGroup.self,
+        LDErrorCaptureGroup.self,
+        LinkerDuplicateSymbolsLocationCaptureGroup.self,
+        LinkerDuplicateSymbolsCaptureGroup.self,
+        LinkerUndefinedSymbolLocationCaptureGroup.self,
+        LinkerUndefinedSymbolsCaptureGroup.self,
+        PodsErrorCaptureGroup.self,
+        SymbolReferencedFromCaptureGroup.self,
+        ModuleIncludesErrorCaptureGroup.self,
+        UndefinedSymbolLocationCaptureGroup.self,
+        PackageFetchingCaptureGroup.self,
+        PackageUpdatingCaptureGroup.self,
+        PackageCheckingOutCaptureGroup.self,
+        PackageGraphResolvingStartCaptureGroup.self,
+        PackageGraphResolvingEndedCaptureGroup.self,
+        PackageGraphResolvedItemCaptureGroup.self,
+        XcodebuildErrorCaptureGroup.self,
+    ]
 
-            let matches = regex.matches(in: self, range: NSRange(location: 0, length: utf16.count))
-            guard let match = matches.first else { return [] }
-
-            let lastRangeIndex = match.numberOfRanges - 1
-            guard lastRangeIndex >= 1 else { return [] }
-
-            return (1...lastRangeIndex).compactMap { index in
-                let capturedGroupIndex = match.range(at: index)
-                return substring(with: capturedGroupIndex)
-            }
-        } catch {
-            assertionFailure(error.localizedDescription)
-            return []
-        }
-    }
-}
-
-extension String {
     func captureGroup(with pattern: String) -> CaptureGroup? {
-        let results: [String] = captureGroup(with: pattern)
-
-        let captureGroups: [any CaptureGroup.Type] = [
-            AnalyzeCaptureGroup.self,
-            BuildTargetCaptureGroup.self,
-            AggregateTargetCaptureGroup.self,
-            AnalyzeTargetCaptureGroup.self,
-            CheckDependenciesCaptureGroup.self,
-            ShellCommandCaptureGroup.self,
-            CleanRemoveCaptureGroup.self,
-            CleanTargetCaptureGroup.self,
-            CodesignCaptureGroup.self,
-            CodesignFrameworkCaptureGroup.self,
-            CompileCaptureGroup.self,
-            CompileCommandCaptureGroup.self,
-            CompileXibCaptureGroup.self,
-            CompileStoryboardCaptureGroup.self,
-            CopyHeaderCaptureGroup.self,
-            CopyPlistCaptureGroup.self,
-            CopyStringsCaptureGroup.self,
-            CpresourceCaptureGroup.self,
-            ExecutedWithoutSkippedCaptureGroup.self,
-            ExecutedWithSkippedCaptureGroup.self,
-            FailingTestCaptureGroup.self,
-            UIFailingTestCaptureGroup.self,
-            RestartingTestCaptureGroup.self,
-            GenerateCoverageDataCaptureGroup.self,
-            GeneratedCoverageReportCaptureGroup.self,
-            GenerateDSYMCaptureGroup.self,
-            LibtoolCaptureGroup.self,
-            LinkingCaptureGroup.self,
-            TestCasePassedCaptureGroup.self,
-            TestCaseStartedCaptureGroup.self,
-            TestCasePendingCaptureGroup.self,
-            TestCaseMeasuredCaptureGroup.self,
-            ParallelTestCasePassedCaptureGroup.self,
-            ParallelTestCaseAppKitPassedCaptureGroup.self,
-            ParallelTestCaseFailedCaptureGroup.self,
-            ParallelTestingStartedCaptureGroup.self,
-            ParallelTestingPassedCaptureGroup.self,
-            ParallelTestingFailedCaptureGroup.self,
-            ParallelTestSuiteStartedCaptureGroup.self,
-            PhaseSuccessCaptureGroup.self,
-            PhaseScriptExecutionCaptureGroup.self,
-            ProcessPchCaptureGroup.self,
-            ProcessPchCommandCaptureGroup.self,
-            PreprocessCaptureGroup.self,
-            PbxcpCaptureGroup.self,
-            ProcessInfoPlistCaptureGroup.self,
-            TestsRunCompletionCaptureGroup.self,
-            TestSuiteStartedCaptureGroup.self,
-            TestSuiteStartCaptureGroup.self,
-            TestSuiteAllTestsPassedCaptureGroup.self,
-            TestSuiteAllTestsFailedCaptureGroup.self,
-            TIFFutilCaptureGroup.self,
-            TouchCaptureGroup.self,
-            WriteFileCaptureGroup.self,
-            WriteAuxiliaryFilesCaptureGroup.self,
-            CompileWarningCaptureGroup.self,
-            LDWarningCaptureGroup.self,
-            GenericWarningCaptureGroup.self,
-            WillNotBeCodeSignedCaptureGroup.self,
-            DuplicateLocalizedStringKeyCaptureGroup.self,
-            ClangErrorCaptureGroup.self,
-            CheckDependenciesErrorsCaptureGroup.self,
-            ProvisioningProfileRequiredCaptureGroup.self,
-            NoCertificateCaptureGroup.self,
-            CompileErrorCaptureGroup.self,
-            CursorCaptureGroup.self,
-            FatalErrorCaptureGroup.self,
-            FileMissingErrorCaptureGroup.self,
-            LDErrorCaptureGroup.self,
-            LinkerDuplicateSymbolsLocationCaptureGroup.self,
-            LinkerDuplicateSymbolsCaptureGroup.self,
-            LinkerUndefinedSymbolLocationCaptureGroup.self,
-            LinkerUndefinedSymbolsCaptureGroup.self,
-            PodsErrorCaptureGroup.self,
-            SymbolReferencedFromCaptureGroup.self,
-            ModuleIncludesErrorCaptureGroup.self,
-            UndefinedSymbolLocationCaptureGroup.self,
-            PackageFetchingCaptureGroup.self,
-            PackageUpdatingCaptureGroup.self,
-            PackageCheckingOutCaptureGroup.self,
-            PackageGraphResolvingStartCaptureGroup.self,
-            PackageGraphResolvingEndedCaptureGroup.self,
-            PackageGraphResolvedItemCaptureGroup.self,
-            XcodebuildErrorCaptureGroup.self,
-        ]
-
-        let captureGroupType: CaptureGroup.Type? = captureGroups.first { captureGroup in
+        let captureGroupType: CaptureGroup.Type? = Self.captureGroups.first { captureGroup in
             captureGroup.pattern == pattern
         }
 
@@ -122,7 +98,9 @@ extension String {
             return nil
         }
 
-        let captureGroup = captureGroupType.init(groups: results)
+        let groups: [String] = captureGroupType.regex.captureGroups(for: self)
+
+        let captureGroup = captureGroupType.init(groups: groups)
         assert(captureGroup != nil)
         return captureGroup
     }
diff --git a/Sources/xcbeautify/Xcbeautify.swift b/Sources/xcbeautify/Xcbeautify.swift
@@ -36,6 +36,15 @@ struct Xcbeautify: ParsableCommand {
     var junitReportFilename = "junit.xml"
 
     func run() throws {
+        #if DEBUG && os(macOS)
+        let start = CFAbsoluteTimeGetCurrent()
+
+        defer {
+            let diff = CFAbsoluteTimeGetCurrent() - start
+            print("Took \(diff) seconds")
+        }
+        #endif
+
         let output = OutputHandler(quiet: quiet, quieter: quieter, isCI: isCi) { print($0) }
         let junitReporter = JunitReporter()
 
@@ -57,6 +66,7 @@ struct Xcbeautify: ParsableCommand {
         )
 
         while let line = readLine() {
+            guard !line.isEmpty else { continue }
             guard let formatted = parser.parse(line: line) else { continue }
             output.write(parser.outputType, formatted)
         }
diff --git a/Tests/XcbeautifyLibTests/ParsingTests/ParsingTests.swift b/Tests/XcbeautifyLibTests/ParsingTests/ParsingTests.swift
@@ -38,4 +38,41 @@ final class ParsingTests: XCTestCase {
         // There's a regression whenever `uncapturedOutput` is greater than the current magic number.
         XCTAssertEqual(uncapturedOutput, 2218)
     }
+
+    func testLargeXcodebuildLog() throws {
+        let url = Bundle.module.url(forResource: "large_xcodebuild_log", withExtension: "txt")!
+
+        var buildLog: [String] = try String(contentsOf: url)
+            .components(separatedBy: .newlines)
+
+        let parser = Parser(
+            colored: false,
+            renderer: .terminal,
+            preserveUnbeautifiedLines: false,
+            additionalLines: {
+                guard !buildLog.isEmpty else {
+                    XCTFail("The build log should never be empty when fetching additional lines.")
+                    return nil
+                }
+                return buildLog.removeFirst()
+            }
+        )
+
+        var uncapturedOutput = 0
+
+        while !buildLog.isEmpty {
+            let line = buildLog.removeFirst()
+            if !line.isEmpty, parser.parse(line: line) == nil {
+                uncapturedOutput += 1
+            }
+        }
+
+        // The following is a magic number.
+        // It represents the number of lines that aren't captured by the Parser.
+        // Slowly, this value should decrease until it reaches 0.
+        // It uses `XCTAssertEqual` instead of `XCTAssertLessThanOrEqual` as a reminder.
+        // Update this magic number whenever `uncapturedOutput` is less than the current magic number.
+        // There's a regression whenever `uncapturedOutput` is greater than the current magic number.
+        XCTAssertEqual(uncapturedOutput, 77104)
+    }
 }
diff --git a/Tests/XcbeautifyLibTests/ParsingTests/large_xcodebuild_log.txt b/Tests/XcbeautifyLibTests/ParsingTests/large_xcodebuild_log.txt

Original file line number	Diff line number	Diff line change
`@@ -41,6 +41,7 @@ let package = Package(`
`41`	`41`	`dependencies: ["XcbeautifyLib"],`
`42`	`42`	`resources: [`
`43`	`43`	`.copy("ParsingTests/clean_build_xcode_15_1.txt"),`
	`44`	`+ .copy("ParsingTests/large_xcodebuild_log.txt"),`
`44`	`45`	`]`
`45`	`46`	`),`
`46`	`47`	`]`