From f62edda5a207cc71dfba1c7003a2214e3cb82a15 Mon Sep 17 00:00:00 2001 From: Sebastiaan van Stijn Date: Thu, 7 Dec 2023 16:06:11 +0100 Subject: [PATCH 1/2] pkg/cri/server/base: use structured log for CRI plugin startup Log the config as a field instead of as part of the log message. Before this: INFO[2023-12-07T14:58:43.515360429Z] loading plugin id=io.containerd.tracing.processor.v1.otlp type=io.containerd.tracing.processor.v1 INFO[2023-12-07T14:58:43.515787512Z] loading plugin id=io.containerd.internal.v1.tracing type=io.containerd.internal.v1 INFO[2023-12-07T14:58:43.515974429Z] loading plugin id=io.containerd.internal.v1.cri type=io.containerd.internal.v1 INFO[2023-12-07T14:58:43.516037887Z] Start cri plugin with config {PluginConfig:{ContainerdConfig:{Snapshotter:overlayfs DefaultRuntimeName:runc Runtimes:map[runc:{Type:io.containerd.runc.v2 Path: PodAnnotations:[] ContainerAnnotations:[] Options:map[BinaryName: CriuImagePath: CriuWorkPath: IoGid:0 IoUid:0 NoNewKeyring:false Root: ShimCgroup:] PrivilegedWithoutHostDevices:false PrivilegedWithoutHostDevicesAllDevicesAllowed:false BaseRuntimeSpec: NetworkPluginConfDir: NetworkPluginMaxConfNum:0 Snapshotter: Sandboxer:podsandbox}] DisableSnapshotAnnotations:true DiscardUnpackedLayers:false IgnoreBlockIONotEnabledErrors:false IgnoreRdtNotEnabledErrors:false} CniConfig:{NetworkPluginBinDir:/opt/cni/bin NetworkPluginConfDir:/etc/cni/net.d NetworkPluginMaxConfNum:1 NetworkPluginSetupSerially:false NetworkPluginConfTemplate: IPPreference:} Registry:{ConfigPath: Mirrors:map[] Configs:map[] Auths:map[] Headers:map[]} ImageDecryption:{KeyModel:node} DisableTCPService:true StreamServerAddress:127.0.0.1 StreamServerPort:0 StreamIdleTimeout:4h0m0s EnableSelinux:false SelinuxCategoryRange:1024 SandboxImage:registry.k8s.io/pause:3.9 StatsCollectPeriod:10 EnableTLSStreaming:false X509KeyPairStreaming:{TLSCertFile: TLSKeyFile:} MaxContainerLogLineSize:16384 DisableCgroup:false DisableApparmor:false RestrictOOMScoreAdj:false MaxConcurrentDownloads:3 DisableProcMount:false UnsetSeccompProfile: TolerateMissingHugetlbController:true DisableHugetlbController:true DeviceOwnershipFromSecurityContext:false IgnoreImageDefinedVolumes:false NetNSMountsUnderStateDir:false EnableUnprivilegedPorts:true EnableUnprivilegedICMP:true EnableCDI:false CDISpecDirs:[/etc/cdi /var/run/cdi] ImagePullProgressTimeout:5m0s DrainExecSyncIOTimeout:0s} ContainerdRootDir:/var/lib/docker/containerd/daemon ContainerdEndpoint:/var/run/docker/containerd/containerd.sock RootDir:/var/lib/docker/containerd/daemon/io.containerd.grpc.v1.cri StateDir:/var/run/docker/containerd/daemon/io.containerd.grpc.v1.cri} After this: INFO[2023-12-07T15:33:39.914112719Z] loading plugin id=io.containerd.tracing.processor.v1.otlp type=io.containerd.tracing.processor.v1 INFO[2023-12-07T15:33:39.914526135Z] loading plugin id=io.containerd.internal.v1.tracing type=io.containerd.internal.v1 INFO[2023-12-07T15:33:39.914580427Z] loading plugin id=io.containerd.internal.v1.cri type=io.containerd.internal.v1 INFO[2023-12-07T15:33:39.914626385Z] starting cri plugin config="{PluginConfig:{ContainerdConfig:{Snapshotter:overlayfs DefaultRuntimeName:runc Runtimes:map[runc:{Type:io.containerd.runc.v2 Path: PodAnnotations:[] ContainerAnnotations:[] Options:map[BinaryName: CriuImagePath: CriuWorkPath: IoGid:0 IoUid:0 NoNewKeyring:false Root: ShimCgroup:] PrivilegedWithoutHostDevices:false PrivilegedWithoutHostDevicesAllDevicesAllowed:false BaseRuntimeSpec: NetworkPluginConfDir: NetworkPluginMaxConfNum:0 Snapshotter: Sandboxer:podsandbox}] DisableSnapshotAnnotations:true DiscardUnpackedLayers:false IgnoreBlockIONotEnabledErrors:false IgnoreRdtNotEnabledErrors:false} CniConfig:{NetworkPluginBinDir:/opt/cni/bin NetworkPluginConfDir:/etc/cni/net.d NetworkPluginMaxConfNum:1 NetworkPluginSetupSerially:false NetworkPluginConfTemplate: IPPreference:} Registry:{ConfigPath: Mirrors:map[] Configs:map[] Auths:map[] Headers:map[]} ImageDecryption:{KeyModel:node} DisableTCPService:true StreamServerAddress:127.0.0.1 StreamServerPort:0 StreamIdleTimeout:4h0m0s EnableSelinux:false SelinuxCategoryRange:1024 SandboxImage:registry.k8s.io/pause:3.9 StatsCollectPeriod:10 EnableTLSStreaming:false X509KeyPairStreaming:{TLSCertFile: TLSKeyFile:} MaxContainerLogLineSize:16384 DisableCgroup:false DisableApparmor:false RestrictOOMScoreAdj:false MaxConcurrentDownloads:3 DisableProcMount:false UnsetSeccompProfile: TolerateMissingHugetlbController:true DisableHugetlbController:true DeviceOwnershipFromSecurityContext:false IgnoreImageDefinedVolumes:false NetNSMountsUnderStateDir:false EnableUnprivilegedPorts:true EnableUnprivilegedICMP:true EnableCDI:false CDISpecDirs:[/etc/cdi /var/run/cdi] ImagePullProgressTimeout:5m0s DrainExecSyncIOTimeout:0s} ContainerdRootDir:/var/lib/docker/containerd/daemon ContainerdEndpoint:/var/run/docker/containerd/containerd.sock RootDir:/var/lib/docker/containerd/daemon/io.containerd.grpc.v1.cri StateDir:/var/run/docker/containerd/daemon/io.containerd.grpc.v1.cri}" Signed-off-by: Sebastiaan van Stijn --- plugins/cri/runtime/plugin.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/plugins/cri/runtime/plugin.go b/plugins/cri/runtime/plugin.go index 95c4451a1..87bf671d5 100644 --- a/plugins/cri/runtime/plugin.go +++ b/plugins/cri/runtime/plugin.go @@ -99,7 +99,7 @@ func initCRIRuntime(ic *plugin.InitContext) (interface{}, error) { StateDir: stateDir, } - log.G(ctx).Infof("Start cri plugin with config %+v", c) + log.G(ctx).WithFields(log.Fields{"config": fmt.Sprintf("%+v", c)}).Info("starting cri plugin") if err := setGLogLevel(); err != nil { return nil, fmt.Errorf("failed to set glog level: %w", err) From 8a8c3e221550611f66478d2c3cbb54acdaf11990 Mon Sep 17 00:00:00 2001 From: Sebastiaan van Stijn Date: Thu, 7 Dec 2023 16:25:55 +0100 Subject: [PATCH 2/2] pkg/cri/server/base: log CRI config as embedded JSON Use the JSON-encoded representation of the config used, which allows users to reconstruct a (valid) config file from the logs, which may be more useful for debugging purposes than the internal (Go) representation. Before this: INFO[2023-12-07T15:33:39.914626385Z] starting cri plugin config="{PluginConfig:{ContainerdConfig:{Snapshotter:overlayfs DefaultRuntimeName:runc Runtimes:map[runc:{Type:io.containerd.runc.v2 Path: PodAnnotations:[] ContainerAnnotations:[] Options:map[BinaryName: CriuImagePath: CriuWorkPath: IoGid:0 IoUid:0 NoNewKeyring:false Root: ShimCgroup:] PrivilegedWithoutHostDevices:false PrivilegedWithoutHostDevicesAllDevicesAllowed:false BaseRuntimeSpec: NetworkPluginConfDir: NetworkPluginMaxConfNum:0 Snapshotter: Sandboxer:podsandbox}] DisableSnapshotAnnotations:true DiscardUnpackedLayers:false IgnoreBlockIONotEnabledErrors:false IgnoreRdtNotEnabledErrors:false} CniConfig:{NetworkPluginBinDir:/opt/cni/bin NetworkPluginConfDir:/etc/cni/net.d NetworkPluginMaxConfNum:1 NetworkPluginSetupSerially:false NetworkPluginConfTemplate: IPPreference:} Registry:{ConfigPath: Mirrors:map[] Configs:map[] Auths:map[] Headers:map[]} ImageDecryption:{KeyModel:node} DisableTCPService:true StreamServerAddress:127.0.0.1 StreamServerPort:0 StreamIdleTimeout:4h0m0s EnableSelinux:false SelinuxCategoryRange:1024 SandboxImage:registry.k8s.io/pause:3.9 StatsCollectPeriod:10 EnableTLSStreaming:false X509KeyPairStreaming:{TLSCertFile: TLSKeyFile:} MaxContainerLogLineSize:16384 DisableCgroup:false DisableApparmor:false RestrictOOMScoreAdj:false MaxConcurrentDownloads:3 DisableProcMount:false UnsetSeccompProfile: TolerateMissingHugetlbController:true DisableHugetlbController:true DeviceOwnershipFromSecurityContext:false IgnoreImageDefinedVolumes:false NetNSMountsUnderStateDir:false EnableUnprivilegedPorts:true EnableUnprivilegedICMP:true EnableCDI:false CDISpecDirs:[/etc/cdi /var/run/cdi] ImagePullProgressTimeout:5m0s DrainExecSyncIOTimeout:0s} ContainerdRootDir:/var/lib/docker/containerd/daemon ContainerdEndpoint:/var/run/docker/containerd/containerd.sock RootDir:/var/lib/docker/containerd/daemon/io.containerd.grpc.v1.cri StateDir:/var/run/docker/containerd/daemon/io.containerd.grpc.v1.cri}" After this: INFO[2023-12-07T15:27:15.862946138Z] starting cri plugin config="{\"containerd\":{\"snapshotter\":\"overlayfs\",\"defaultRuntimeName\":\"runc\",\"runtimes\":{\"runc\":{\"runtimeType\":\"io.containerd.runc.v2\",\"runtimePath\":\"\",\"PodAnnotations\":null,\"ContainerAnnotations\":null,\"options\":{\"BinaryName\":\"\",\"CriuImagePath\":\"\",\"CriuWorkPath\":\"\",\"IoGid\":0,\"IoUid\":0,\"NoNewKeyring\":false,\"Root\":\"\",\"ShimCgroup\":\"\"},\"privileged_without_host_devices\":false,\"privileged_without_host_devices_all_devices_allowed\":false,\"baseRuntimeSpec\":\"\",\"cniConfDir\":\"\",\"cniMaxConfNum\":0,\"snapshotter\":\"\",\"sandboxer\":\"podsandbox\"}},\"disableSnapshotAnnotations\":true,\"discardUnpackedLayers\":false,\"ignoreBlockIONotEnabledErrors\":false,\"ignoreRdtNotEnabledErrors\":false},\"cni\":{\"binDir\":\"/opt/cni/bin\",\"confDir\":\"/etc/cni/net.d\",\"maxConfNum\":1,\"setupSerially\":false,\"confTemplate\":\"\",\"ipPref\":\"\"},\"registry\":{\"configPath\":\"\",\"mirrors\":null,\"configs\":null,\"auths\":null,\"headers\":null},\"imageDecryption\":{\"keyModel\":\"node\"},\"disableTCPService\":true,\"streamServerAddress\":\"127.0.0.1\",\"streamServerPort\":\"0\",\"streamIdleTimeout\":\"4h0m0s\",\"enableSelinux\":false,\"selinuxCategoryRange\":1024,\"sandboxImage\":\"registry.k8s.io/pause:3.9\",\"statsCollectPeriod\":10,\"enableTLSStreaming\":false,\"x509KeyPairStreaming\":{\"tlsCertFile\":\"\",\"tlsKeyFile\":\"\"},\"maxContainerLogSize\":16384,\"disableCgroup\":false,\"disableApparmor\":false,\"restrictOOMScoreAdj\":false,\"maxConcurrentDownloads\":3,\"disableProcMount\":false,\"unsetSeccompProfile\":\"\",\"tolerateMissingHugetlbController\":true,\"disableHugetlbController\":true,\"device_ownership_from_security_context\":false,\"ignoreImageDefinedVolumes\":false,\"netnsMountsUnderStateDir\":false,\"enableUnprivilegedPorts\":true,\"enableUnprivilegedICMP\":true,\"enableCDI\":false,\"cdiSpecDirs\":[\"/etc/cdi\",\"/var/run/cdi\"],\"imagePullProgressTimeout\":\"5m0s\",\"drainExecSyncIOTimeout\":\"0s\",\"containerdRootDir\":\"/var/lib/docker/containerd/daemon\",\"containerdEndpoint\":\"/var/run/docker/containerd/containerd.sock\",\"rootDir\":\"/var/lib/docker/containerd/daemon/io.containerd.grpc.v1.cri\",\"stateDir\":\"/var/run/docker/containerd/daemon/io.containerd.grpc.v1.cri\"}" Signed-off-by: Sebastiaan van Stijn --- plugins/cri/runtime/plugin.go | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/plugins/cri/runtime/plugin.go b/plugins/cri/runtime/plugin.go index 87bf671d5..adc64d937 100644 --- a/plugins/cri/runtime/plugin.go +++ b/plugins/cri/runtime/plugin.go @@ -99,7 +99,9 @@ func initCRIRuntime(ic *plugin.InitContext) (interface{}, error) { StateDir: stateDir, } - log.G(ctx).WithFields(log.Fields{"config": fmt.Sprintf("%+v", c)}).Info("starting cri plugin") + // Ignoring errors here; this should never fail. + cfg, _ := json.Marshal(c) + log.G(ctx).WithFields(log.Fields{"config": string(cfg)}).Info("starting cri plugin") if err := setGLogLevel(); err != nil { return nil, fmt.Errorf("failed to set glog level: %w", err)