From: Tom Clegg <tom@curii.com>
Date: Mon, 6 Sep 2021 19:48:50 +0000 (-0400)
Subject: 18102: Improve logging.
X-Git-Tag: 2.3.0~78^2
X-Git-Url: https://git.arvados.org/arvados.git/commitdiff_plain/6ba70e34ec9bc9941e8c04d6654106e6d1bbae82

18102: Improve logging.

Arvados-DCO-1.1-Signed-off-by: Tom Clegg <tom@curii.com>
---

diff --git a/lib/dispatchcloud/scheduler/run_queue.go b/lib/dispatchcloud/scheduler/run_queue.go
index 5bd4477ca5..e9fc5f9021 100644
--- a/lib/dispatchcloud/scheduler/run_queue.go
+++ b/lib/dispatchcloud/scheduler/run_queue.go
@@ -75,7 +75,7 @@ tryrun:
 				// starve this one by using keeping
 				// idle workers alive on different
 				// instance types.
-				logger.Debug("overquota")
+				logger.Trace("overquota")
 				overquota = sorted[i:]
 				break tryrun
 			} else if logger.Info("creating new instance"); sch.pool.Create(it) {
@@ -88,6 +88,7 @@ tryrun:
 				// avoid getting starved here if
 				// instances of a specific type always
 				// fail.
+				logger.Trace("pool declined to create new instance")
 				continue
 			}
 
diff --git a/lib/dispatchcloud/scheduler/sync.go b/lib/dispatchcloud/scheduler/sync.go
index 038b4c8c5f..4d601d6ae8 100644
--- a/lib/dispatchcloud/scheduler/sync.go
+++ b/lib/dispatchcloud/scheduler/sync.go
@@ -66,7 +66,7 @@ func (sch *Scheduler) sync() {
 				// a network outage and is still
 				// preparing to run a container that
 				// has already been unlocked/requeued.
-				go sch.kill(uuid, fmt.Sprintf("state=%s", ent.Container.State))
+				go sch.kill(uuid, fmt.Sprintf("pool says running, but queue says state=%s", ent.Container.State))
 			} else if ent.Container.Priority == 0 {
 				sch.logger.WithFields(logrus.Fields{
 					"ContainerUUID": uuid,
@@ -118,6 +118,10 @@ func (sch *Scheduler) kill(uuid string, reason string) {
 		return
 	}
 	defer sch.uuidUnlock(uuid)
+	sch.logger.WithFields(logrus.Fields{
+		"ContainerUUID": uuid,
+		"reason":        reason,
+	}).Debug("kill")
 	sch.pool.KillContainer(uuid, reason)
 	sch.pool.ForgetContainer(uuid)
 }