add DependencyResolverDelegate to track events from the dependency resolver

tomerd · tomerd · commit 16288324afa2 · 2021-04-20T17:41:57.000-07:00
motivation:
* significant part of pacakge resolution is spent in the dependency resolver which does not emit events we can use to tell the user what is happening
* a follow up PR would use these new events to emit inforamtion when package depedencies are resolved, e.g when running swift package update

chnages:
* define DependencyResolverDelegate
* replace logging in PubgrubDependencyResolver with calling the relevant delegate methods
* add TracingDependencyResolverDelegate which back-fills the existing logging behavior in PubgrubDependencyResolver
* adjust call-sites

open issues:
* is this the right API shape? the delegate methods are 1:1 mapping to PubgrubDependencyResolver logging which may or may not be the right API
* add tests once API is stable
diff --git a/Sources/PackageGraph/DependencyResolver.swift b/Sources/PackageGraph/DependencyResolver.swift
@@ -11,15 +11,16 @@
 import TSCBasic
 import PackageModel
 
+public protocol DependencyResolver {
+    typealias Binding = (container: PackageReference, binding: BoundVersion, products: ProductFilter)
+    typealias Delegate = DependencyResolverDelegate
+}
+
 public enum DependencyResolverError: Error, Equatable {
      /// A revision-based dependency contains a local package dependency.
     case revisionDependencyContainsLocalPackage(dependency: String, localPackage: String)
 }
 
-public class DependencyResolver {
-    public typealias Binding = (container: PackageReference, binding: BoundVersion, products: ProductFilter)
-}
-
 extension DependencyResolverError: CustomStringConvertible {
     public var description: String {
         switch self {
@@ -28,3 +29,71 @@ extension DependencyResolverError: CustomStringConvertible {
         }
     }
 }
+
+public protocol DependencyResolverDelegate {
+    func willResolve(term: Term)
+    func didResolve(term: Term, version: Version)
+
+    func derived(term: Term)
+    func conflict(conflict: Incompatibility)
+    func satisfied(term: Term, by: Assignment, incompatibility: Incompatibility)
+    func partiallySatisfied(term: Term, by: Assignment, incompatibility: Incompatibility, difference: Term)
+    func failedToResolve(incompatibility: Incompatibility)
+    func computed(bindings: [DependencyResolver.Binding])
+}
+
+public struct TracingDependencyResolverDelegate: DependencyResolverDelegate {
+    private let stream: OutputByteStream
+
+    public init (path: AbsolutePath) throws {
+        self.stream = try LocalFileOutputByteStream(path, closeOnDeinit: true, buffered: false)
+    }
+
+    public init (stream: OutputByteStream) {
+        self.stream = stream
+    }
+
+    public func willResolve(term: Term) {
+        self.log("resolving: \(term.node.package.location)")
+    }
+
+    public func didResolve(term: Term, version: Version) {
+        self.log("resolved: \(term.node.package.location) @ \(version)")
+    }
+
+    public func derived(term: Term) {
+        self.log("derived: \(term.node.package.location)")
+    }
+
+    public func conflict(conflict: Incompatibility) {
+        self.log("conflict: \(conflict)")
+    }
+
+    public func failedToResolve(incompatibility: Incompatibility) {
+        self.log("failed to resolve: \(incompatibility)")
+    }
+
+    public func satisfied(term: Term, by assignment: Assignment, incompatibility: Incompatibility) {
+        log("CR: \(term) is satisfied by \(assignment)")
+        log("CR: which is caused by \(assignment.cause?.description ?? "")")
+        log("CR: new incompatibility \(incompatibility)")
+    }
+
+    public func partiallySatisfied(term: Term, by assignment: Assignment, incompatibility: Incompatibility, difference: Term) {
+        log("CR: \(term) is partially satisfied by \(assignment)")
+        log("CR: which is caused by \(assignment.cause?.description ?? "")")
+        log("CR: new incompatibility \(incompatibility)")
+    }
+
+    public func computed(bindings: [DependencyResolver.Binding]) {
+        self.log("solved:")
+        for (container, binding, _) in bindings {
+            self.log("\(container) \(binding)")
+        }
+    }
+
+    private func log(_ message: String) {
+        self.stream <<< message <<< "\n"
+        self.stream.flush()
+    }
+}
diff --git a/Sources/PackageGraph/Pubgrub/PartialSolution.swift b/Sources/PackageGraph/Pubgrub/PartialSolution.swift
@@ -29,7 +29,7 @@ public struct PartialSolution {
 
     /// Union of all negative assignments for a package.
     ///
-    /// Only present if a package has no postive assignment.
+    /// Only present if a package has no positive assignment.
     public private(set) var _negative: [DependencyResolutionNode: Term] = [:]
 
     /// The current decision level.
diff --git a/Sources/PackageGraph/Pubgrub/PubgrubDependencyResolver.swift b/Sources/PackageGraph/Pubgrub/PubgrubDependencyResolver.swift
@@ -111,40 +111,22 @@ public struct PubgrubDependencyResolver {
     /// Should resolver prefetch the containers.
     private let isPrefetchingEnabled: Bool
 
-    // Log stream
-    private let traceStream: OutputByteStream?
+    /// Resolver delegate
+    private let delegate: DependencyResolverDelegate?
 
     public init(
         provider: PackageContainerProvider,
         pinsMap: PinsStore.PinsMap = [:],
         isPrefetchingEnabled: Bool = false,
         skipUpdate: Bool = false,
-        traceFile: AbsolutePath? = nil,
-        traceStream: OutputByteStream? = nil
+        delegate: DependencyResolverDelegate? = nil
     ) {
         self.packageContainerProvider = provider
         self.pinsMap = pinsMap
         self.isPrefetchingEnabled = isPrefetchingEnabled
         self.skipUpdate = skipUpdate
-        if let stream = traceStream {
-            self.traceStream = stream
-        } else {
-            self.traceStream = traceFile.flatMap { file in
-                // FIXME: Emit a warning if this fails.
-                try? LocalFileOutputByteStream(file, closeOnDeinit: true, buffered: false)
-            }
-        }
         self.provider = ContainerProvider(provider: self.packageContainerProvider, skipUpdate: self.skipUpdate, pinsMap: self.pinsMap)
-    }
-
-    public init(
-        provider: PackageContainerProvider,
-        pinsMap: PinsStore.PinsMap = [:],
-        isPrefetchingEnabled: Bool = false,
-        skipUpdate: Bool = false,
-        traceFile: AbsolutePath? = nil
-    ) {
-        self.init(provider: provider, pinsMap: pinsMap, isPrefetchingEnabled: isPrefetchingEnabled, skipUpdate: skipUpdate, traceFile: traceFile, traceStream: nil)
+        self.delegate = delegate
     }
 
     /// Execute the resolution algorithm to find a valid assignment of versions.
@@ -256,7 +238,7 @@ public struct PubgrubDependencyResolver {
             finalAssignments.append((identifier, override.version, override.products))
         }
 
-        self.log(finalAssignments)
+        self.delegate?.computed(bindings: finalAssignments)
 
         return (finalAssignments, state)
     }
@@ -517,7 +499,8 @@ public struct PubgrubDependencyResolver {
             return .conflict
         }
 
-        log("derived: \(unsatisfiedTerm.inverse)")
+        //log("derived: \(unsatisfiedTerm.inverse)")
+        self.delegate?.derived(term: unsatisfiedTerm.inverse)
         state.derive(unsatisfiedTerm.inverse, cause: incompatibility)
 
         return .almostSatisfied(node: unsatisfiedTerm.node)
@@ -527,7 +510,7 @@ public struct PubgrubDependencyResolver {
     // https://github.com/dart-lang/pub/tree/master/doc/solver.md#conflict-resolution
     // https://github.com/dart-lang/pub/blob/master/lib/src/solver/version_solver.dart#L201
     internal func resolve(state: State, conflict: Incompatibility) throws -> Incompatibility {
-        log("conflict: \(conflict)")
+        self.delegate?.conflict(conflict: conflict)
 
         var incompatibility = conflict
         var createdIncompatibility = false
@@ -594,12 +577,17 @@ public struct PubgrubDependencyResolver {
             )
             createdIncompatibility = true
 
-            log("CR: \(mostRecentTerm?.description ?? "") is\(difference != nil ? " partially" : "") satisfied by \(_mostRecentSatisfier)")
-            log("CR: which is caused by \(_mostRecentSatisfier.cause?.description ?? "")")
-            log("CR: new incompatibility \(incompatibility)")
+            if let term = mostRecentTerm {
+                if let diff = difference {
+                    self.delegate?.partiallySatisfied(term: term, by: _mostRecentSatisfier, incompatibility: incompatibility, difference: diff)
+                } else {
+                    self.delegate?.satisfied(term: term, by: _mostRecentSatisfier, incompatibility: incompatibility)
+                }
+            }
         }
 
-        log("failed: \(incompatibility)")
+        //log("failed: \(incompatibility)")
+        self.delegate?.failedToResolve(incompatibility: incompatibility)
         throw PubgrubError._unresolvable(incompatibility, state.incompatibilities)
     }
 
@@ -649,8 +637,10 @@ public struct PubgrubDependencyResolver {
                 let counts = try result.get()
                 // forced unwraps safe since we are testing for count and errors above
                 let pkgTerm = undecided.min { counts[$0]! < counts[$1]! }!
+                self.delegate?.willResolve(term: pkgTerm)
                 // at this point the container is cached 
                 let container = try self.provider.getCachedContainer(for: pkgTerm.node.package)
+
                 // Get the best available version for this package.
                 guard let version = try container.getBestAvailableVersion(for: pkgTerm) else {
                     state.addIncompatibility(try Incompatibility(pkgTerm, root: state.root, cause: .noAvailableVersion), at: .decisionMaking)
@@ -670,7 +660,7 @@ public struct PubgrubDependencyResolver {
                     // Add the incompatibility to our partial solution.
                     state.addIncompatibility(incompatibility, at: .decisionMaking)
 
-                    // Check if this incompatibility will statisfy the solution.
+                    // Check if this incompatibility will satisfy the solution.
                     haveConflict = haveConflict || incompatibility.terms.allSatisfy {
                         // We only need to check if the terms other than this package
                         // are satisfied because we _know_ that the terms matching
@@ -682,7 +672,8 @@ public struct PubgrubDependencyResolver {
 
                 // Decide this version if there was no conflict with its dependencies.
                 if !haveConflict {
-                    self.log("decision: \(pkgTerm.node.package)@\(version)")
+                    //self.log("decision: \(pkgTerm.node.package)@\(version)")
+                    self.delegate?.didResolve(term: pkgTerm, version: version)
                     state.decide(pkgTerm.node, at: version)
                 }
 
@@ -692,20 +683,6 @@ public struct PubgrubDependencyResolver {
             }
         }
     }
-
-    private func log(_ assignments: [(container: PackageReference, binding: BoundVersion, products: ProductFilter)]) {
-        log("solved:")
-        for (container, binding, _) in assignments {
-            log("\(container) \(binding)")
-        }
-    }
-
-    private func log(_ message: String) {
-        if let traceStream = traceStream {
-            traceStream <<< message <<< "\n"
-            traceStream.flush()
-        }
-    }
 }
 
 private struct DiagnosticReportBuilder {
diff --git a/Sources/Workspace/Workspace.swift b/Sources/Workspace/Workspace.swift
@@ -580,7 +580,7 @@ extension Workspace {
         }
         
         // Resolve the dependencies.
-        let resolver = self.createResolver(pinsMap: pinsMap)
+        let resolver = try self.createResolver(pinsMap: pinsMap)
         self.activeResolver = resolver
 
         let updateResults = resolveDependencies(
@@ -1924,7 +1924,7 @@ extension Workspace {
         constraints += try graphRoot.constraints() + extraConstraints
 
         // Perform dependency resolution.
-        let resolver = createResolver(pinsMap: pinsStore.pinsMap)
+        let resolver = try createResolver(pinsMap: pinsStore.pinsMap)
         self.activeResolver = resolver
 
         let result = resolveDependencies(
@@ -2285,14 +2285,15 @@ extension Workspace {
     }
 
     /// Creates resolver for the workspace.
-    fileprivate func createResolver(pinsMap: PinsStore.PinsMap) -> PubgrubDependencyResolver {
-        let traceFile = enableResolverTrace ? self.dataPath.appending(components: "resolver.trace") : nil
+    fileprivate func createResolver(pinsMap: PinsStore.PinsMap) throws -> PubgrubDependencyResolver {
+        let delegate = self.enableResolverTrace ? try TracingDependencyResolverDelegate(path: self.dataPath.appending(components: "resolver.trace")) : nil
 
         return PubgrubDependencyResolver(
             provider: containerProvider,
             pinsMap: pinsMap,
             isPrefetchingEnabled: isResolverPrefetchingEnabled,
-            skipUpdate: skipUpdate, traceFile: traceFile
+            skipUpdate: skipUpdate,
+            delegate: delegate
         )
     }
 
diff --git a/Tests/PackageGraphTests/PubgrubTests.swift b/Tests/PackageGraphTests/PubgrubTests.swift
@@ -2152,7 +2152,8 @@ class DependencyGraphBuilder {
             self.references = [:]
         }
         let provider = MockProvider(containers: self.containers.values.map { $0 })
-        return PubgrubDependencyResolver(provider :provider, pinsMap: pinsMap, traceStream: log ? stdoutStream : nil)
+        let delegate =  log ? TracingDependencyResolverDelegate(stream: stdoutStream) : nil
+        return PubgrubDependencyResolver(provider :provider, pinsMap: pinsMap, delegate: delegate)
     }
 }
 

Original file line number	Diff line number	Diff line change
`@@ -2152,7 +2152,8 @@ class DependencyGraphBuilder {`
`2152`	`2152`	`self.references = [:]`
`2153`	`2153`	`}`
`2154`	`2154`	`let provider = MockProvider(containers: self.containers.values.map { $0 })`
`2155`		`- return PubgrubDependencyResolver(provider :provider, pinsMap: pinsMap, traceStream: log ? stdoutStream : nil)`
	`2155`	`+ let delegate = log ? TracingDependencyResolverDelegate(stream: stdoutStream) : nil`
	`2156`	`+ return PubgrubDependencyResolver(provider :provider, pinsMap: pinsMap, delegate: delegate)`
`2156`	`2157`	`}`
`2157`	`2158`	`}`
`2158`	`2159`