kata-monitor: improve debug logging

Improve debug log formatting of the sandbox cache update process.
Move raw and tracing logs from the DEBUG to the TRACE log level.

Signed-off-by: Francesco Giudici <fgiudici@redhat.com>

src/runtime/pkg/kata-monitor/cri.go

@@ -39,7 +39,6 @@ func getAddressAndDialer(endpoint string) (string, func(ctx context.Context, add
 
 func getConnection(endPoint string) (*grpc.ClientConn, error) {
 	var conn *grpc.ClientConn
-	monitorLog.Debugf("connect using endpoint '%s' with '%s' timeout", endPoint, defaultTimeout)
 	addr, dialer, err := getAddressAndDialer(endPoint)
 	if err != nil {
 		return nil, err
@@ -51,7 +50,7 @@ func getConnection(endPoint string) (*grpc.ClientConn, error) {
 		errMsg := errors.Wrapf(err, "connect endpoint '%s', make sure you are running as root and the endpoint has been started", endPoint)
 		return nil, errMsg
 	}
-	monitorLog.Debugf("connected successfully using endpoint: %s", endPoint)
+	monitorLog.Tracef("connected successfully using endpoint: %s", endPoint)
 	return conn, nil
 }
 
@@ -132,28 +131,34 @@ func (km *KataMonitor) getSandboxes(sandboxMap map[string]bool) (map[string]bool
 	request := &pb.ListPodSandboxRequest{
 		Filter: filter,
 	}
-	monitorLog.Debugf("ListPodSandboxRequest: %v", request)
+	monitorLog.Tracef("ListPodSandboxRequest: %v", request)
 	r, err := runtimeClient.ListPodSandbox(context.Background(), request)
 	if err != nil {
 		return newMap, err
 	}
-	monitorLog.Debugf("ListPodSandboxResponse: %v", r)
+	monitorLog.Tracef("ListPodSandboxResponse: %v", r)
 
 	for _, pod := range r.Items {
 		// Use the cached data if available
 		if isKata, ok := sandboxMap[pod.Id]; ok {
 			newMap[pod.Id] = isKata
+			if isKata {
+				monitorLog.Debugf("KATA POD %s (cached)", pod.Id)
+			}
 			continue
 		}
 
 		// Check if a directory associated with the POD ID exist on the kata fs:
 		// if so we know that the POD is a kata one.
 		newMap[pod.Id] = checkSandboxFSExists(pod.Id)
+		if newMap[pod.Id] {
+			monitorLog.Debugf("KATA POD %s (new)", pod.Id)
+		}
 		monitorLog.WithFields(logrus.Fields{
 			"id":      pod.Id,
 			"is kata": newMap[pod.Id],
 			"pod":     pod,
-		}).Debug("")
+		}).Trace("")
 	}
 
 	return newMap, nil

src/runtime/pkg/kata-monitor/metrics.go

@@ -156,7 +156,7 @@ func (km *KataMonitor) aggregateSandboxMetrics(encoder expfmt.Encoder) error {
 	// used to receive response
 	results := make(chan []*dto.MetricFamily, len(sandboxes))
 
-	monitorLog.WithField("sandbox_count", len(sandboxes)).Debugf("sandboxes count")
+	monitorLog.WithField("sandboxes count", len(sandboxes)).Debugf("aggregate sandbox metrics")
 
 	// get metrics from sandbox's shim
 	for _, sandboxID := range sandboxes {

src/runtime/pkg/kata-monitor/monitor.go

@@ -126,13 +126,14 @@ func (km *KataMonitor) startPodCacheUpdater() {
 				"cache update timer fires in %d secs", podCacheRefreshDelaySeconds)
 
 		case <-cacheUpdateTimer.C:
+			monitorLog.Debugf("sync sandbox cache with the container engine")
 			sandboxes, err := km.getSandboxes(km.sandboxCache.getAllSandboxes())
 			if err != nil {
 				monitorLog.WithError(err).Error("failed to get sandboxes")
 				continue
 			}
 			monitorLog.WithField("count", len(sandboxes)).Info("synced sandbox cache with the container engine")
-			monitorLog.WithField("sandboxes", sandboxes).Debug("dump sandbox cache")
+			monitorLog.WithField("sandboxes", sandboxes).Trace("dump sandbox cache")
 			km.sandboxCache.set(sandboxes)
 		}
 	}