Merge pull request #99970 from krzysiekg/structured_logging_pkg_kubelet_kuberuntime

Migrate pkg/kubelet/kuberuntime to structured logging
This commit is contained in:
Kubernetes Prow Robot 2021-03-17 11:45:31 -07:00 committed by GitHub
commit 862aa6d3a0
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 50 additions and 49 deletions

View File

@ -81,7 +81,7 @@ func toRuntimeProtocol(protocol v1.Protocol) runtimeapi.Protocol {
return runtimeapi.Protocol_SCTP
}
klog.Warningf("Unknown protocol %q: defaulting to TCP", protocol)
klog.InfoS("Unknown protocol, defaulting to TCP", "protocol", protocol)
return runtimeapi.Protocol_TCP
}

View File

@ -112,13 +112,13 @@ func GetHugepageLimitsFromResources(resources v1.ResourceRequirements) []*runtim
pageSize, err := v1helper.HugePageSizeFromResourceName(resourceObj)
if err != nil {
klog.Warningf("Failed to get hugepage size from resource name: %v", err)
klog.InfoS("Failed to get hugepage size from resource", "object", resourceObj, "err", err)
continue
}
sizeString, err := v1helper.HugePageUnitSizeFromByteSize(pageSize.Value())
if err != nil {
klog.Warningf("pageSize is invalid: %v", err)
klog.InfoS("Size is invalid", "object", resourceObj, "err", err)
continue
}
requiredHugepageLimits[sizeString] = uint64(amountObj.Value())

View File

@ -97,7 +97,7 @@ func (m *kubeGenericRuntimeManager) generateWindowsContainerConfig(container *v1
if wc.Resources.CpuCount > 0 {
if wc.Resources.CpuMaximum > 0 {
wc.Resources.CpuMaximum = 0
klog.Warningf("Mutually exclusive options: CPUCount priority > CPUMaximum priority on Windows Server Containers. CPUMaximum should be ignored")
klog.InfoS("Mutually exclusive options: CPUCount priority > CPUMaximum priority on Windows Server Containers. CPUMaximum should be ignored")
}
}

View File

@ -44,11 +44,11 @@ func (m *kubeGenericRuntimeManager) PullImage(image kubecontainer.ImageSpec, pul
creds, withCredentials := keyring.Lookup(repoToPull)
if !withCredentials {
klog.V(3).Infof("Pulling image %q without credentials", img)
klog.V(3).InfoS("Pulling image without credentials", "image", img)
imageRef, err := m.imageService.PullImage(imgSpec, nil, podSandboxConfig)
if err != nil {
klog.Errorf("Pull image %q failed: %v", img, err)
klog.ErrorS(err, "Failed to pull image", "image", img)
return "", err
}
@ -83,7 +83,7 @@ func (m *kubeGenericRuntimeManager) PullImage(image kubecontainer.ImageSpec, pul
func (m *kubeGenericRuntimeManager) GetImageRef(image kubecontainer.ImageSpec) (string, error) {
status, err := m.imageService.ImageStatus(toRuntimeAPIImageSpec(image))
if err != nil {
klog.Errorf("ImageStatus for image %q failed: %v", image, err)
klog.ErrorS(err, "Failed to get image status", "image", image.Image)
return "", err
}
if status == nil {
@ -98,7 +98,7 @@ func (m *kubeGenericRuntimeManager) ListImages() ([]kubecontainer.Image, error)
allImages, err := m.imageService.ListImages(nil)
if err != nil {
klog.Errorf("ListImages failed: %v", err)
klog.ErrorS(err, "Failed to list images")
return nil, err
}
@ -119,7 +119,7 @@ func (m *kubeGenericRuntimeManager) ListImages() ([]kubecontainer.Image, error)
func (m *kubeGenericRuntimeManager) RemoveImage(image kubecontainer.ImageSpec) error {
err := m.imageService.RemoveImage(&runtimeapi.ImageSpec{Image: image.Image})
if err != nil {
klog.Errorf("Remove image %q failed: %v", image.Image, err)
klog.ErrorS(err, "Failed to remove image", "image", image.Image)
return err
}
@ -133,7 +133,7 @@ func (m *kubeGenericRuntimeManager) RemoveImage(image kubecontainer.ImageSpec) e
func (m *kubeGenericRuntimeManager) ImageStats() (*kubecontainer.ImageStats, error) {
allImages, err := m.imageService.ListImages(nil)
if err != nil {
klog.Errorf("ListImages failed: %v", err)
klog.ErrorS(err, "Failed to list images")
return nil, err
}
stats := &kubecontainer.ImageStats{}

View File

@ -37,16 +37,16 @@ import (
func (m *kubeGenericRuntimeManager) createPodSandbox(pod *v1.Pod, attempt uint32) (string, string, error) {
podSandboxConfig, err := m.generatePodSandboxConfig(pod, attempt)
if err != nil {
message := fmt.Sprintf("GeneratePodSandboxConfig for pod %q failed: %v", format.Pod(pod), err)
klog.Error(message)
message := fmt.Sprintf("Failed to generate sandbox config for pod %q: %v", format.Pod(pod), err)
klog.ErrorS(err, "Failed to generate sandbox config for pod", "pod", klog.KObj(pod))
return "", message, err
}
// Create pod logs directory
err = m.osInterface.MkdirAll(podSandboxConfig.LogDirectory, 0755)
if err != nil {
message := fmt.Sprintf("Create pod log directory for pod %q failed: %v", format.Pod(pod), err)
klog.Errorf(message)
message := fmt.Sprintf("Failed to create log directory for pod %q: %v", format.Pod(pod), err)
klog.ErrorS(err, "Failed to create log directory for pod", "pod", klog.KObj(pod))
return "", message, err
}
@ -54,18 +54,18 @@ func (m *kubeGenericRuntimeManager) createPodSandbox(pod *v1.Pod, attempt uint32
if m.runtimeClassManager != nil {
runtimeHandler, err = m.runtimeClassManager.LookupRuntimeHandler(pod.Spec.RuntimeClassName)
if err != nil {
message := fmt.Sprintf("CreatePodSandbox for pod %q failed: %v", format.Pod(pod), err)
message := fmt.Sprintf("Failed to create sandbox for pod %q: %v", format.Pod(pod), err)
return "", message, err
}
if runtimeHandler != "" {
klog.V(2).Infof("Running pod %s with RuntimeHandler %q", format.Pod(pod), runtimeHandler)
klog.V(2).InfoS("Running pod with runtime handler", "pod", klog.KObj(pod), "runtimeHandler", runtimeHandler)
}
}
podSandBoxID, err := m.runtimeService.RunPodSandbox(podSandboxConfig, runtimeHandler)
if err != nil {
message := fmt.Sprintf("CreatePodSandbox for pod %q failed: %v", format.Pod(pod), err)
klog.Error(message)
message := fmt.Sprintf("Failed to create sandbox for pod %q: %v", format.Pod(pod), err)
klog.ErrorS(err, "Failed to create sandbox for pod", "pod", klog.KObj(pod))
return "", message, err
}
@ -220,7 +220,7 @@ func (m *kubeGenericRuntimeManager) getKubeletSandboxes(all bool) ([]*runtimeapi
resp, err := m.runtimeService.ListPodSandbox(filter)
if err != nil {
klog.Errorf("ListPodSandbox failed: %v", err)
klog.ErrorS(err, "Failed to list pod sandboxes")
return nil, err
}
@ -231,7 +231,7 @@ func (m *kubeGenericRuntimeManager) getKubeletSandboxes(all bool) ([]*runtimeapi
func (m *kubeGenericRuntimeManager) determinePodSandboxIPs(podNamespace, podName string, podSandbox *runtimeapi.PodSandboxStatus) []string {
podIPs := make([]string, 0)
if podSandbox.Network == nil {
klog.Warningf("Pod Sandbox status doesn't have network information, cannot report IPs")
klog.InfoS("Pod Sandbox status doesn't have network information, cannot report IPs", "pod", klog.KRef(podNamespace, podName))
return podIPs
}
@ -241,7 +241,7 @@ func (m *kubeGenericRuntimeManager) determinePodSandboxIPs(podNamespace, podName
// pick primary IP
if len(podSandbox.Network.Ip) != 0 {
if net.ParseIP(podSandbox.Network.Ip) == nil {
klog.Warningf("Pod Sandbox reported an unparseable IP (Primary) %v", podSandbox.Network.Ip)
klog.InfoS("Pod Sandbox reported an unparseable primary IP", "pod", klog.KRef(podNamespace, podName), "IP", podSandbox.Network.Ip)
return nil
}
podIPs = append(podIPs, podSandbox.Network.Ip)
@ -250,7 +250,7 @@ func (m *kubeGenericRuntimeManager) determinePodSandboxIPs(podNamespace, podName
// pick additional ips, if cri reported them
for _, podIP := range podSandbox.Network.AdditionalIps {
if nil == net.ParseIP(podIP.Ip) {
klog.Warningf("Pod Sandbox reported an unparseable IP (additional) %v", podIP.Ip)
klog.InfoS("Pod Sandbox reported an unparseable additional IP", "pod", klog.KRef(podNamespace, podName), "IP", podIP.Ip)
return nil
}
podIPs = append(podIPs, podIP.Ip)
@ -272,7 +272,7 @@ func (m *kubeGenericRuntimeManager) getSandboxIDByPodUID(podUID kubetypes.UID, s
}
sandboxes, err := m.runtimeService.ListPodSandbox(filter)
if err != nil {
klog.Errorf("ListPodSandbox with pod UID %q failed: %v", podUID, err)
klog.ErrorS(err, "Failed to list sandboxes for pod", "podUID", podUID)
return nil, err
}

View File

@ -20,12 +20,11 @@ import (
"encoding/json"
"strconv"
"k8s.io/api/core/v1"
v1 "k8s.io/api/core/v1"
kubetypes "k8s.io/apimachinery/pkg/types"
"k8s.io/klog/v2"
kubecontainer "k8s.io/kubernetes/pkg/kubelet/container"
"k8s.io/kubernetes/pkg/kubelet/types"
"k8s.io/kubernetes/pkg/kubelet/util/format"
)
const (
@ -129,7 +128,7 @@ func newContainerAnnotations(container *v1.Container, pod *v1.Pod, restartCount
// Using json encoding so that the PreStop handler object is readable after writing as a label
rawPreStop, err := json.Marshal(container.Lifecycle.PreStop)
if err != nil {
klog.Errorf("Unable to marshal lifecycle PreStop handler for container %q of pod %q: %v", container.Name, format.Pod(pod), err)
klog.ErrorS(err, "Unable to marshal lifecycle PreStop handler for container", "containerName", container.Name, "pod", klog.KObj(pod))
} else {
annotations[containerPreStopHandlerLabel] = string(rawPreStop)
}
@ -138,7 +137,7 @@ func newContainerAnnotations(container *v1.Container, pod *v1.Pod, restartCount
if len(container.Ports) > 0 {
rawContainerPorts, err := json.Marshal(container.Ports)
if err != nil {
klog.Errorf("Unable to marshal container ports for container %q for pod %q: %v", container.Name, format.Pod(pod), err)
klog.ErrorS(err, "Unable to marshal container ports for container", "containerName", container.Name, "pod", klog.KObj(pod))
} else {
annotations[containerPortsLabel] = string(rawContainerPorts)
}
@ -192,28 +191,28 @@ func getContainerInfoFromAnnotations(annotations map[string]string) *annotatedCo
}
if containerInfo.Hash, err = getUint64ValueFromLabel(annotations, containerHashLabel); err != nil {
klog.Errorf("Unable to get %q from annotations %q: %v", containerHashLabel, annotations, err)
klog.ErrorS(err, "Unable to get label value from annotations", "label", containerHashLabel, "annotations", annotations)
}
if containerInfo.RestartCount, err = getIntValueFromLabel(annotations, containerRestartCountLabel); err != nil {
klog.Errorf("Unable to get %q from annotations %q: %v", containerRestartCountLabel, annotations, err)
klog.ErrorS(err, "Unable to get label value from annotations", "label", containerRestartCountLabel, "annotations", annotations)
}
if containerInfo.PodDeletionGracePeriod, err = getInt64PointerFromLabel(annotations, podDeletionGracePeriodLabel); err != nil {
klog.Errorf("Unable to get %q from annotations %q: %v", podDeletionGracePeriodLabel, annotations, err)
klog.ErrorS(err, "Unable to get label value from annotations", "label", podDeletionGracePeriodLabel, "annotations", annotations)
}
if containerInfo.PodTerminationGracePeriod, err = getInt64PointerFromLabel(annotations, podTerminationGracePeriodLabel); err != nil {
klog.Errorf("Unable to get %q from annotations %q: %v", podTerminationGracePeriodLabel, annotations, err)
klog.ErrorS(err, "Unable to get label value from annotations", "label", podTerminationGracePeriodLabel, "annotations", annotations)
}
preStopHandler := &v1.Handler{}
if found, err := getJSONObjectFromLabel(annotations, containerPreStopHandlerLabel, preStopHandler); err != nil {
klog.Errorf("Unable to get %q from annotations %q: %v", containerPreStopHandlerLabel, annotations, err)
klog.ErrorS(err, "Unable to get label value from annotations", "label", containerPreStopHandlerLabel, "annotations", annotations)
} else if found {
containerInfo.PreStopHandler = preStopHandler
}
containerPorts := []v1.ContainerPort{}
if found, err := getJSONObjectFromLabel(annotations, containerPortsLabel, &containerPorts); err != nil {
klog.Errorf("Unable to get %q from annotations %q: %v", containerPortsLabel, annotations, err)
klog.ErrorS(err, "Unable to get label value from annotations", "label", containerPortsLabel, "annotations", annotations)
} else if found {
containerInfo.ContainerPorts = containerPorts
}
@ -226,7 +225,7 @@ func getStringValueFromLabel(labels map[string]string, label string) string {
return value
}
// Do not report error, because there should be many old containers without label now.
klog.V(3).Infof("Container doesn't have label %s, it may be an old or invalid container", label)
klog.V(3).InfoS("Container doesn't have requested label, it may be an old or invalid container", "label", label)
// Return empty string "" for these containers, the caller will get value by other ways.
return ""
}
@ -241,7 +240,7 @@ func getIntValueFromLabel(labels map[string]string, label string) (int, error) {
return intValue, nil
}
// Do not report error, because there should be many old containers without label now.
klog.V(3).Infof("Container doesn't have label %s, it may be an old or invalid container", label)
klog.V(3).InfoS("Container doesn't have requested label, it may be an old or invalid container", "label", label)
// Just set the value to 0
return 0, nil
}
@ -256,7 +255,7 @@ func getUint64ValueFromLabel(labels map[string]string, label string) (uint64, er
return intValue, nil
}
// Do not report error, because there should be many old containers without label now.
klog.V(3).Infof("Container doesn't have label %s, it may be an old or invalid container", label)
klog.V(3).InfoS("Container doesn't have requested label, it may be an old or invalid container", "label", label)
// Just set the value to 0
return 0, nil
}

View File

@ -32,7 +32,7 @@ import (
"github.com/fsnotify/fsnotify"
"k8s.io/klog/v2"
"k8s.io/api/core/v1"
v1 "k8s.io/api/core/v1"
internalapi "k8s.io/cri-api/pkg/apis"
runtimeapi "k8s.io/cri-api/pkg/apis/runtime/v1alpha2"
"k8s.io/kubernetes/pkg/kubelet/types"
@ -316,7 +316,7 @@ func ReadLogs(ctx context.Context, path, containerID string, opts *LogOptions, r
msg := &logMessage{}
for {
if stop || (limitedMode && limitedNum == 0) {
klog.V(2).Infof("Finish parsing log file %q", path)
klog.V(2).InfoS("Finished parsing log file", "path", path)
return nil
}
l, err := r.ReadBytes(eol[0])
@ -363,7 +363,7 @@ func ReadLogs(ctx context.Context, path, containerID string, opts *LogOptions, r
}
f.Close()
if err := watcher.Remove(f.Name()); err != nil && !os.IsNotExist(err) {
klog.Errorf("failed to remove file watch %q: %v", f.Name(), err)
klog.ErrorS(err, "Failed to remove file watch", "path", f.Name())
}
f = newF
if err := watcher.Add(f.Name()); err != nil {
@ -379,7 +379,7 @@ func ReadLogs(ctx context.Context, path, containerID string, opts *LogOptions, r
if len(l) == 0 {
continue
}
klog.Warningf("Incomplete line in log file %q: %q", path, l)
klog.InfoS("Incomplete line in log file", "path", path, "line", l)
}
if parse == nil {
// Initialize the log parsing function.
@ -391,16 +391,16 @@ func ReadLogs(ctx context.Context, path, containerID string, opts *LogOptions, r
// Parse the log line.
msg.reset()
if err := parse(l, msg); err != nil {
klog.Errorf("Failed with err %v when parsing log for log file %q: %q", err, path, l)
klog.ErrorS(err, "Failed when parsing line in log file", "path", path, "line", l)
continue
}
// Write the log line into the stream.
if err := writer.write(msg); err != nil {
if err == errMaximumWrite {
klog.V(2).Infof("Finish parsing log file %q, hit bytes limit %d(bytes)", path, opts.bytes)
klog.V(2).InfoS("Finished parsing log file, hit bytes limit", "path", path, "limit", opts.bytes)
return nil
}
klog.Errorf("Failed with err %v when writing log for log file %q: %+v", err, path, msg)
klog.ErrorS(err, "Failed when writing line to log file", "path", path, "line", msg)
return err
}
if limitedMode {
@ -417,7 +417,7 @@ func isContainerRunning(id string, r internalapi.RuntimeService) (bool, error) {
}
// Only keep following container log when it is running.
if s.State != runtimeapi.ContainerState_CONTAINER_RUNNING {
klog.V(5).Infof("Container %q is not running (state=%q)", id, s.State)
klog.V(5).InfoS("Container is not running", "containerId", id, "state", s.State)
// Do not return error because it's normal that the container stops
// during waiting.
return false, nil
@ -451,10 +451,10 @@ func waitLogs(ctx context.Context, id string, w *fsnotify.Watcher, runtimeServic
case fsnotify.Chmod:
return true, true, nil
default:
klog.Errorf("Unexpected fsnotify event: %v, retrying...", e)
klog.ErrorS(nil, "Received unexpected fsnotify event, retrying", "event", e)
}
case err := <-w.Errors:
klog.Errorf("Fsnotify watch error: %v, %d error retries remaining", err, errRetry)
klog.ErrorS(err, "Received fsnotify watch error, retrying unless no more retries left", "retries", errRetry)
if errRetry == 0 {
return false, false, err
}

View File

@ -43,13 +43,15 @@ func verifyRunAsNonRoot(pod *v1.Pod, container *v1.Container, uid *int64, userna
return nil
}
if effectiveSc.RunAsUser != nil {
klog.Warningf("Windows container does not support SecurityContext.RunAsUser, please use SecurityContext.WindowsOptions (pod: %q, container: %s)", format.Pod(pod), container.Name)
klog.InfoS("Windows container does not support SecurityContext.RunAsUser, please use SecurityContext.WindowsOptions",
"pod", klog.KObj(pod), "containerName", container.Name)
}
if effectiveSc.SELinuxOptions != nil {
klog.Warningf("Windows container does not support SecurityContext.SELinuxOptions, please use SecurityContext.WindowsOptions (pod: %q, container: %s)", format.Pod(pod), container.Name)
klog.InfoS("Windows container does not support SecurityContext.SELinuxOptions, please use SecurityContext.WindowsOptions",
"pod", klog.KObj(pod), "containerName", container.Name)
}
if effectiveSc.RunAsGroup != nil {
klog.Warningf("Windows container does not support SecurityContext.RunAsGroup (pod: %q, container: %s)", format.Pod(pod), container.Name)
klog.InfoS("Windows container does not support SecurityContext.RunAsGroup", "pod", klog.KObj(pod), "containerName", container.Name)
}
if effectiveSc.WindowsOptions != nil {
if effectiveSc.WindowsOptions.RunAsUserName != nil {