Merge pull request #2069 from haircommander/master

Added traces to CRI API pertaining to containers and sandboxes

oci/container.go

@@ -14,6 +14,7 @@ import (
 	specs "github.com/opencontainers/runtime-spec/specs-go"
 	"k8s.io/apimachinery/pkg/fields"
 	pb "k8s.io/kubernetes/pkg/kubelet/apis/cri/runtime/v1alpha2"
+	"k8s.io/kubernetes/pkg/kubelet/types"
 )
 
 const (
@@ -318,3 +319,8 @@ func (c *Container) SetStartFailed(err error) {
 	c.state.Finished, c.state.Started = c.state.Created, c.state.Created
 	c.state.Error = err.Error()
 }
+
+// Description returns a description for the container
+func (c *Container) Description() string {
+	return fmt.Sprintf("%s/%s/%s", c.Labels()[types.KubernetesPodNamespaceLabel], c.Labels()[types.KubernetesPodNameLabel], c.Labels()[types.KubernetesContainerNameLabel])
+}

server/container_create.go

@@ -481,6 +481,7 @@ func (s *Server) CreateContainer(ctx context.Context, req *pb.CreateContainerReq
 		recordError(operation, err)
 	}()
 	logrus.Debugf("CreateContainerRequest %+v", req)
+	logrus.Infof("Attempting to create container: %s", translateLabelsToDescription(req.GetConfig().GetLabels()))
 
 	s.updateLock.RLock()
 	defer s.updateLock.RUnlock()
@@ -571,6 +572,7 @@ func (s *Server) CreateContainer(ctx context.Context, req *pb.CreateContainerReq
 
 	container.SetCreated()
 
+	logrus.Infof("Created container: %s", container.Description())
 	resp := &pb.CreateContainerResponse{
 		ContainerId: containerID,
 	}

server/container_execsync.go

@@ -47,6 +47,7 @@ func (s *Server) ExecSync(ctx context.Context, req *pb.ExecSyncRequest) (resp *p
 		ExitCode: execResp.ExitCode,
 	}
 
+	logrus.Infof("Exec'd %s in %s", cmd, c.Description())
 	logrus.Debugf("ExecSyncResponse: %+v", resp)
 	return resp, nil
 }

server/container_remove.go

@@ -18,11 +18,18 @@ func (s *Server) RemoveContainer(ctx context.Context, req *pb.RemoveContainerReq
 	}()
 	logrus.Debugf("RemoveContainerRequest: %+v", req)
 
+	// save container description to print
+	c, err := s.GetContainerFromShortID(req.ContainerId)
+	if err != nil {
+		return nil, err
+	}
+
 	_, err = s.ContainerServer.Remove(ctx, req.ContainerId, true)
 	if err != nil {
 		return nil, err
 	}
 
+	logrus.Infof("Removed container %s", c.Description())
 	resp = &pb.RemoveContainerResponse{}
 	logrus.Debugf("RemoveContainerResponse: %+v", resp)
 	return resp, nil

server/container_start.go

@@ -43,6 +43,7 @@ func (s *Server) StartContainer(ctx context.Context, req *pb.StartContainerReque
 		return nil, fmt.Errorf("failed to start container %s: %v", c.ID(), err)
 	}
 
+	logrus.Infof("Started container: %s", c.Description())
 	resp = &pb.StartContainerResponse{}
 	logrus.Debugf("StartContainerResponse %+v", resp)
 	return resp, nil

server/container_stop.go

@@ -17,11 +17,19 @@ func (s *Server) StopContainer(ctx context.Context, req *pb.StopContainerRequest
 	}()
 	logrus.Debugf("StopContainerRequest %+v", req)
 
+	// save container description to print
+	c, err := s.GetContainerFromShortID(req.ContainerId)
+	if err != nil {
+		return nil, err
+	}
+	description := c.Description()
+
 	_, err = s.ContainerServer.ContainerStop(ctx, req.ContainerId, req.Timeout)
 	if err != nil {
 		return nil, err
 	}
 
+	logrus.Infof("Stopped container %s", description)
 	resp = &pb.StopContainerResponse{}
 	logrus.Debugf("StopContainerResponse %s: %+v", req.ContainerId, resp)
 	return resp, nil

server/sandbox_remove.go

@@ -103,6 +103,7 @@ func (s *Server) RemovePodSandbox(ctx context.Context, req *pb.RemovePodSandboxR
 		return nil, fmt.Errorf("failed to delete pod sandbox %s from index: %v", sb.ID(), err)
 	}
 
+	logrus.Infof("Removed pod sandbox with infra container: %s", podInfraContainer.Description())
 	resp = &pb.RemovePodSandboxResponse{}
 	logrus.Debugf("RemovePodSandboxResponse %+v", resp)
 	return resp, nil

server/sandbox_run_linux.go

@@ -46,6 +46,8 @@ func (s *Server) runPodSandbox(ctx context.Context, req *pb.RunPodSandboxRequest
 	}
 
 	logrus.Debugf("RunPodSandboxRequest %+v", req)
+	// we need to fill in the container name, as it is not present in the request. Luckily, it is a constant.
+	logrus.Infof("Attempting to run pod sandbox with infra container: %s%s", translateLabelsToDescription(req.GetConfig().GetLabels()), leaky.PodInfraContainerName)
 	var processLabel, mountLabel, resolvPath string
 	// process req.Name
 	kubeName := req.GetConfig().GetMetadata().GetName()
@@ -675,6 +677,7 @@ func (s *Server) runPodSandbox(ctx context.Context, req *pb.RunPodSandboxRequest
 
 	sb.SetCreated()
 
+	logrus.Infof("Ran pod sandbox with infra container: %s", container.Description())
 	resp = &pb.RunPodSandboxResponse{PodSandboxId: id}
 	logrus.Debugf("RunPodSandboxResponse: %+v", resp)
 	return resp, nil

server/sandbox_stop_linux.go

@@ -139,6 +139,7 @@ func (s *Server) stopPodSandbox(ctx context.Context, req *pb.StopPodSandboxReque
 		logrus.Warnf("failed to stop sandbox container in pod sandbox %s: %v", sb.ID(), err)
 	}
 
+	logrus.Infof("Stopped pod sandbox: %s", podInfraContainer.Description())
 	sb.SetStopped()
 	resp = &pb.StopPodSandboxResponse{}
 	logrus.Debugf("StopPodSandboxResponse %s: %+v", sb.ID(), resp)

server/utils.go

@@ -16,6 +16,7 @@ import (
 	"github.com/pkg/errors"
 	"github.com/syndtr/gocapability/capability"
 	pb "k8s.io/kubernetes/pkg/kubelet/apis/cri/runtime/v1alpha2"
+	"k8s.io/kubernetes/pkg/kubelet/types"
 )
 
 const (
@@ -272,3 +273,8 @@ func getUlimitsFromConfig(config Config) ([]ulimit, error) {
 	}
 	return ulimits, nil
 }
+
+// Translate container labels to a description of the container
+func translateLabelsToDescription(labels map[string]string) string {
+	return fmt.Sprintf("%s/%s/%s", labels[types.KubernetesPodNamespaceLabel], labels[types.KubernetesPodNameLabel], labels[types.KubernetesContainerNameLabel])
+}