solver: improve slow cache detection and add logging

Signed-off-by: Tonis Tiigi <[email protected]>
GOMYWAY-NETWORKS-LLC · Dec 2, 2020 · 6a321dc · 6a321dc
1 parent 7884713
commit 6a321dc
Show file tree

Hide file tree

Showing 2 changed files with 10 additions and 10 deletions.
diff --git a/solver/edge.go b/solver/edge.go
@@ -359,6 +359,7 @@ func (e *edge) unpark(incoming []pipe.Sender, updates, allPipes []pipe.Receiver,
 	if e.execReq == nil {
 		if added := e.createInputRequests(desiredState, f, false); !added && !e.hasActiveOutgoing && !cacheMapReq {
 			logrus.Errorf("buildkit scheluding error: leaving incoming open. forcing solve. Please report this with BUILDKIT_SCHEDULER_DEBUG=1")
+			debugSchedulerPreUnpark(e, incoming, updates, allPipes)
 			e.createInputRequests(desiredState, f, true)
 		}
 	}
@@ -594,6 +595,7 @@ func (e *edge) recalcCurrentState() {
 	stHigh := edgeStatusCacheSlow // maximum possible state
 	if e.cacheMap != nil {
 		for _, dep := range e.deps {
+			isSlowKeysIncomplete := e.slowCacheFunc(dep) != nil && (dep.state == edgeStatusCacheSlow || (dep.state == edgeStatusComplete && !dep.slowCacheComplete))
 			isSlowIncomplete := (e.slowCacheFunc(dep) != nil || e.preprocessFunc(dep) != nil) && (dep.state == edgeStatusCacheSlow || (dep.state == edgeStatusComplete && !dep.slowCacheComplete))
 
 			if dep.state > stLow && len(dep.keyMap) == 0 && !isSlowIncomplete {
@@ -618,7 +620,7 @@ func (e *edge) recalcCurrentState() {
 			if dep.state < edgeStatusCacheFast {
 				allDepsCompletedCacheFast = false
 			}
-			if isSlowIncomplete || dep.state < edgeStatusCacheSlow {
+			if isSlowKeysIncomplete || dep.state < edgeStatusCacheSlow {
 				allDepsCompletedCacheSlow = false
 			}
 			if dep.state < edgeStatusCacheSlow && len(dep.keyMap) == 0 {

diff --git a/solver/scheduler.go b/solver/scheduler.go
@@ -130,9 +130,13 @@ func (s *scheduler) dispatch(e *edge) {
 	pf := &pipeFactory{s: s, e: e}
 
 	// unpark the edge
-	debugSchedulerPreUnpark(e, inc, updates, out)
+	if debugScheduler {
+		debugSchedulerPreUnpark(e, inc, updates, out)
+	}
 	e.unpark(inc, updates, out, pf)
-	debugSchedulerPostUnpark(e, inc)
+	if debugScheduler {
+		debugSchedulerPostUnpark(e, inc)
+	}
 
 postUnpark:
 	// set up new requests that didn't complete/were added by this run
@@ -361,17 +365,14 @@ func (pf *pipeFactory) NewFuncRequest(f func(context.Context) (interface{}, erro
 }
 
 func debugSchedulerPreUnpark(e *edge, inc []pipe.Sender, updates, allPipes []pipe.Receiver) {
-	if !debugScheduler {
-		return
-	}
 	logrus.Debugf(">> unpark %s req=%d upt=%d out=%d state=%s %s", e.edge.Vertex.Name(), len(inc), len(updates), len(allPipes), e.state, e.edge.Vertex.Digest())
 
 	for i, dep := range e.deps {
 		des := edgeStatusInitial
 		if dep.req != nil {
 			des = dep.req.Request().(*edgeRequest).desiredState
 		}
-		logrus.Debugf(":: dep%d %s state=%s des=%s keys=%d hasslowcache=%v", i, e.edge.Vertex.Inputs()[i].Vertex.Name(), dep.state, des, len(dep.keys), e.slowCacheFunc(dep) != nil)
+		logrus.Debugf(":: dep%d %s state=%s des=%s keys=%d hasslowcache=%v preprocessfunc=%v", i, e.edge.Vertex.Inputs()[i].Vertex.Name(), dep.state, des, len(dep.keys), e.slowCacheFunc(dep) != nil, e.preprocessFunc(dep) != nil)
 	}
 
 	for i, in := range inc {
@@ -400,9 +401,6 @@ func debugSchedulerPreUnpark(e *edge, inc []pipe.Sender, updates, allPipes []pip
 }
 
 func debugSchedulerPostUnpark(e *edge, inc []pipe.Sender) {
-	if !debugScheduler {
-		return
-	}
 	for i, in := range inc {
 		logrus.Debugf("< incoming-%d: %p completed=%v", i, in, in.Status().Completed)
 	}