Skip to content

Commit

Permalink
Merge pull request #96973 from chenyw1990/optimizationRuntimeContaine…
Browse files Browse the repository at this point in the history 
…rLog

Optimization log: add containerName to log
  • Loading branch information
@k8s-ci-robot
k8s-ci-robot committed Mar 6, 2021
2 parents ecdbcd8 + 6845781 commit 56bcd56
Showing 1 changed file with 30 additions and 22 deletions.
52 changes: 30 additions & 22 deletions pkg/kubelet/kuberuntime/kuberuntime_container.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,7 @@ var (
func (m *kubeGenericRuntimeManager) recordContainerEvent(pod *v1.Pod, container *v1.Container, containerID, eventType, reason, message string, args ...interface{}) {
ref, err := kubecontainer.GenerateContainerRef(pod, container)
if err != nil {
klog.Errorf("Can't make a ref to pod %q, container %v: %v", format.Pod(pod), container.Name, err)
klog.ErrorS(err, "Can't make a container ref", "pod", klog.KObj(pod), "podUID", pod.UID, "containerName", container.Name)
return
}
eventMessage := message
Expand Down Expand Up @@ -213,8 +213,8 @@ func (m *kubeGenericRuntimeManager) startContainer(podSandboxID string, podSandb
// to create it in the first place. it happens when journald logging driver is used with docker.
if _, err := m.osInterface.Stat(containerLog); !os.IsNotExist(err) {
if err := m.osInterface.Symlink(containerLog, legacySymlink); err != nil {
klog.Errorf("Failed to create legacy symbolic link %q to container %q log %q: %v",
legacySymlink, containerID, containerLog, err)
klog.ErrorS(err, "Failed to create legacy symbolic link", "path", legacySymlink,
"containerID", containerID, "containerLogPath", containerLog)
}
}

Expand All @@ -228,8 +228,8 @@ func (m *kubeGenericRuntimeManager) startContainer(podSandboxID string, podSandb
if handlerErr != nil {
m.recordContainerEvent(pod, container, kubeContainerID.ID, v1.EventTypeWarning, events.FailedPostStartHook, msg)
if err := m.killContainer(pod, kubeContainerID, container.Name, "FailedPostStartHook", nil); err != nil {
klog.Errorf("Failed to kill container %q(id=%q) in pod %q: %v, %v",
container.Name, kubeContainerID.String(), format.Pod(pod), ErrPostStartHook, err)
klog.ErrorS(fmt.Errorf("%s: %v", ErrPostStartHook, handlerErr), "Failed to kill container", "pod", klog.KObj(pod),
"podUID", pod.UID, "containerName", container.Name, "containerID", kubeContainerID.String())
}
return msg, fmt.Errorf("%s: %v", ErrPostStartHook, handlerErr)
}
Expand Down Expand Up @@ -388,7 +388,7 @@ func (m *kubeGenericRuntimeManager) getKubeletContainers(allContainers bool) ([]

containers, err := m.runtimeService.ListContainers(filter)
if err != nil {
klog.Errorf("getKubeletContainers failed: %v", err)
klog.ErrorS(err, "ListContainers failed")
return nil, err
}

Expand Down Expand Up @@ -443,7 +443,7 @@ func (m *kubeGenericRuntimeManager) getPodContainerStatuses(uid kubetypes.UID, n
LabelSelector: map[string]string{types.KubernetesPodUIDLabel: string(uid)},
})
if err != nil {
klog.Errorf("ListContainers error: %v", err)
klog.ErrorS(err, "ListContainers error")
return nil, err
}

Expand All @@ -453,7 +453,7 @@ func (m *kubeGenericRuntimeManager) getPodContainerStatuses(uid kubetypes.UID, n
status, err := m.runtimeService.ContainerStatus(c.Id)
if err != nil {
// Merely log this here; GetPodStatus will actually report the error out.
klog.V(4).Infof("ContainerStatus for %s error: %v", c.Id, err)
klog.V(4).InfoS("ContainerStatus return error", "containerID", c.Id, "err", err)
return nil, err
}
cStatus := toKubeContainerStatus(status, m.runtimeName)
Expand Down Expand Up @@ -523,24 +523,27 @@ func toKubeContainerStatus(status *runtimeapi.ContainerStatus, runtimeName strin

// executePreStopHook runs the pre-stop lifecycle hooks if applicable and returns the duration it takes.
func (m *kubeGenericRuntimeManager) executePreStopHook(pod *v1.Pod, containerID kubecontainer.ContainerID, containerSpec *v1.Container, gracePeriod int64) int64 {
klog.V(3).Infof("Running preStop hook for container %q", containerID.String())
klog.V(3).InfoS("Running preStop hook", "pod", klog.KObj(pod), "podUID", pod.UID, "containerName", containerSpec.Name, "containerID", containerID.String())

start := metav1.Now()
done := make(chan struct{})
go func() {
defer close(done)
defer utilruntime.HandleCrash()
if msg, err := m.runner.Run(containerID, pod, containerSpec, containerSpec.Lifecycle.PreStop); err != nil {
klog.Errorf("preStop hook for container %q failed: %v", containerSpec.Name, err)
klog.ErrorS(err, "PreStop hook failed", "pod", klog.KObj(pod), "podUID", pod.UID,
"containerName", containerSpec.Name, "containerID", containerID.String())
m.recordContainerEvent(pod, containerSpec, containerID.ID, v1.EventTypeWarning, events.FailedPreStopHook, msg)
}
}()

select {
case <-time.After(time.Duration(gracePeriod) * time.Second):
klog.V(2).Infof("preStop hook for container %q did not complete in %d seconds", containerID, gracePeriod)
klog.V(2).InfoS("PreStop hook not completed in grace period", "pod", klog.KObj(pod), "podUID", pod.UID,
"containerName", containerSpec.Name, "containerID", containerID.String(), "gracePeriod", gracePeriod)
case <-done:
klog.V(3).Infof("preStop hook for container %q completed", containerID)
klog.V(3).InfoS("PreStop hook completed", "pod", klog.KObj(pod), "podUID", pod.UID,
"containerName", containerSpec.Name, "containerID", containerID.String())
}

return int64(metav1.Now().Sub(start.Time).Seconds())
Expand Down Expand Up @@ -597,7 +600,7 @@ func (m *kubeGenericRuntimeManager) killContainer(pod *v1.Pod, containerID kubec
var containerSpec *v1.Container
if pod != nil {
if containerSpec = kubecontainer.GetContainerSpec(pod, containerName); containerSpec == nil {
return fmt.Errorf("failed to get containerSpec %q(id=%q) in pod %q when killing container for reason %q",
return fmt.Errorf("failed to get containerSpec %q (id=%q) in pod %q when killing container for reason %q",
containerName, containerID.String(), format.Pod(pod), message)
}
} else {
Expand Down Expand Up @@ -638,16 +641,20 @@ func (m *kubeGenericRuntimeManager) killContainer(pod *v1.Pod, containerID kubec
}
if gracePeriodOverride != nil {
gracePeriod = *gracePeriodOverride
klog.V(3).Infof("Killing container %q, but using a %d second grace period override", containerID, gracePeriod)
klog.V(3).InfoS("Killing container with a grace period override", "pod", klog.KObj(pod), "podUID", pod.UID,
"containerName", containerName, "containerID", containerID.String(), "gracePeriod", gracePeriod)
}

klog.V(2).Infof("Killing container %q with a %d second grace period", containerID.String(), gracePeriod)
klog.V(2).InfoS("Killing container with a grace period override", "pod", klog.KObj(pod), "podUID", pod.UID,
"containerName", containerName, "containerID", containerID.String(), "gracePeriod", gracePeriod)

err := m.runtimeService.StopContainer(containerID.ID, gracePeriod)
if err != nil {
klog.Errorf("Container %q termination failed with gracePeriod %d: %v", containerID.String(), gracePeriod, err)
klog.ErrorS(err, "Container termination failed with gracePeriod", "pod", klog.KObj(pod), "podUID", pod.UID,
"containerName", containerName, "containerID", containerID.String(), "gracePeriod", gracePeriod)
} else {
klog.V(3).Infof("Container %q exited normally", containerID.String())
klog.V(3).InfoS("Container exited normally", "pod", klog.KObj(pod), "podUID", pod.UID,
"containerName", containerName, "containerID", containerID.String())
}

return err
Expand All @@ -667,7 +674,8 @@ func (m *kubeGenericRuntimeManager) killContainersWithSyncResult(pod *v1.Pod, ru
killContainerResult := kubecontainer.NewSyncResult(kubecontainer.KillContainer, container.Name)
if err := m.killContainer(pod, container.ID, container.Name, "", gracePeriodOverride); err != nil {
killContainerResult.Fail(kubecontainer.ErrKillContainer, err.Error())
klog.Errorf("killContainer %q(id=%q) for pod %q failed: %v", container.Name, container.ID, format.Pod(pod), err)
klog.ErrorS(err, "Kill container failed", "pod", klog.KObj(pod), "podUID", pod.UID,
"containerName", container.Name, "containerID", container.ID)
}
containerResults <- killContainerResult
}(container)
Expand Down Expand Up @@ -709,7 +717,7 @@ func (m *kubeGenericRuntimeManager) pruneInitContainersBeforeStart(pod *v1.Pod,
continue
}
// prune all other init containers that match this container name
klog.V(4).Infof("Removing init container %q instance %q %d", status.Name, status.ID.ID, count)
klog.V(4).InfoS("Removing init container", "containerName", status.Name, "containerID", status.ID.ID, "count", count)
if err := m.removeContainer(status.ID.ID); err != nil {
utilruntime.HandleError(fmt.Errorf("failed to remove pod init container %q: %v; Skipping pod %q", status.Name, err, format.Pod(pod)))
continue
Expand All @@ -734,7 +742,7 @@ func (m *kubeGenericRuntimeManager) purgeInitContainers(pod *v1.Pod, podStatus *
}
count++
// Purge all init containers that match this container name
klog.V(4).Infof("Removing init container %q instance %q %d", status.Name, status.ID.ID, count)
klog.V(4).InfoS("Removing init container", "containerName", status.Name, "containerID", status.ID.ID, "count", count)
if err := m.removeContainer(status.ID.ID); err != nil {
utilruntime.HandleError(fmt.Errorf("failed to remove pod init container %q: %v; Skipping pod %q", status.Name, err, format.Pod(pod)))
continue
Expand Down Expand Up @@ -804,7 +812,7 @@ func findNextInitContainerToRun(pod *v1.Pod, podStatus *kubecontainer.PodStatus)
func (m *kubeGenericRuntimeManager) GetContainerLogs(ctx context.Context, pod *v1.Pod, containerID kubecontainer.ContainerID, logOptions *v1.PodLogOptions, stdout, stderr io.Writer) (err error) {
status, err := m.runtimeService.ContainerStatus(containerID.ID)
if err != nil {
klog.V(4).Infof("failed to get container status for %v: %v", containerID.String(), err)
klog.V(4).InfoS("Failed to get container status", "containerID", containerID.String(), "err", err)
return fmt.Errorf("unable to retrieve container logs for %v", containerID.String())
}
return m.ReadLogs(ctx, status.GetLogPath(), containerID.ID, logOptions, stdout, stderr)
Expand Down Expand Up @@ -860,7 +868,7 @@ func (m *kubeGenericRuntimeManager) RunInContainer(id kubecontainer.ContainerID,
// Notice that we assume that the container should only be removed in non-running state, and
// it will not write container logs anymore in that state.
func (m *kubeGenericRuntimeManager) removeContainer(containerID string) error {
klog.V(4).Infof("Removing container %q", containerID)
klog.V(4).InfoS("Removing container", "containerID", containerID)
// Call internal container post-stop lifecycle hook.
if err := m.internalLifecycle.PostStopContainer(containerID); err != nil {
return err
Expand Down

0 comments on commit 56bcd56

Please sign in to comment.